如何在PostgreSQL的postgres.c中打印parse、rewrite等流程的输入输出？用printf报错求助

Hey there! Let's work through adding debug logging for the parse/rewrite/plan/execute stages in PostgreSQL 11.1's src/backend/tcop/postgres.c—I get why using plain printf() might be causing issues, since PostgreSQL has its own logging and memory management systems that don't play nicely with standard C print functions. Let's fix this properly.

First, let's break down why your printf() attempts are failing:

• PostgreSQL runs as a background daemon, so stdout is often redirected to /dev/null or a non-interactive stream—you won't see the output in your terminal.
• Internal PostgreSQL structs (like Query or PlannedStmt) are complex and don't have simple string representations; printing them directly with printf() can cause memory access errors.
• PostgreSQL uses custom memory contexts, and printf() doesn't respect these, leading to potential crashes or unexpected behavior.

Instead, we'll use PostgreSQL's built-in logging functions (elog()/ereport()) and internal debug utilities to safely print stage details.

We'll focus on the ProcessQuery() function in postgres.c—this is the core entry point where the query lifecycle happens.

1. Parse Stage: Input SQL & Parsed Query Tree #

Find where parse_analyze() is called in ProcessQuery(), then add logging before and after:

// Before parsing: log the raw input SQL
elog(LOG, "=== Parse Stage Input ===");
elog(LOG, "Raw SQL: %s", query_string);

// Run the parser
Query *parsetree = parse_analyze(query_string, NULL, NULL);

// After parsing: log key details of the parsed Query struct
elog(LOG, "=== Parse Stage Output ===");
elog(LOG, "Query Command Type: %s", GetCommandName(parsetree->commandType));
elog(LOG, "Relation Target: %s", parsetree->relationName ? parsetree->relationName : "N/A");

• GetCommandName() converts the integer commandType (like CMD_SELECT, CMD_INSERT) to a human-readable string.
• We check if relationName exists before printing to avoid null pointer errors.

2. Rewrite Stage: Rewritten Query List #

Next, locate the rewriteQuery() call. This returns a List* of rewritten queries (for things like views or rules):

// Run the query rewriter
List *rewritten_queries = rewriteQuery(parsetree, NULL, NULL);

// Log the rewrite output
elog(LOG, "=== Rewrite Stage Output ===");
elog(LOG, "Number of rewritten queries: %d", list_length(rewritten_queries));

// Iterate through the list to log each query's type
ListCell *lc;
foreach(lc, rewritten_queries) {
    Query *q = (Query *) lfirst(lc);
    elog(LOG, "  Rewritten Query Type: %s", GetCommandName(q->commandType));
}

• foreach() is PostgreSQL's macro for iterating over list structures.
• lfirst() retrieves the element from the list cell.

3. Plan Stage: Generated Execution Plan #

Now find the planner() call, which returns a PlannedStmt*. We can log basic plan details or use PostgreSQL's built-in plan printer:

// First, include the print header at the top of postgres.c if not already present
#include "nodes/print.h"

// Run the planner
PlannedStmt *plan = planner(parsetree, NULL, NULL, 0, NULL);

// Log plan details
elog(LOG, "=== Plan Stage Output ===");
elog(LOG, "Plan Type: %d (0=normal, 1=utility, 2=portal)", plan->plan_type);
elog(LOG, "Has Sort Step: %s", (plan->plan->sortClause != NULL) ? "Yes" : "No");

// For detailed plan output (requires debug build), use print_plan()
elog(LOG, "Detailed Execution Plan:");
print_plan(plan->plan);

• print_plan() is a debug utility that prints the full execution tree to the logs. Make sure you compiled PostgreSQL with --enable-debug to use this.

4. Execute Stage: Execution Results #

Finally, locate the ExecutorRun() call. We can log row counts and tuple descriptor details:

// Run the executor (adjust the DestReceiver to match existing code in your version)
DestReceiver *dest = CreateDestReceiver(DestNone);
TupleDesc tupdesc = ExecutorRun(estate, plan, ForwardScanDirection, 0L, true, true);

// Log execution results
elog(LOG, "=== Execute Stage Output ===");
elog(LOG, "Result Tuple Columns: %d", tupdesc->natts);

// For write queries (INSERT/UPDATE/DELETE), log affected rows
if (parsetree->commandType == CMD_INSERT || 
    parsetree->commandType == CMD_UPDATE || 
    parsetree->commandType == CMD_DELETE) {
    elog(LOG, "Rows Affected: %lld", estate->es_processed);
}

• estate->es_processed tracks the number of rows modified by write operations.

1. After modifying postgres.c, recompile PostgreSQL:

   cd postgresql-11.1
   make clean
   ./configure --enable-debug  # Include this for full debug utilities
   make && make install
   

2. Restart your PostgreSQL service to load the updated binary.
3. Run a test query (e.g., SELECT * FROM your_table; or INSERT INTO your_table VALUES (1);).
4. Check your PostgreSQL log file (usually located in the data directory, named postgresql.log) to see the stage logs.

• Never leave these debug logs in a production environment—they'll hurt performance and bloat log files.
• If you need even more detail, use GDB to set breakpoints at each stage and inspect structs interactively.
• For simpler query logging (without stage details), you can enable log_statement = all in postgresql.conf, but that won't show you the internal parse/rewrite/plan outputs.

内容的提问来源于stack exchange，提问作者christine vincenza