Skip to content

Commit 860d3d6

Browse files
committed
Add cache pressure summary and include failing query in error logs
Log a one-line summary after each cache-pressure pass (files/bytes added, evicted, and skipped by reason) so we can see why the cache stayed full or churned. Append the first 500 chars of the failing query to pgduck_server parse/bind/execute WARNING lines so a stray error is debuggable without replaying the session. Signed-off-by: Marco Slot <marco.slot@snowflake.com>
1 parent 36b61e8 commit 860d3d6

3 files changed

Lines changed: 51 additions & 7 deletions

File tree

duckdb_pglake/src/fs/file_cache_manager.cpp

Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -702,6 +702,43 @@ FileCacheManager::ManageCache(ClientContext &context, int64_t maxCacheSize)
702702
}
703703
}
704704

705+
int64_t added = 0, addedBytes = 0;
706+
int64_t removed = 0, removedBytes = 0;
707+
int64_t skippedTooLarge = 0, skippedTooOld = 0;
708+
int64_t skippedConcurrent = 0, addFailed = 0;
709+
710+
for (const CacheAction &a : actions)
711+
{
712+
switch (a.action)
713+
{
714+
case ADDED: added++; addedBytes += a.fileSize; break;
715+
case REMOVED: removed++; removedBytes += a.fileSize; break;
716+
case SKIPPED_TOO_LARGE: skippedTooLarge++; break;
717+
case SKIPPED_TOO_OLD: skippedTooOld++; break;
718+
case SKIPPED_CONCURRENT_MODIFY: skippedConcurrent++; break;
719+
case ADD_FAILED: addFailed++; break;
720+
default: break;
721+
}
722+
}
723+
724+
if (added > 0 || removed > 0 || skippedTooOld > 0 ||
725+
skippedTooLarge > 0 || addFailed > 0)
726+
{
727+
PGDUCK_SERVER_LOG("cache pressure: added %" PRIu64 " files (%" PRIu64
728+
" bytes), evicted %" PRIu64 " files (%" PRIu64 " bytes), "
729+
"skipped %" PRIu64 " (too old), %" PRIu64 " (too large), "
730+
"%" PRIu64 " (concurrent), %" PRIu64 " (add failed); "
731+
"cache now %" PRIu64 "/%" PRIu64 " bytes",
732+
(uint64_t) added, (uint64_t) addedBytes,
733+
(uint64_t) removed, (uint64_t) removedBytes,
734+
(uint64_t) skippedTooOld,
735+
(uint64_t) skippedTooLarge,
736+
(uint64_t) skippedConcurrent,
737+
(uint64_t) addFailed,
738+
(uint64_t) totalCacheSize,
739+
(uint64_t) maxCacheSize);
740+
}
741+
705742
return actions;
706743
}
707744

pgduck_server/src/duckdb/duckdb.c

Lines changed: 8 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -759,7 +759,8 @@ duckdb_session_run_command(DuckDBSession * duckSession, const char *queryString,
759759
}
760760
else
761761
{
762-
PGDUCK_SERVER_WARN("query on duckdb failed: %s", duckdbError);
762+
PGDUCK_SERVER_WARN("query on duckdb failed: %s; query: %.500s",
763+
duckdbError, queryString);
763764
status = DUCKDB_QUERY_ERROR;
764765
}
765766

@@ -931,7 +932,9 @@ duckdb_session_execute_prepared(DuckDBSession * duckSession,
931932
}
932933
else
933934
{
934-
PGDUCK_SERVER_WARN("could not execute prepared statement: %s", duckdbError);
935+
PGDUCK_SERVER_WARN("could not execute prepared statement: %s; query: %.500s",
936+
duckdbError,
937+
duckSession->clientSession->pgSessionPreparedStmt.queryString);
935938
status = DUCKDB_QUERY_ERROR;
936939
}
937940

@@ -1216,7 +1219,9 @@ process_and_send_data_chunks(DuckDBQueryResult * duckdb_query_result,
12161219
}
12171220
else
12181221
{
1219-
PGDUCK_SERVER_WARN("query on duckdb failed during execution: %s", duckdbError);
1222+
PGDUCK_SERVER_WARN("query on duckdb failed during execution: %s; query: %.500s",
1223+
duckdbError,
1224+
clientSession->pgSessionPreparedStmt.queryString);
12201225
status = DUCKDB_QUERY_ERROR;
12211226
}
12221227

pgduck_server/src/pgsession/pgsession.c

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -562,9 +562,10 @@ process_parse_message(PGSession * pgSession, StringInfo inputMessage)
562562
/* we have to raise errors to the client */
563563
int sentErrorMsg = handle_pgsession_error_message(status, pgSession, errorMessage);
564564

565-
PGDUCK_SERVER_WARN("query from client %d failed during parse: %s",
565+
PGDUCK_SERVER_WARN("query from client %d failed during parse: %s; query: %.500s",
566566
pgSession->pgClient->clientSocket,
567-
errorMessage);
567+
errorMessage,
568+
queryStringCopy);
568569

569570
/* free error message allocated by duckdb_session_prepare */
570571
pfree(errorMessage);
@@ -706,9 +707,10 @@ process_bind_message(PGSession * pgSession, StringInfo inputMessage)
706707
{
707708
int sentResult = handle_pgsession_error_message(bindResult, pgSession, errorMessage);
708709

709-
PGDUCK_SERVER_WARN("query from client %d failed during bind: %s",
710+
PGDUCK_SERVER_WARN("query from client %d failed during bind: %s; query: %.500s",
710711
pgSession->pgClient->clientSocket,
711-
errorMessage);
712+
errorMessage,
713+
pgSession->pgSessionPreparedStmt.queryString);
712714

713715
/* free error message allocated by duckdb_session_bind_varchar */
714716
pfree(errorMessage);

0 commit comments

Comments
 (0)