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