Age Owner TLA Line data Source code
1 : /*-------------------------------------------------------------------------
2 : *
3 : * jsonlog.c
4 : * JSON logging
5 : *
6 : * Portions Copyright (c) 1996-2023, PostgreSQL Global Development Group
7 : * Portions Copyright (c) 1994, Regents of the University of California
8 : *
9 : *
10 : * IDENTIFICATION
11 : * src/backend/utils/error/jsonlog.c
12 : *
13 : *-------------------------------------------------------------------------
14 : */
15 :
16 : #include "postgres.h"
17 :
18 : #include "access/xact.h"
19 : #include "libpq/libpq.h"
20 : #include "lib/stringinfo.h"
21 : #include "miscadmin.h"
22 : #include "postmaster/bgworker.h"
23 : #include "postmaster/syslogger.h"
24 : #include "storage/lock.h"
25 : #include "storage/proc.h"
26 : #include "tcop/tcopprot.h"
27 : #include "utils/backend_status.h"
28 : #include "utils/elog.h"
29 : #include "utils/guc.h"
30 : #include "utils/json.h"
31 : #include "utils/ps_status.h"
32 :
33 : static void appendJSONKeyValueFmt(StringInfo buf, const char *key,
34 : bool escape_key,
35 : const char *fmt,...) pg_attribute_printf(4, 5);
36 :
37 : /*
38 : * appendJSONKeyValue
39 : *
40 : * Append to a StringInfo a comma followed by a JSON key and a value.
41 : * The key is always escaped. The value can be escaped optionally, that
42 : * is dependent on the data type of the key.
43 : */
44 : static void
447 michael 45 CBC 259 : appendJSONKeyValue(StringInfo buf, const char *key, const char *value,
46 : bool escape_value)
47 : {
48 259 : Assert(key != NULL);
49 :
50 259 : if (value == NULL)
51 20 : return;
52 :
53 239 : appendStringInfoChar(buf, ',');
54 239 : escape_json(buf, key);
55 239 : appendStringInfoChar(buf, ':');
56 :
57 239 : if (escape_value)
58 158 : escape_json(buf, value);
59 : else
60 81 : appendStringInfoString(buf, value);
61 : }
62 :
63 :
64 : /*
65 : * appendJSONKeyValueFmt
66 : *
67 : * Evaluate the fmt string and then invoke appendJSONKeyValue() as the
68 : * value of the JSON property. Both the key and value will be escaped by
69 : * appendJSONKeyValue().
70 : */
71 : static void
72 110 : appendJSONKeyValueFmt(StringInfo buf, const char *key,
73 : bool escape_key, const char *fmt,...)
74 : {
75 110 : int save_errno = errno;
76 110 : size_t len = 128; /* initial assumption about buffer size */
77 : char *value;
78 :
79 : for (;;)
447 michael 80 UBC 0 : {
81 : va_list args;
82 : size_t newlen;
83 :
84 : /* Allocate result buffer */
447 michael 85 CBC 110 : value = (char *) palloc(len);
86 :
87 : /* Try to format the data. */
88 110 : errno = save_errno;
89 110 : va_start(args, fmt);
90 110 : newlen = pvsnprintf(value, len, fmt, args);
91 110 : va_end(args);
92 :
93 110 : if (newlen < len)
94 110 : break; /* success */
95 :
96 : /* Release buffer and loop around to try again with larger len. */
447 michael 97 UBC 0 : pfree(value);
98 0 : len = newlen;
99 : }
100 :
447 michael 101 CBC 110 : appendJSONKeyValue(buf, key, value, escape_key);
102 :
103 : /* Clean up */
104 110 : pfree(value);
105 110 : }
106 :
107 : /*
108 : * Write logs in json format.
109 : */
110 : void
111 20 : write_jsonlog(ErrorData *edata)
112 : {
113 : StringInfoData buf;
114 : char *start_time;
115 : char *log_time;
116 :
117 : /* static counter for line numbers */
118 : static long log_line_number = 0;
119 :
120 : /* Has the counter been reset in the current process? */
121 : static int log_my_pid = 0;
122 :
123 : /*
124 : * This is one of the few places where we'd rather not inherit a static
125 : * variable's value from the postmaster. But since we will, reset it when
126 : * MyProcPid changes.
127 : */
128 20 : if (log_my_pid != MyProcPid)
129 : {
130 11 : log_line_number = 0;
131 11 : log_my_pid = MyProcPid;
132 11 : reset_formatted_start_time();
133 : }
134 20 : log_line_number++;
135 :
136 20 : initStringInfo(&buf);
137 :
138 : /* Initialize string */
139 20 : appendStringInfoChar(&buf, '{');
140 :
141 : /* timestamp with milliseconds */
142 20 : log_time = get_formatted_log_time();
143 :
144 : /*
145 : * First property does not use appendJSONKeyValue as it does not have
146 : * comma prefix.
147 : */
148 20 : escape_json(&buf, "timestamp");
149 20 : appendStringInfoChar(&buf, ':');
150 20 : escape_json(&buf, log_time);
151 :
152 : /* username */
153 20 : if (MyProcPort)
154 9 : appendJSONKeyValue(&buf, "user", MyProcPort->user_name, true);
155 :
156 : /* database name */
157 20 : if (MyProcPort)
158 9 : appendJSONKeyValue(&buf, "dbname", MyProcPort->database_name, true);
159 :
160 : /* Process ID */
161 20 : if (MyProcPid != 0)
162 20 : appendJSONKeyValueFmt(&buf, "pid", false, "%d", MyProcPid);
163 :
164 : /* Remote host and port */
165 20 : if (MyProcPort && MyProcPort->remote_host)
166 : {
167 9 : appendJSONKeyValue(&buf, "remote_host", MyProcPort->remote_host, true);
168 9 : if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0')
447 michael 169 UBC 0 : appendJSONKeyValue(&buf, "remote_port", MyProcPort->remote_port, false);
170 : }
171 :
172 : /* Session id */
447 michael 173 CBC 20 : appendJSONKeyValueFmt(&buf, "session_id", true, "%lx.%x",
174 : (long) MyStartTime, MyProcPid);
175 :
176 : /* Line number */
177 20 : appendJSONKeyValueFmt(&buf, "line_num", false, "%ld", log_line_number);
178 :
179 : /* PS display */
180 20 : if (MyProcPort)
181 : {
182 : StringInfoData msgbuf;
183 : const char *psdisp;
184 : int displen;
185 :
186 9 : initStringInfo(&msgbuf);
187 9 : psdisp = get_ps_display(&displen);
188 9 : appendBinaryStringInfo(&msgbuf, psdisp, displen);
189 9 : appendJSONKeyValue(&buf, "ps", msgbuf.data, true);
190 :
191 9 : pfree(msgbuf.data);
192 : }
193 :
194 : /* session start timestamp */
195 20 : start_time = get_formatted_start_time();
196 20 : appendJSONKeyValue(&buf, "session_start", start_time, true);
197 :
198 : /* Virtual transaction id */
199 : /* keep VXID format in sync with lockfuncs.c */
200 20 : if (MyProc != NULL && MyProc->backendId != InvalidBackendId)
201 9 : appendJSONKeyValueFmt(&buf, "vxid", true, "%d/%u", MyProc->backendId,
202 9 : MyProc->lxid);
203 :
204 : /* Transaction id */
205 20 : appendJSONKeyValueFmt(&buf, "txid", false, "%u",
206 : GetTopTransactionIdIfAny());
207 :
208 : /* Error severity */
209 20 : if (edata->elevel)
210 20 : appendJSONKeyValue(&buf, "error_severity",
211 : (char *) error_severity(edata->elevel), true);
212 :
213 : /* SQL state code */
214 20 : if (edata->sqlerrcode)
215 2 : appendJSONKeyValue(&buf, "state_code",
216 2 : unpack_sql_state(edata->sqlerrcode), true);
217 :
218 : /* errmessage */
219 20 : appendJSONKeyValue(&buf, "message", edata->message, true);
220 :
221 : /* errdetail or error_detail log */
222 20 : if (edata->detail_log)
447 michael 223 UBC 0 : appendJSONKeyValue(&buf, "detail", edata->detail_log, true);
224 : else
447 michael 225 CBC 20 : appendJSONKeyValue(&buf, "detail", edata->detail, true);
226 :
227 : /* errhint */
228 20 : if (edata->hint)
447 michael 229 UBC 0 : appendJSONKeyValue(&buf, "hint", edata->hint, true);
230 :
231 : /* internal query */
447 michael 232 CBC 20 : if (edata->internalquery)
447 michael 233 UBC 0 : appendJSONKeyValue(&buf, "internal_query", edata->internalquery,
234 : true);
235 :
236 : /* if printed internal query, print internal pos too */
447 michael 237 CBC 20 : if (edata->internalpos > 0 && edata->internalquery != NULL)
361 peter 238 UBC 0 : appendJSONKeyValueFmt(&buf, "internal_position", false, "%d",
239 : edata->internalpos);
240 :
241 : /* errcontext */
447 michael 242 CBC 20 : if (edata->context && !edata->hide_ctx)
447 michael 243 UBC 0 : appendJSONKeyValue(&buf, "context", edata->context, true);
244 :
245 : /* user query --- only reported if not disabled by the caller */
447 michael 246 CBC 20 : if (check_log_of_query(edata))
247 : {
248 2 : appendJSONKeyValue(&buf, "statement", debug_query_string, true);
249 2 : if (edata->cursorpos > 0)
250 1 : appendJSONKeyValueFmt(&buf, "cursor_position", false, "%d",
251 : edata->cursorpos);
252 : }
253 :
254 : /* file error location */
255 20 : if (Log_error_verbosity >= PGERROR_VERBOSE)
256 : {
447 michael 257 UBC 0 : if (edata->funcname)
258 0 : appendJSONKeyValue(&buf, "func_name", edata->funcname, true);
259 0 : if (edata->filename)
260 : {
261 0 : appendJSONKeyValue(&buf, "file_name", edata->filename, true);
262 0 : appendJSONKeyValueFmt(&buf, "file_line_num", false, "%d",
263 : edata->lineno);
264 : }
265 : }
266 :
267 : /* Application name */
447 michael 268 CBC 20 : if (application_name && application_name[0] != '\0')
269 9 : appendJSONKeyValue(&buf, "application_name", application_name, true);
270 :
271 : /* backend type */
272 20 : appendJSONKeyValue(&buf, "backend_type", get_backend_type_for_log(), true);
273 :
274 : /* leader PID */
275 20 : if (MyProc)
276 : {
277 13 : PGPROC *leader = MyProc->lockGroupLeader;
278 :
279 : /*
280 : * Show the leader only for active parallel workers. This leaves out
281 : * the leader of a parallel group.
282 : */
283 13 : if (leader && leader->pid != MyProcPid)
447 michael 284 UBC 0 : appendJSONKeyValueFmt(&buf, "leader_pid", false, "%d",
285 : leader->pid);
286 : }
287 :
288 : /* query id */
447 michael 289 CBC 20 : appendJSONKeyValueFmt(&buf, "query_id", false, "%lld",
290 20 : (long long) pgstat_get_my_query_id());
291 :
292 : /* Finish string */
293 20 : appendStringInfoChar(&buf, '}');
294 20 : appendStringInfoChar(&buf, '\n');
295 :
296 : /* If in the syslogger process, try to write messages direct to file */
297 20 : if (MyBackendType == B_LOGGER)
447 michael 298 UBC 0 : write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_JSONLOG);
299 : else
447 michael 300 CBC 20 : write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_JSONLOG);
301 :
302 20 : pfree(buf.data);
303 20 : }
|
