AIO-debugging.patch

text/x-patch

Filename: AIO-debugging.patch
Type: text/x-patch
Part: 0
Message: Re: Non-reproducible AIO failure

Patch

Same data as JSON: GET /api/v1/attachments/:id/patch the parsed metadata as JSON — format, series position, per-file stats; never the diff bytes. API reference →
Format: unified
File+
src/backend/storage/aio/aio.c 8 0
src/backend/storage/aio/aio_io.c 6 0
src/backend/storage/buffer/bufmgr.c 9 0
src/backend/storage/file/fd.c 6 0
src/include/storage/aio.h 2 2
diff --git a/src/backend/storage/aio/aio.c b/src/backend/storage/aio/aio.c
index 3643f27ad6e..bc5202227da 100644
--- a/src/backend/storage/aio/aio.c
+++ b/src/backend/storage/aio/aio.c
@@ -206,6 +206,7 @@ pgaio_io_acquire_nb(struct ResourceOwnerData *resowner, PgAioReturn *ret)
 		dlist_node *ion = dclist_pop_head_node(&pgaio_my_backend->idle_ios);
 
 		ioh = dclist_container(PgAioHandle, node, ion);
+int pre_op = ioh->op;
 
 		Assert(ioh->state == PGAIO_HS_IDLE);
 		Assert(ioh->owner_procno == MyProcNumber);
@@ -221,6 +222,11 @@ pgaio_io_acquire_nb(struct ResourceOwnerData *resowner, PgAioReturn *ret)
 			ioh->report_return = ret;
 			ret->result.status = PGAIO_RS_UNKNOWN;
 		}
+
+if (ioh->op != PGAIO_OP_INVALID)
+{
+fprintf(stderr, "!!!pgaio_io_acquire_nb [%d]| ioh: %p, ioh->op: %d, pre_op: %d\n", getpid(), ioh, ioh->op, pre_op);
+}
 	}
 
 	RESUME_INTERRUPTS();
@@ -675,6 +681,7 @@ pgaio_io_reclaim(PgAioHandle *ioh)
 	Assert(ioh->owner_procno == MyProcNumber);
 	Assert(ioh->state != PGAIO_HS_IDLE);
 
+fprintf(stderr, "!!!pgaio_io_reclaim [%d]| ioh: %p, ioh->op: %d, ioh->state: %d, ioh->target: %d, ioh->result: %d, ioh->num_callbacks: %d, ioh->generation: %llu\n", getpid(), ioh, ioh->op, ioh->state, ioh->target, ioh->result, ioh->num_callbacks, ioh->generation);
 	/* see comment in function header */
 	HOLD_INTERRUPTS();
 
@@ -747,6 +754,7 @@ pgaio_io_reclaim(PgAioHandle *ioh)
 	dclist_push_head(&pgaio_my_backend->idle_ios, &ioh->node);
 
 	RESUME_INTERRUPTS();
+fprintf(stderr, "!!!pgaio_io_reclaim [%d]| ioh: %p, ioh->op: %d, ioh->state: %d, ioh->target: %d, ioh->generation: %llu\n", getpid(), ioh, ioh->op, ioh->state, ioh->target, ioh->generation);
 }
 
 /*
diff --git a/src/backend/storage/aio/aio_io.c b/src/backend/storage/aio/aio_io.c
index 520b5077df2..ffd7edcc82b 100644
--- a/src/backend/storage/aio/aio_io.c
+++ b/src/backend/storage/aio/aio_io.c
@@ -85,6 +85,7 @@ pgaio_io_start_readv(PgAioHandle *ioh,
 	ioh->op_data.read.iov_length = iovcnt;
 
 	pgaio_io_stage(ioh, PGAIO_OP_READV);
+fprintf(stderr, "!!!pgaio_io_start_readv [%d]| ioh: %p, ioh->op: %d, ioh->state: %d, ioh->target: %d, ioh->generation: %llu\n", getpid(), ioh, ioh->op, ioh->state, ioh->target, ioh->generation);
 }
 
 void
@@ -158,6 +159,11 @@ pgaio_io_before_start(PgAioHandle *ioh)
 	Assert(ioh->state == PGAIO_HS_HANDED_OUT);
 	Assert(pgaio_my_backend->handed_out_io == ioh);
 	Assert(pgaio_io_has_target(ioh));
+if (ioh->op != PGAIO_OP_INVALID)
+{
+elog(LOG, "!!!pgaio_io_before_start| ioh: %p, ioh->op: %d, ioh->state: %d, ioh->target: %d, ioh->result: %d, ioh->num_callbacks: %d, ioh->generation: %llu", ioh, ioh->op, ioh->state, ioh->target, ioh->result, ioh->num_callbacks, ioh->generation);
+}
+
 	Assert(ioh->op == PGAIO_OP_INVALID);
 
 	/*
diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c
index fd7e21d96d3..6d9d1c60882 100644
--- a/src/backend/storage/buffer/bufmgr.c
+++ b/src/backend/storage/buffer/bufmgr.c
@@ -67,6 +67,7 @@
 #include "utils/resowner.h"
 #include "utils/timestamp.h"
 
+#include "storage/aio_internal.h"
 
 /* Note: these two macros only work on shared buffers, not local ones! */
 #define BufHdrGetBlock(bufHdr)	((Block) (BufferBlocks + ((Size) (bufHdr)->buf_id) * BLCKSZ))
@@ -1850,7 +1851,10 @@ AsyncReadBuffers(ReadBuffersOperation *operation, int *nblocks_progress)
 		pgaio_submit_staged();
 
 		ioh = pgaio_io_acquire(CurrentResourceOwner, &operation->io_return);
+fprintf(stderr, "!!!AsyncReadBuffers [%d] (2)| blocknum: %d, ioh: %p, ioh->op: %d, ioh->state: %d, ioh->target: %d, ioh->result: %d, ioh->num_callbacks: %d, ioh->generation: %llu\n", getpid(), blocknum, ioh, ((PgAioHandle *)ioh)->op, ((PgAioHandle *)ioh)->state, ((PgAioHandle *)ioh)->target, ((PgAioHandle *)ioh)->result, ((PgAioHandle *)ioh)->num_callbacks, ((PgAioHandle *)ioh)->generation);
 	}
+else
+fprintf(stderr, "!!!AsyncReadBuffers [%d] (1)| blocknum: %d, ioh: %p, ioh->op: %d, ioh->state: %d, ioh->target: %d, ioh->result: %d, ioh->num_callbacks: %d, ioh->generation: %llu\n", getpid(), blocknum, ioh, ((PgAioHandle *)ioh)->op, ((PgAioHandle *)ioh)->state, ((PgAioHandle *)ioh)->target, ((PgAioHandle *)ioh)->result, ((PgAioHandle *)ioh)->num_callbacks, ((PgAioHandle *)ioh)->generation);
 
 	/*
 	 * Check if we can start IO on the first to-be-read buffer.
@@ -1902,6 +1906,7 @@ AsyncReadBuffers(ReadBuffersOperation *operation, int *nblocks_progress)
 	}
 	else
 	{
+int pre_op = ioh->op;
 		instr_time	io_start;
 
 		/* We found a buffer that we need to read in. */
@@ -1951,6 +1956,10 @@ AsyncReadBuffers(ReadBuffersOperation *operation, int *nblocks_progress)
 		 * ---
 		 */
 		io_start = pgstat_prepare_io_time(track_io_timing);
+if (ioh->op != PGAIO_OP_INVALID)
+{
+fprintf(stderr, "!!!AsyncReadBuffers [%d]  before smgrstartreadv| blocknum: %d, ioh: %p, ioh->op: %d, pre_op: %d, ioh->state: %d, ioh->target: %d, ioh->result: %d, ioh->num_callbacks: %d, ioh->generation: %llu\n", getpid(), blocknum, ioh, ((PgAioHandle *)ioh)->op, pre_op, ((PgAioHandle *)ioh)->state, ((PgAioHandle *)ioh)->target, ((PgAioHandle *)ioh)->result, ((PgAioHandle *)ioh)->num_callbacks, ((PgAioHandle *)ioh)->generation);
+}
 		smgrstartreadv(ioh, operation->smgr, forknum,
 					   blocknum + nblocks_done,
 					   io_pages, io_buffers_len);
diff --git a/src/backend/storage/file/fd.c b/src/backend/storage/file/fd.c
index a4ec7959f31..3ba3a3c0e62 100644
--- a/src/backend/storage/file/fd.c
+++ b/src/backend/storage/file/fd.c
@@ -102,6 +102,8 @@
 #include "utils/resowner.h"
 #include "utils/varlena.h"
 
+#include "storage/aio_internal.h"
+
 /* Define PG_FLUSH_DATA_WORKS if we have an implementation for pg_flush_data */
 #if defined(HAVE_SYNC_FILE_RANGE)
 #define PG_FLUSH_DATA_WORKS 1
@@ -2235,6 +2237,10 @@ FileStartReadV(PgAioHandle *ioh, File file,
 
 	vfdP = &VfdCache[file];
 
+if (ioh->op != PGAIO_OP_INVALID)
+{
+elog(LOG, "!!!FileStartReadV| ioh: %p, ioh->op: %d, ioh->state: %d, ioh->target: %d, ioh->result: %d, ioh->num_callbacks: %d, ioh->generation: %llu", ioh,  ((PgAioHandle *)ioh)->op, ((PgAioHandle *)ioh)->state, ((PgAioHandle *)ioh)->target, ((PgAioHandle *)ioh)->result, ((PgAioHandle *)ioh)->num_callbacks, ((PgAioHandle *)ioh)->generation);
+}
 	pgaio_io_start_readv(ioh, vfdP->fd, iovcnt, offset);
 
 	return 0;
diff --git a/src/include/storage/aio.h b/src/include/storage/aio.h
index 2933eea0649..7e2215bddfd 100644
--- a/src/include/storage/aio.h
+++ b/src/include/storage/aio.h
@@ -89,8 +89,8 @@ typedef enum PgAioOp
 	/* intentionally the zero value, to help catch zeroed memory etc */
 	PGAIO_OP_INVALID = 0,
 
-	PGAIO_OP_READV,
-	PGAIO_OP_WRITEV,
+	PGAIO_OP_READV = 0xaa,
+	PGAIO_OP_WRITEV = 0xbb,
 
 	/**
 	 * In the near term we'll need at least: