lightdb for postgresql日志详解

　　log_min_messages：控制服务器日志级别，总控参数，log_min_error_statement要大于等于log_min_messages时，SQL语句才会被记录（默认ERROR，足够）。默认是WARNING，每个级别的定义如下：

 

 　　log_min_duration_statement：本质上的作用是记录慢日志，记录信息少，建议使用https://www.postgresql.org/docs/current/auto-explain.html（LightDB默认采用此）。log_duration则是为每个SQL语句记录执行时长，非常的耗性能，如果客户端使用扩展查询协议，则会记录解析、绑定、执行三个阶段的时间。所以，一般生产应该开log_min_duration_statement，关log_duration。

　　log_error_verbosity：log_min_messages控制了级别，log_error_verbosity控制对于每个要记录的日志，记录的详细程度，例如上下文、参数等，取值为TERSE, DEFAULT, 和VERBOSE。TERSE比DEFAULT少DETAIL, HINT, QUERY, CONTEXT，VERBOSE记录了SQLSTATE错误码以及记录日志的函数、c源文件名、以及行号，类似LOG4J。其实现在elog.c send_message_to_server_log方法中，详细的错误日志结构体为struct ErrorData。如下：

/*
 * ErrorData holds the data accumulated during any one ereport() cycle.
 * Any non-NULL pointers must point to palloc'd data.
 * (The const pointers are an exception; we assume they point at non-freeable
 * constant strings.)
 */
typedef struct ErrorData
{
    int            elevel;            /* error level */
    bool        output_to_server;    /* will report to server log? */
    bool        output_to_client;    /* will report to client? */
    bool        show_funcname;    /* true to force funcname inclusion */
    bool        hide_stmt;        /* true to prevent STATEMENT: inclusion */
    bool        hide_ctx;        /* true to prevent CONTEXT: inclusion */
    const char *filename;        /* __FILE__ of ereport() call */
    int            lineno;            /* __LINE__ of ereport() call */
    const char *funcname;        /* __func__ of ereport() call */
    const char *domain;            /* message domain */
    const char *context_domain; /* message domain for context message */
    int            sqlerrcode;        /* encoded ERRSTATE */
    char       *message;        /* primary error message (translated) */
    char       *detail;            /* detail error message */
    char       *detail_log;        /* detail error message for server log only */
    char       *hint;            /* hint message */
    char       *context;        /* context message */
    char       *backtrace;        /* backtrace */
    const char *message_id;        /* primary message's id (original string) */
    char       *schema_name;    /* name of schema */
    char       *table_name;        /* name of table */
    char       *column_name;    /* name of column */
    char       *datatype_name;    /* name of datatype */
    char       *constraint_name;    /* name of constraint */
    int            cursorpos;        /* cursor index into query string */
    int            internalpos;    /* cursor index into internalquery */
    char       *internalquery;    /* text of internally-generated query */
    int            saved_errno;    /* errno at entry */

    /* context containing associated non-constant strings */
    struct MemoryContextData *assoc_context;
} ErrorData;

 

/*
 * Write error report to server's log
 */
static void
send_message_to_server_log(ErrorData *edata)
{
    StringInfoData buf;

    initStringInfo(&buf);

    saved_timeval_set = false;
    formatted_log_time[0] = '\0';

    log_line_prefix(&buf, edata);
    appendStringInfo(&buf, "%s:  ", _(error_severity(edata->elevel)));

    if (Log_error_verbosity >= PGERROR_VERBOSE)
        appendStringInfo(&buf, "%s: ", unpack_sql_state(edata->sqlerrcode));

    if (edata->message)
        append_with_tabs(&buf, edata->message);
    else
        append_with_tabs(&buf, _("missing error text"));

    if (edata->cursorpos > 0)
        appendStringInfo(&buf, _(" at character %d"),
                         edata->cursorpos);
    else if (edata->internalpos > 0)
        appendStringInfo(&buf, _(" at character %d"),
                         edata->internalpos);

    appendStringInfoChar(&buf, '\n');

    if (Log_error_verbosity >= PGERROR_DEFAULT)
    {
        if (edata->detail_log)
        {
            log_line_prefix(&buf, edata);
            appendStringInfoString(&buf, _("DETAIL:  "));
            append_with_tabs(&buf, edata->detail_log);
            appendStringInfoChar(&buf, '\n');
        }
        else if (edata->detail)
        {
            log_line_prefix(&buf, edata);
            appendStringInfoString(&buf, _("DETAIL:  "));
            append_with_tabs(&buf, edata->detail);
            appendStringInfoChar(&buf, '\n');
        }
        if (edata->hint)
        {
            log_line_prefix(&buf, edata);
            appendStringInfoString(&buf, _("HINT:  "));
            append_with_tabs(&buf, edata->hint);
            appendStringInfoChar(&buf, '\n');
        }
        if (edata->internalquery)
        {
            log_line_prefix(&buf, edata);
            appendStringInfoString(&buf, _("QUERY:  "));
            append_with_tabs(&buf, edata->internalquery);
            appendStringInfoChar(&buf, '\n');
        }
        if (edata->context && !edata->hide_ctx)
        {
            log_line_prefix(&buf, edata);
            appendStringInfoString(&buf, _("CONTEXT:  "));
            append_with_tabs(&buf, edata->context);
            appendStringInfoChar(&buf, '\n');
        }
        if (Log_error_verbosity >= PGERROR_VERBOSE)
        {
            /* assume no newlines in funcname or filename... */
            if (edata->funcname && edata->filename)
            {
                log_line_prefix(&buf, edata);
                appendStringInfo(&buf, _("LOCATION:  %s, %s:%d\n"),   /*记录发生位置*/
                                 edata->funcname, edata->filename,
                                 edata->lineno);
            }
            else if (edata->filename)
            {
                log_line_prefix(&buf, edata);
                appendStringInfo(&buf, _("LOCATION:  %s:%d\n"),
                                 edata->filename, edata->lineno);
            }
        }
        if (edata->backtrace)
        {
            log_line_prefix(&buf, edata);
            appendStringInfoString(&buf, _("BACKTRACE:  "));
            append_with_tabs(&buf, edata->backtrace);
            appendStringInfoChar(&buf, '\n');
        }
    }

示例

2021-08-28 18:53:24.959351T pgbench zjh@postgres localhost(40546) client backend idle 00000 [2021-08-28 18:53:24 CST] 0 [143033] DEBUG:  00000: StartTransaction(1) name: unnamed; blockState: 
DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2021-08-28 18:53:24.959351T pgbench zjh@postgres localhost(40546) client backend idle 00000 [2021-08-28 18:53:24 CST] 0 [143033] LOCATION:  ShowTransactionStateRec, xact.c:5351
2021-08-28 18:53:24.959351T pgbench zjh@postgres localhost(40546) client backend idle 00000 [2021-08-28 18:53:24 CST] 0 [143033] STATEMENT:  begin
2021-08-28 18:53:24.959379T pgbench zjh@postgres localhost(40546) client backend idle 00000 [2021-08-28 18:53:24 CST] 0 [143033] LOG:  00000: statement: begin
2021-08-28 18:53:24.959379T pgbench zjh@postgres localhost(40546) client backend idle 00000 [2021-08-28 18:53:24 CST] 0 [143033] LOCATION:  exec_simple_query, postgres.c:1044
2021-08-28 18:53:24.959403T pgbench zjh@postgres localhost(40546) client backend BEGIN 00000 [2021-08-28 18:53:24 CST] 0 [143033] LOG:  00000: parse tree:
2021-08-28 18:53:24.959403T pgbench zjh@postgres localhost(40546) client backend BEGIN 00000 [2021-08-28 18:53:24 CST] 0 [143033] DETAIL:     {QUERY 
	   :commandType 5 
	   :querySource 0 
	   :canSetTag true 
	   :utilityStmt ? 
	   :resultRelation 0 
	   :hasAggs false 
	   :hasWindowFuncs false 
	   :hasTargetSRFs false 
	   :hasSubLinks false 
	   :hasDistinctOn false 
	   :hasRecursive false 
	   :hasModifyingCTE false 
	   :hasForUpdate false 
	   :hasRowSecurity false 
	   :cteList <> 
	   :rtable <> 
	   :jointree <> 
	   :targetList <> 
	   :override 0 
	   :onConflict <> 
	   :returningList <> 
	   :groupClause <> 
	   :groupingSets <> 
	   :havingQual <> 
	   :windowClause <> 
	   :distinctClause <> 
	   :sortClause <> 
	   :limitOffset <> 
	   :limitCount <> 
	   :limitOption 0 
	   :rowMarks <> 
	   :setOperations <> 
	   :constraintDeps <> 
	   :withCheckOptions <> 
	   :stmt_location 0 
	   :stmt_len 0
	   }
	
2021-08-28 18:53:24.959403T pgbench zjh@postgres localhost(40546) client backend BEGIN 00000 [2021-08-28 18:53:24 CST] 0 [143033] LOCATION:  elog_node_display, print.c:85

2021-08-28 19:01:46.087410T  @  autovacuum worker  00000 [2021-08-28 19:01:45 CST] 0 [143957] DEBUG:  00000: "pgbench_history": found 0 removable, 21724 nonremovable row versions in 139 out of 139 pages
2021-08-28 19:01:46.087410T  @  autovacuum worker  00000 [2021-08-28 19:01:45 CST] 0 [143957] DETAIL:  0 dead row versions cannot be removed yet, oldest xmin: 23145
	There were 0 unused item identifiers.
	Skipped 0 pages due to buffer pins, 0 frozen pages.
	0 pages are entirely empty.
	CPU: user: 0.01 s, system: 0.00 s, elapsed: 0.01 s.
2021-08-28 19:01:46.087410T  @  autovacuum worker  00000 [2021-08-28 19:01:45 CST] 0 [143957] CONTEXT:  while scanning relation "public.pgbench_history"

LightDB 21.3将增加参数 log_retention_days 控制自动清理日志文件

参考：

pg日志总结详解 https://docs.aws.amazon.com/AmazonRDS/latest/UserGuide/USER_LogAccess.Concepts.PostgreSQL.html
https://www.postgresql.org/docs/current/runtime-config-logging.html