/src/postgres/src/backend/utils/error/jsonlog.c
Line | Count | Source (jump to first uncovered line) |
1 | | /*------------------------------------------------------------------------- |
2 | | * |
3 | | * jsonlog.c |
4 | | * JSON logging |
5 | | * |
6 | | * Portions Copyright (c) 1996-2025, 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 | | appendJSONKeyValue(StringInfo buf, const char *key, const char *value, |
44 | | bool escape_value) |
45 | 0 | { |
46 | 0 | Assert(key != NULL); |
47 | |
|
48 | 0 | if (value == NULL) |
49 | 0 | return; |
50 | | |
51 | 0 | appendStringInfoChar(buf, ','); |
52 | 0 | escape_json(buf, key); |
53 | 0 | appendStringInfoChar(buf, ':'); |
54 | |
|
55 | 0 | if (escape_value) |
56 | 0 | escape_json(buf, value); |
57 | 0 | else |
58 | 0 | appendStringInfoString(buf, value); |
59 | 0 | } |
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 | | appendJSONKeyValueFmt(StringInfo buf, const char *key, |
71 | | bool escape_key, const char *fmt,...) |
72 | 0 | { |
73 | 0 | int save_errno = errno; |
74 | 0 | size_t len = 128; /* initial assumption about buffer size */ |
75 | 0 | char *value; |
76 | |
|
77 | 0 | for (;;) |
78 | 0 | { |
79 | 0 | va_list args; |
80 | 0 | size_t newlen; |
81 | | |
82 | | /* Allocate result buffer */ |
83 | 0 | value = (char *) palloc(len); |
84 | | |
85 | | /* Try to format the data. */ |
86 | 0 | errno = save_errno; |
87 | 0 | va_start(args, fmt); |
88 | 0 | newlen = pvsnprintf(value, len, fmt, args); |
89 | 0 | va_end(args); |
90 | |
|
91 | 0 | if (newlen < len) |
92 | 0 | break; /* success */ |
93 | | |
94 | | /* Release buffer and loop around to try again with larger len. */ |
95 | 0 | pfree(value); |
96 | 0 | len = newlen; |
97 | 0 | } |
98 | |
|
99 | 0 | appendJSONKeyValue(buf, key, value, escape_key); |
100 | | |
101 | | /* Clean up */ |
102 | 0 | pfree(value); |
103 | 0 | } |
104 | | |
105 | | /* |
106 | | * Write logs in json format. |
107 | | */ |
108 | | void |
109 | | write_jsonlog(ErrorData *edata) |
110 | 0 | { |
111 | 0 | StringInfoData buf; |
112 | 0 | char *start_time; |
113 | 0 | char *log_time; |
114 | | |
115 | | /* static counter for line numbers */ |
116 | 0 | static long log_line_number = 0; |
117 | | |
118 | | /* Has the counter been reset in the current process? */ |
119 | 0 | 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 | 0 | if (log_my_pid != MyProcPid) |
127 | 0 | { |
128 | 0 | log_line_number = 0; |
129 | 0 | log_my_pid = MyProcPid; |
130 | 0 | reset_formatted_start_time(); |
131 | 0 | } |
132 | 0 | log_line_number++; |
133 | |
|
134 | 0 | initStringInfo(&buf); |
135 | | |
136 | | /* Initialize string */ |
137 | 0 | appendStringInfoChar(&buf, '{'); |
138 | | |
139 | | /* timestamp with milliseconds */ |
140 | 0 | 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 | 0 | escape_json(&buf, "timestamp"); |
147 | 0 | appendStringInfoChar(&buf, ':'); |
148 | 0 | escape_json(&buf, log_time); |
149 | | |
150 | | /* username */ |
151 | 0 | if (MyProcPort) |
152 | 0 | appendJSONKeyValue(&buf, "user", MyProcPort->user_name, true); |
153 | | |
154 | | /* database name */ |
155 | 0 | if (MyProcPort) |
156 | 0 | appendJSONKeyValue(&buf, "dbname", MyProcPort->database_name, true); |
157 | | |
158 | | /* Process ID */ |
159 | 0 | if (MyProcPid != 0) |
160 | 0 | appendJSONKeyValueFmt(&buf, "pid", false, "%d", MyProcPid); |
161 | | |
162 | | /* Remote host and port */ |
163 | 0 | if (MyProcPort && MyProcPort->remote_host) |
164 | 0 | { |
165 | 0 | appendJSONKeyValue(&buf, "remote_host", MyProcPort->remote_host, true); |
166 | 0 | if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0') |
167 | 0 | appendJSONKeyValue(&buf, "remote_port", MyProcPort->remote_port, false); |
168 | 0 | } |
169 | | |
170 | | /* Session id */ |
171 | 0 | appendJSONKeyValueFmt(&buf, "session_id", true, INT64_HEX_FORMAT ".%x", |
172 | 0 | MyStartTime, MyProcPid); |
173 | | |
174 | | /* Line number */ |
175 | 0 | appendJSONKeyValueFmt(&buf, "line_num", false, "%ld", log_line_number); |
176 | | |
177 | | /* PS display */ |
178 | 0 | if (MyProcPort) |
179 | 0 | { |
180 | 0 | StringInfoData msgbuf; |
181 | 0 | const char *psdisp; |
182 | 0 | int displen; |
183 | |
|
184 | 0 | initStringInfo(&msgbuf); |
185 | 0 | psdisp = get_ps_display(&displen); |
186 | 0 | appendBinaryStringInfo(&msgbuf, psdisp, displen); |
187 | 0 | appendJSONKeyValue(&buf, "ps", msgbuf.data, true); |
188 | |
|
189 | 0 | pfree(msgbuf.data); |
190 | 0 | } |
191 | | |
192 | | /* session start timestamp */ |
193 | 0 | start_time = get_formatted_start_time(); |
194 | 0 | appendJSONKeyValue(&buf, "session_start", start_time, true); |
195 | | |
196 | | /* Virtual transaction id */ |
197 | | /* keep VXID format in sync with lockfuncs.c */ |
198 | 0 | if (MyProc != NULL && MyProc->vxid.procNumber != INVALID_PROC_NUMBER) |
199 | 0 | appendJSONKeyValueFmt(&buf, "vxid", true, "%d/%u", |
200 | 0 | MyProc->vxid.procNumber, MyProc->vxid.lxid); |
201 | | |
202 | | /* Transaction id */ |
203 | 0 | appendJSONKeyValueFmt(&buf, "txid", false, "%u", |
204 | 0 | GetTopTransactionIdIfAny()); |
205 | | |
206 | | /* Error severity */ |
207 | 0 | if (edata->elevel) |
208 | 0 | appendJSONKeyValue(&buf, "error_severity", |
209 | 0 | error_severity(edata->elevel), true); |
210 | | |
211 | | /* SQL state code */ |
212 | 0 | if (edata->sqlerrcode) |
213 | 0 | appendJSONKeyValue(&buf, "state_code", |
214 | 0 | unpack_sql_state(edata->sqlerrcode), true); |
215 | | |
216 | | /* errmessage */ |
217 | 0 | appendJSONKeyValue(&buf, "message", edata->message, true); |
218 | | |
219 | | /* errdetail or error_detail log */ |
220 | 0 | if (edata->detail_log) |
221 | 0 | appendJSONKeyValue(&buf, "detail", edata->detail_log, true); |
222 | 0 | else |
223 | 0 | appendJSONKeyValue(&buf, "detail", edata->detail, true); |
224 | | |
225 | | /* errhint */ |
226 | 0 | if (edata->hint) |
227 | 0 | appendJSONKeyValue(&buf, "hint", edata->hint, true); |
228 | | |
229 | | /* internal query */ |
230 | 0 | if (edata->internalquery) |
231 | 0 | appendJSONKeyValue(&buf, "internal_query", edata->internalquery, |
232 | 0 | true); |
233 | | |
234 | | /* if printed internal query, print internal pos too */ |
235 | 0 | if (edata->internalpos > 0 && edata->internalquery != NULL) |
236 | 0 | appendJSONKeyValueFmt(&buf, "internal_position", false, "%d", |
237 | 0 | edata->internalpos); |
238 | | |
239 | | /* errcontext */ |
240 | 0 | 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 | 0 | if (check_log_of_query(edata)) |
245 | 0 | { |
246 | 0 | appendJSONKeyValue(&buf, "statement", debug_query_string, true); |
247 | 0 | if (edata->cursorpos > 0) |
248 | 0 | appendJSONKeyValueFmt(&buf, "cursor_position", false, "%d", |
249 | 0 | edata->cursorpos); |
250 | 0 | } |
251 | | |
252 | | /* file error location */ |
253 | 0 | if (Log_error_verbosity >= PGERROR_VERBOSE) |
254 | 0 | { |
255 | 0 | if (edata->funcname) |
256 | 0 | appendJSONKeyValue(&buf, "func_name", edata->funcname, true); |
257 | 0 | if (edata->filename) |
258 | 0 | { |
259 | 0 | appendJSONKeyValue(&buf, "file_name", edata->filename, true); |
260 | 0 | appendJSONKeyValueFmt(&buf, "file_line_num", false, "%d", |
261 | 0 | edata->lineno); |
262 | 0 | } |
263 | 0 | } |
264 | | |
265 | | /* Application name */ |
266 | 0 | if (application_name && application_name[0] != '\0') |
267 | 0 | appendJSONKeyValue(&buf, "application_name", application_name, true); |
268 | | |
269 | | /* backend type */ |
270 | 0 | appendJSONKeyValue(&buf, "backend_type", get_backend_type_for_log(), true); |
271 | | |
272 | | /* leader PID */ |
273 | 0 | if (MyProc) |
274 | 0 | { |
275 | 0 | 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 | 0 | if (leader && leader->pid != MyProcPid) |
282 | 0 | appendJSONKeyValueFmt(&buf, "leader_pid", false, "%d", |
283 | 0 | leader->pid); |
284 | 0 | } |
285 | | |
286 | | /* query id */ |
287 | 0 | appendJSONKeyValueFmt(&buf, "query_id", false, "%" PRId64, |
288 | 0 | pgstat_get_my_query_id()); |
289 | | |
290 | | /* Finish string */ |
291 | 0 | appendStringInfoChar(&buf, '}'); |
292 | 0 | appendStringInfoChar(&buf, '\n'); |
293 | | |
294 | | /* If in the syslogger process, try to write messages direct to file */ |
295 | 0 | if (MyBackendType == B_LOGGER) |
296 | 0 | write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_JSONLOG); |
297 | 0 | else |
298 | 0 | write_pipe_chunks(buf.data, buf.len, LOG_DESTINATION_JSONLOG); |
299 | |
|
300 | 0 | pfree(buf.data); |
301 | 0 | } |