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