From 039bfc457e436dc5c6b1d6ef996048ae19ff480d Mon Sep 17 00:00:00 2001 From: Andres Freund Date: Fri, 25 Apr 2025 12:31:42 -0400 Subject: [PATCH] aio: Improve debug logging around waiting for IOs Trying to investigate a bug report by Alexander Lakhin made it apparent that the debug logging around waiting for IO completion is insufficient. Fix that. Discussion: https://postgr.es/m/h4in2db37vepagmi2oz5vvqymjasc5gyb4lpqkunj4eusu274i@37jpd3c2spd3 --- src/backend/storage/aio/aio.c | 29 +++++++++++++++++++++++++---- 1 file changed, 25 insertions(+), 4 deletions(-) diff --git a/src/backend/storage/aio/aio.c b/src/backend/storage/aio/aio.c index e2a133cfac6..57b9cf3dcab 100644 --- a/src/backend/storage/aio/aio.c +++ b/src/backend/storage/aio/aio.c @@ -711,8 +711,10 @@ pgaio_io_wait_for_free(void) { int reclaimed = 0; - pgaio_debug(DEBUG2, "waiting for self with %d pending", - pgaio_my_backend->num_staged_ios); + pgaio_debug(DEBUG2, "waiting for free IO with %d pending, %d in-flight, %d idle IOs", + pgaio_my_backend->num_staged_ios, + dclist_count(&pgaio_my_backend->in_flight_ios), + dclist_is_empty(&pgaio_my_backend->idle_ios)); /* * First check if any of our IOs actually have completed - when using @@ -743,7 +745,12 @@ pgaio_io_wait_for_free(void) pgaio_submit_staged(); if (dclist_count(&pgaio_my_backend->in_flight_ios) == 0) - elog(ERROR, "no free IOs despite no in-flight IOs"); + ereport(ERROR, + errmsg_internal("no free IOs despite no in-flight IOs"), + errdetail_internal("%d pending, %d in-flight, %d idle IOs", + pgaio_my_backend->num_staged_ios, + dclist_count(&pgaio_my_backend->in_flight_ios), + dclist_is_empty(&pgaio_my_backend->idle_ios))); /* * Wait for the oldest in-flight IO to complete. @@ -1136,7 +1143,13 @@ pgaio_closing_fd(int fd) * For now just submit all staged IOs - we could be more selective, but * it's probably not worth it. */ - pgaio_submit_staged(); + if (pgaio_my_backend->num_staged_ios > 0) + { + pgaio_debug(DEBUG2, + "submitting %d IOs before FD %d gets closed", + pgaio_my_backend->num_staged_ios, fd); + pgaio_submit_staged(); + } /* * If requested by the IO method, wait for all IOs that use the @@ -1168,6 +1181,10 @@ pgaio_closing_fd(int fd) if (!ioh) break; + pgaio_debug_io(DEBUG2, ioh, + "waiting for IO before FD %d gets closed, %d in-flight IOs", + fd, dclist_count(&pgaio_my_backend->in_flight_ios)); + /* see comment in pgaio_io_wait_for_free() about raciness */ pgaio_io_wait(ioh, ioh->generation); } @@ -1199,6 +1216,10 @@ pgaio_shutdown(int code, Datum arg) { PgAioHandle *ioh = dclist_head_element(PgAioHandle, node, &pgaio_my_backend->in_flight_ios); + pgaio_debug_io(DEBUG2, ioh, + "waiting for IO to complete during shutdown, %d in-flight IOs", + dclist_count(&pgaio_my_backend->in_flight_ios)); + /* see comment in pgaio_io_wait_for_free() about raciness */ pgaio_io_wait(ioh, ioh->generation); }