Add temporary debug logging, in 9.4 branch only.

Commit 5ee940e1c served its purpose by demonstrating that buildfarm
member okapi is seeing some sort of locally-visible state mismanagement,
not a cross-process data visibility problem as I'd first theorized.
Put in some elog(LOG) messages in hopes of gathering more info about
exactly what's happening there.  Again, this is temporary code to be
reverted once we have buildfarm results.

Discussion: https://postgr.es/m/6744.1523833660@sss.pgh.pa.us

diff --git a/src/backend/commands/indexcmds.c b/src/backend/commands/indexcmds.c
index 05afcb0088d66f9889e0f1294974b0d0d747919e..e8b9d1a4dd8b07b97f42a4bc2b11b4bf66cc825a 100644 (file)
--- a/src/backend/commands/indexcmds.c
+++ b/src/backend/commands/indexcmds.c
@@ -758,6 +758,8 @@ DefineIndex(Oid relationId,
     */
    validate_index(relationId, indexRelationId, snapshot);
 
+   PrintSnapMgrStatus("concurrent index build, before snapshot release");
+
    /*
     * Drop the reference snapshot.  We must do this before waiting out other
     * snapshot holders, else we will deadlock against other processes also
@@ -770,9 +772,13 @@ DefineIndex(Oid relationId,
    limitXmin = snapshot->xmin;
 
    PopActiveSnapshot();
+   PrintSnapMgrStatus("concurrent index build, after PopActiveSnapshot");
    UnregisterSnapshot(snapshot);
+   PrintSnapMgrStatus("concurrent index build, after UnregisterSnapshot");
    InvalidateCatalogSnapshot();
 
+   PrintSnapMgrStatus("concurrent index build, after InvalidateCatalogSnapshot");
+
    /*
     * The index is now valid in the sense that it contains all currently
     * interesting tuples.  But since it might not contain tuples deleted just

diff --git a/src/backend/utils/time/snapmgr.c b/src/backend/utils/time/snapmgr.c
index 331c91044f2fe816a5f969722ce80060da755737..2a3d915e1f9beed43154c60852da6f862a7e06ec 100644 (file)
--- a/src/backend/utils/time/snapmgr.c
+++ b/src/backend/utils/time/snapmgr.c
@@ -1401,3 +1401,17 @@ HistoricSnapshotGetTupleCids(void)
    Assert(HistoricSnapshotActive());
    return tuplecid_data;
 }
+
+void
+PrintSnapMgrStatus(const char *context)
+{
+   int         asdepth = 0;
+   ActiveSnapshotElt *active;
+
+   for (active = ActiveSnapshot; active != NULL; active = active->as_next)
+       asdepth++;
+
+   elog(LOG, "%s: %d reg snaps, %d active snaps, cat snap %p, xmin %u",
+        context, RegisteredSnapshots, asdepth,
+        CatalogSnapshot, MyPgXact->xmin);
+}

diff --git a/src/include/utils/snapmgr.h b/src/include/utils/snapmgr.h
index c6aa3619508894823358f684329d1dc266f125ff..71452d9afe11ba34ea2fdcc0e7df32e242a64010 100644 (file)
--- a/src/include/utils/snapmgr.h
+++ b/src/include/utils/snapmgr.h
@@ -65,4 +65,6 @@ extern void SetupHistoricSnapshot(Snapshot snapshot_now, struct HTAB *tuplecids)
 extern void TeardownHistoricSnapshot(bool is_error);
 extern bool HistoricSnapshotActive(void);
 
+extern void PrintSnapMgrStatus(const char *context);
+
 #endif   /* SNAPMGR_H */