Subject: RE: Conflict detection and logging in logical replication

From: "Zhijie Hou (Fujitsu)" <[email-masked]>
Date: Tue, 13 Aug 2024 04:39:15 +0000

On Monday, August 12, 2024 7:41 PM Amit Kapila <[email-masked]> wrote:
> 
> On Fri, Aug 9, 2024 at 12:29 PM Zhijie Hou (Fujitsu)
> <[email-masked]> wrote:
> >
> > Here is the V12 patch that improved the log format as discussed.
> >
> 
> Review comments:

Thanks for the comments.

> ===============
> 1. The patch doesn't display the remote tuple for delete_differ case.
> However, it shows the remote tuple correctly for update_differ. Is
> there a reason for the same? See below messages:
> 
> update_differ:
> --------------
> LOG:  conflict detected on relation "public.t1": conflict=update_differ
> DETAIL:  Updating the row containing (c1)=(1) that was modified
> locally in transaction 806 at 2024-08-12 11:48:14.970002+05:30.
>         Existing local tuple (1, 3, arun      ); remote tuple (1, 3,
> ajay      ).
> ...
> 
> delete_differ
> --------------
> LOG:  conflict detected on relation "public.t1": conflict=delete_differ
> DETAIL:  Deleting the row containing (c1)=(1) that was modified by
> locally in transaction 809 at 2024-08-12 14:15:41.966467+05:30.
>         Existing local tuple (1, 3, arun      ).
> 
> Note this happens when the publisher table has a REPLICA IDENTITY FULL
> and the subscriber table has primary_key. It would be better to keep
> the messages consistent. One possibility is that we remove
> key/old_tuple from the first line of the DETAIL message and display it
> in the second line as Existing local tuple <local_tuple>; remote tuple
> <..>; key <...>

Agreed. I thought that in delete_differ/missing cases, the remote tuple is covered
In the key values in the first sentence. To be consistent, I have moved the column-values
from the first sentence to the second sentence including the insert_exists conflict.

The new format looks like:

LOG: xxx
DETAIL: Key %s; existing local tuple %s; remote new tuple %s; replica identity %s

The Key will include the conflicting key for xxx_exists conflicts. And the replica identity part
will include the replica identity keys or the full tuple value in replica identity FULL case.

> 
> 2. Similar to above, the remote tuple is not displayed in
> delete_missing but displayed in updated_missing type of conflict. If
> we follow the style mentioned in the previous point then the DETAIL
> message: "DETAIL:  Did not find the row containing (c1)=(1) to be
> updated." can also be changed to: "DETAIL:  Could not find the row to
> be updated." followed by other detail.

Same as above.

> 3. The detail of insert_exists is confusing.
> 
> ERROR:  conflict detected on relation "public.t1": conflict=insert_exists
> DETAIL:  Key (c1)=(1) already exists in unique index "t1_pkey", which
> was modified locally in transaction 802 at 2024-08-12
> 11:11:31.252148+05:30.
> 
> It sounds like the key value "(c1)=(1)" in the index is modified. How
> about changing slightly as: "Key (c1)=(1) already exists in unique
> index "t1_pkey", modified locally in transaction 802 at 2024-08-12
> 11:11:31.252148+05:30."? Feel free to propose if anything better comes
> to your mind.

The suggested message looks good to me.

> 
> 4.
> if (localorigin == InvalidRepOriginId)
> + appendStringInfo(&err_detail, _("Deleting the row containing %s that
> was modified by locally in transaction %u at %s."),
> + val_desc, localxmin, timestamptz_to_str(localts));
> 
> Typo in the above message. /modified by locally/modified locally

Fixed.

> 
> 5.
> @@ -2661,6 +2662,29 @@ apply_handle_update_internal(ApplyExecutionData
> *edata,
> {
> ...
> found = FindReplTupleInLocalRel(edata, localrel,
> &relmapentry->remoterel,
> localindexoid,
> remoteslot, &localslot);
> ...
> ...
> +
> + ReportApplyConflict(LOG, CT_UPDATE_DIFFER, relinfo,
> + GetRelationIdentityOrPK(localrel),
> 
> To find the tuple, we may have used an index other than Replica
> Identity or PK (see IsIndexUsableForReplicaIdentityFull), but while
> reporting conflict we don't consider such an index. I think the reason
> is that such an index scan wouldn't have resulted in a unique tuple
> and that is why we always compare the complete tuple in such cases. Is
> that the reason? Can we write a comment to make it clear?

Added comments atop of ReportApplyConflict for the 'indexoid' parameter.

> 
> 6.
> void ReportApplyConflict(int elevel, ConflictType type,
> + ResultRelInfo *relinfo, Oid indexoid,
> + TransactionId localxmin,
> + RepOriginId localorigin,
> + TimestampTz localts,
> + TupleTableSlot *searchslot,
> + TupleTableSlot *localslot,
> + TupleTableSlot *remoteslot,
> + EState *estate);
> 
> The prototype looks odd with pointers and non-pointer variables in
> mixed order. How about arranging parameters in the following order:
> Estate, ResultRelInfo, TupleTableSlot *searchslot, TupleTableSlot
> *localslot, TupleTableSlot *remoteslot, Oid indexoid, TransactionId
> localxmin, RepOriginId localorigin, TimestampTz localts?
> 
> 7. Like above, check the parameters of other functions like
> errdetail_apply_conflict, build_index_value_desc,
> build_tuple_value_details, etc.

Changed as suggested.

Here is V13 patch set which addressed above comments.

Best Regards,
Hou zj

---

From: Amit Kapila <[email-masked]>
Date: Tue, 13 Aug 2024 16:33:43 +0530

> Here is V13 patch set which addressed above comments.

1.
+ReportApplyConflict(int elevel, ConflictType type, EState *estate,
+ ResultRelInfo *relinfo,

The change looks better but it would still be better to keep elevel
and type after relinfo. The same applies to other places as well.

2.
+ * The caller should ensure that the index with the OID 'indexoid' is locked.
+ *
+ * Refer to errdetail_apply_conflict for the content that will be included in
+ * the DETAIL line.
+ */
+void
+ReportApplyConflict(int elevel, ConflictType type, EState *estate,

Is it possible to add an assert to ensure that the index is locked by
the caller?

3.
+static char *
+build_tuple_value_details(EState *estate, ResultRelInfo *relinfo,
+   TupleTableSlot *searchslot,
+   TupleTableSlot *localslot,
+   TupleTableSlot *remoteslot,
+   Oid indexoid)
{
...
...
+ /*
+ * If 'searchslot' is NULL and 'indexoid' is valid, it indicates that we
+ * are reporting the unique constraint violation conflict, in which case
+ * the conflicting key values will be reported.
+ */
+ if (OidIsValid(indexoid) && !searchslot)
+ {
...
...
}

This indirect way of inferencing constraint violation looks fragile.
The caller should pass the required information explicitly and then
you can have the required assertions here.

Apart from the above, I have made quite a few changes in the code
comments and LOG messages in the attached.

-- 
With Regards,
Amit Kapila.
diff --git a/src/backend/replication/logical/conflict.c b/src/backend/replication/logical/conflict.c
index 8f7e5bfdd4..4995651644 100644
--- a/src/backend/replication/logical/conflict.c
+++ b/src/backend/replication/logical/conflict.c
@@ -79,10 +79,11 @@ GetTupleTransactionInfo(TupleTableSlot *localslot, TransactionId *xmin,
 }
 
 /*
- * Report a conflict when applying remote changes.
+ * This function is used to report a conflict while applying replication
+ * changes.
  *
- * 'searchslot' should contain the tuple used to search for the local tuple to
- * be updated or deleted.
+ * 'searchslot' should contain the tuple used to search the local tuple to be
+ * updated or deleted.
  *
  * 'localslot' should contain the existing local tuple, if any, that conflicts
  * with the remote tuple. 'localxmin', 'localorigin', and 'localts' provide the
@@ -91,17 +92,17 @@ GetTupleTransactionInfo(TupleTableSlot *localslot, TransactionId *xmin,
  * 'remoteslot' should contain the remote new tuple, if any.
  *
  * The 'indexoid' represents the OID of the replica identity index or the OID
- * of the unique index that triggered the constraint violation error. Note that
- * while other indexes may also be used (see
+ * of the unique index that triggered the constraint violation error. We use
+ * this to report the key values for conflicting tuple.
+ *
+ * Note that while other indexes may also be used (see
  * IsIndexUsableForReplicaIdentityFull for details) to find the tuple when
  * applying update or delete, such an index scan may not result in a unique
  * tuple and we still compare the complete tuple in such cases, thus such index
  * OIDs should not be passed here.
  *
- * The caller should ensure that the index with the OID 'indexoid' is locked.
- *
- * Refer to errdetail_apply_conflict for the content that will be included in
- * the DETAIL line.
+ * The caller must ensure that the index with the OID 'indexoid' is locked so
+ * that we can display the conflicting key value.
  */
 void
 ReportApplyConflict(int elevel, ConflictType type, EState *estate,
@@ -157,10 +158,10 @@ InitConflictIndexes(ResultRelInfo *relInfo)
 /*
  * Add an errdetail() line showing conflict detail.
  *
- * The DETAIL line comprises two parts:
+ * The DETAIL line comprises of two parts:
  * 1. Explanation of the conflict type, including the origin and commit
  *    timestamp of the existing local tuple.
- * 2. Display of conflicting key, existing local tuple, remote new tuple and
+ * 2. Display of conflicting key, existing local tuple, remote new tuple, and
  *    replica identity columns, if any. The remote old tuple is excluded as its
  *    information is covered in the replica identity columns.
  */
@@ -196,11 +197,11 @@ errdetail_apply_conflict(ConflictType type, EState *estate,
 									 localxmin, timestamptz_to_str(localts));
 
 				/*
-				 * The origin which modified the row has been dropped. This
-				 * situation may occur if the origin was created by a
-				 * different apply worker, but its associated subscription and
-				 * origin were dropped after updating the row, or if the
-				 * origin was manually dropped by the user.
+				 * The origin that modified this row has been removed. This
+				 * can happen if the origin was created by a different apply
+				 * worker and its associated subscription and origin were
+				 * dropped after updating the row, or if the origin was
+				 * manually dropped by the user.
 				 */
 				else
 					appendStringInfo(&err_detail, _("Key already exists in unique index \"%s\", modified by a non-existent origin in transaction %u at %s."),
@@ -221,7 +222,7 @@ errdetail_apply_conflict(ConflictType type, EState *estate,
 				appendStringInfo(&err_detail, _("Updating the row that was modified by a different origin \"%s\" in transaction %u at %s."),
 								 origin_name, localxmin, timestamptz_to_str(localts));
 
-			/* The origin which modified the row has been dropped */
+			/* The origin that modified this row has been removed. */
 			else
 				appendStringInfo(&err_detail, _("Updating the row that was modified by a non-existent origin in transaction %u at %s."),
 								 localxmin, timestamptz_to_str(localts));
@@ -229,7 +230,7 @@ errdetail_apply_conflict(ConflictType type, EState *estate,
 			break;
 
 		case CT_UPDATE_MISSING:
-			appendStringInfo(&err_detail, _("Did not find the row to be updated."));
+			appendStringInfo(&err_detail, _("Could not find the row to be updated."));
 			break;
 
 		case CT_DELETE_DIFFER:
@@ -240,7 +241,7 @@ errdetail_apply_conflict(ConflictType type, EState *estate,
 				appendStringInfo(&err_detail, _("Deleting the row that was modified by a different origin \"%s\" in transaction %u at %s."),
 								 origin_name, localxmin, timestamptz_to_str(localts));
 
-			/* The origin which modified the row has been dropped */
+			/* The origin that modified this row has been removed. */
 			else
 				appendStringInfo(&err_detail, _("Deleting the row that was modified by a non-existent origin in transaction %u at %s."),
 								 localxmin, timestamptz_to_str(localts));
@@ -248,7 +249,7 @@ errdetail_apply_conflict(ConflictType type, EState *estate,
 			break;
 
 		case CT_DELETE_MISSING:
-			appendStringInfo(&err_detail, _("Did not find the row to be deleted."));
+			appendStringInfo(&err_detail, _("Could not find the row to be deleted."));
 			break;
 	}
 
@@ -268,12 +269,11 @@ errdetail_apply_conflict(ConflictType type, EState *estate,
 }
 
 /*
- * Helper function to build the additional details after the main DETAIL line
- * that describes the values of the conflicting key, existing local tuple,
- * remote tuple and replica identity columns.
+ * Helper function to build the additional details for conflicting key,
+ * existing local tuple, remote tuple, and replica identity columns.
  *
  * If the return value is NULL, it indicates that the current user lacks
- * permissions to view all the columns involved.
+ * permissions to view the columns involved.
  */
 static char *
 build_tuple_value_details(EState *estate, ResultRelInfo *relinfo,

---

From: "Zhijie Hou (Fujitsu)" <[email-masked]>
Date: Wed, 14 Aug 2024 02:35:34 +0000

On Tuesday, August 13, 2024 7:04 PM Amit Kapila <[email-masked]> wrote:
> +ResultRelInfo *relinfo,
> The change looks better but it would still be better to keep elevel and type after
> relinfo. The same applies to other places as well.

Changed.

> + * Refer to errdetail_apply_conflict for the content that will be
> +included in
> + * the DETAIL line.
> + */
> +void
> Is it possible to add an assert to ensure that the index is locked by the caller?

Added.

> + * If 'searchslot' is NULL and 'indexoid' is valid, it indicates that
> + we
> + * are reporting the unique constraint violation conflict, in which
> + case
> + if (OidIsValid(indexoid) && !searchslot) {
> ...
> ...
> }
> 
> The caller should pass the required information explicitly and then you can
> have the required assertions here.
> 
> Apart from the above, I have made quite a few changes in the code comments
> and LOG messages in the attached.

Thanks. I have addressed above comments and merged the changes.

Here is the V14 patch.

Best Regards,
Hou zj