TLA Line data Source code
1 : /*-------------------------------------------------------------------------
2 : *
3 : * fe-trace.c
4 : * functions for libpq protocol tracing
5 : *
6 : * Portions Copyright (c) 1996-2023, PostgreSQL Global Development Group
7 : * Portions Copyright (c) 1994, Regents of the University of California
8 : *
9 : * IDENTIFICATION
10 : * src/interfaces/libpq/fe-trace.c
11 : *
12 : *-------------------------------------------------------------------------
13 : */
14 :
15 : #include "postgres_fe.h"
16 :
17 : #include <ctype.h>
18 : #include <limits.h>
19 : #include <sys/time.h>
20 : #include <time.h>
21 :
22 : #ifdef WIN32
23 : #include "win32.h"
24 : #else
25 : #include <unistd.h>
26 : #endif
27 :
28 : #include "libpq-fe.h"
29 : #include "libpq-int.h"
30 : #include "port/pg_bswap.h"
31 :
32 :
33 : /* Enable tracing */
34 : void
35 CBC 9 : PQtrace(PGconn *conn, FILE *debug_port)
36 : {
37 9 : if (conn == NULL)
38 UBC 0 : return;
39 CBC 9 : PQuntrace(conn);
40 9 : if (debug_port == NULL)
41 UBC 0 : return;
42 :
43 CBC 9 : conn->Pfdebug = debug_port;
44 9 : conn->traceFlags = 0;
45 : }
46 :
47 : /* Disable tracing */
48 : void
49 9 : PQuntrace(PGconn *conn)
50 : {
51 9 : if (conn == NULL)
52 UBC 0 : return;
53 CBC 9 : if (conn->Pfdebug)
54 : {
55 UBC 0 : fflush(conn->Pfdebug);
56 0 : conn->Pfdebug = NULL;
57 : }
58 :
59 CBC 9 : conn->traceFlags = 0;
60 : }
61 :
62 : /* Set flags for current tracing session */
63 : void
64 9 : PQsetTraceFlags(PGconn *conn, int flags)
65 : {
66 9 : if (conn == NULL)
67 UBC 0 : return;
68 : /* If PQtrace() failed, do nothing. */
69 CBC 9 : if (conn->Pfdebug == NULL)
70 UBC 0 : return;
71 CBC 9 : conn->traceFlags = flags;
72 : }
73 :
74 : /*
75 : * Print the current time, with microseconds, into a caller-supplied
76 : * buffer.
77 : * Cribbed from setup_formatted_log_time, but much simpler.
78 : */
79 : static void
80 UBC 0 : pqTraceFormatTimestamp(char *timestr, size_t ts_len)
81 : {
82 : struct timeval tval;
83 : time_t now;
84 :
85 0 : gettimeofday(&tval, NULL);
86 :
87 : /*
88 : * MSVC's implementation of timeval uses a long for tv_sec, however,
89 : * localtime() expects a time_t pointer. Here we'll assign tv_sec to a
90 : * local time_t variable so that we pass localtime() the correct pointer
91 : * type.
92 : */
93 0 : now = tval.tv_sec;
94 0 : strftime(timestr, ts_len,
95 : "%Y-%m-%d %H:%M:%S",
96 0 : localtime(&now));
97 : /* append microseconds */
98 0 : snprintf(timestr + strlen(timestr), ts_len - strlen(timestr),
99 0 : ".%06u", (unsigned int) (tval.tv_usec));
100 0 : }
101 :
102 : /*
103 : * pqTraceOutputByte1: output a 1-char message to the log
104 : */
105 : static void
106 CBC 124 : pqTraceOutputByte1(FILE *pfdebug, const char *data, int *cursor)
107 : {
108 124 : const char *v = data + *cursor;
109 :
110 : /*
111 : * Show non-printable data in hex format, including the terminating \0
112 : * that completes ErrorResponse and NoticeResponse messages.
113 : */
114 124 : if (!isprint((unsigned char) *v))
115 8 : fprintf(pfdebug, " \\x%02x", *v);
116 : else
117 116 : fprintf(pfdebug, " %c", *v);
118 124 : *cursor += 1;
119 124 : }
120 :
121 : /*
122 : * pqTraceOutputInt16: output a 2-byte integer message to the log
123 : */
124 : static int
125 324 : pqTraceOutputInt16(FILE *pfdebug, const char *data, int *cursor)
126 : {
127 : uint16 tmp;
128 : int result;
129 :
130 324 : memcpy(&tmp, data + *cursor, 2);
131 324 : *cursor += 2;
132 324 : result = (int) pg_ntoh16(tmp);
133 324 : fprintf(pfdebug, " %d", result);
134 :
135 324 : return result;
136 : }
137 :
138 : /*
139 : * pqTraceOutputInt32: output a 4-byte integer message to the log
140 : *
141 : * If 'suppress' is true, print a literal NNNN instead of the actual number.
142 : */
143 : static int
144 179 : pqTraceOutputInt32(FILE *pfdebug, const char *data, int *cursor, bool suppress)
145 : {
146 : int result;
147 :
148 179 : memcpy(&result, data + *cursor, 4);
149 179 : *cursor += 4;
150 179 : result = (int) pg_ntoh32(result);
151 179 : if (suppress)
152 69 : fprintf(pfdebug, " NNNN");
153 : else
154 110 : fprintf(pfdebug, " %d", result);
155 :
156 179 : return result;
157 : }
158 :
159 : /*
160 : * pqTraceOutputString: output a string message to the log
161 : */
162 : static void
163 337 : pqTraceOutputString(FILE *pfdebug, const char *data, int *cursor, bool suppress)
164 : {
165 : int len;
166 :
167 337 : if (suppress)
168 : {
169 24 : fprintf(pfdebug, " \"SSSS\"");
170 24 : *cursor += strlen(data + *cursor) + 1;
171 : }
172 : else
173 : {
174 313 : len = fprintf(pfdebug, " \"%s\"", data + *cursor);
175 :
176 : /*
177 : * This is a null-terminated string. So add 1 after subtracting 3
178 : * which is the double quotes and space length from len.
179 : */
180 313 : *cursor += (len - 3 + 1);
181 : }
182 337 : }
183 :
184 : /*
185 : * pqTraceOutputNchar: output a string of exactly len bytes message to the log
186 : */
187 : static void
188 46 : pqTraceOutputNchar(FILE *pfdebug, int len, const char *data, int *cursor)
189 : {
190 : int i,
191 : next; /* first char not yet printed */
192 46 : const char *v = data + *cursor;
193 :
194 46 : fprintf(pfdebug, " \'");
195 :
196 760 : for (next = i = 0; i < len; ++i)
197 : {
198 714 : if (isprint((unsigned char) v[i]))
199 714 : continue;
200 : else
201 : {
202 UBC 0 : fwrite(v + next, 1, i - next, pfdebug);
203 0 : fprintf(pfdebug, "\\x%02x", v[i]);
204 0 : next = i + 1;
205 : }
206 : }
207 CBC 46 : if (next < len)
208 46 : fwrite(v + next, 1, len - next, pfdebug);
209 :
210 46 : fprintf(pfdebug, "\'");
211 46 : *cursor += len;
212 46 : }
213 :
214 : /*
215 : * Output functions by protocol message type
216 : */
217 :
218 : /* NotificationResponse */
219 : static void
220 UBC 0 : pqTraceOutputA(FILE *f, const char *message, int *cursor, bool regress)
221 : {
222 0 : fprintf(f, "NotificationResponse\t");
223 0 : pqTraceOutputInt32(f, message, cursor, regress);
224 0 : pqTraceOutputString(f, message, cursor, false);
225 0 : pqTraceOutputString(f, message, cursor, false);
226 0 : }
227 :
228 : /* Bind */
229 : static void
230 CBC 34 : pqTraceOutputB(FILE *f, const char *message, int *cursor)
231 : {
232 : int nparams;
233 :
234 34 : fprintf(f, "Bind\t");
235 34 : pqTraceOutputString(f, message, cursor, false);
236 34 : pqTraceOutputString(f, message, cursor, false);
237 34 : nparams = pqTraceOutputInt16(f, message, cursor);
238 :
239 34 : for (int i = 0; i < nparams; i++)
240 UBC 0 : pqTraceOutputInt16(f, message, cursor);
241 :
242 CBC 34 : nparams = pqTraceOutputInt16(f, message, cursor);
243 :
244 44 : for (int i = 0; i < nparams; i++)
245 : {
246 : int nbytes;
247 :
248 10 : nbytes = pqTraceOutputInt32(f, message, cursor, false);
249 10 : if (nbytes == -1)
250 UBC 0 : continue;
251 CBC 10 : pqTraceOutputNchar(f, nbytes, message, cursor);
252 : }
253 :
254 34 : nparams = pqTraceOutputInt16(f, message, cursor);
255 68 : for (int i = 0; i < nparams; i++)
256 34 : pqTraceOutputInt16(f, message, cursor);
257 34 : }
258 :
259 : /* Close(F) or CommandComplete(B) */
260 : static void
261 35 : pqTraceOutputC(FILE *f, bool toServer, const char *message, int *cursor)
262 : {
263 35 : if (toServer)
264 : {
265 UBC 0 : fprintf(f, "Close\t");
266 0 : pqTraceOutputByte1(f, message, cursor);
267 0 : pqTraceOutputString(f, message, cursor, false);
268 : }
269 : else
270 : {
271 CBC 35 : fprintf(f, "CommandComplete\t");
272 35 : pqTraceOutputString(f, message, cursor, false);
273 : }
274 35 : }
275 :
276 : /* Describe(F) or DataRow(B) */
277 : static void
278 72 : pqTraceOutputD(FILE *f, bool toServer, const char *message, int *cursor)
279 : {
280 72 : if (toServer)
281 : {
282 36 : fprintf(f, "Describe\t");
283 36 : pqTraceOutputByte1(f, message, cursor);
284 36 : pqTraceOutputString(f, message, cursor, false);
285 : }
286 : else
287 : {
288 : int nfields;
289 : int len;
290 : int i;
291 :
292 36 : fprintf(f, "DataRow\t");
293 36 : nfields = pqTraceOutputInt16(f, message, cursor);
294 72 : for (i = 0; i < nfields; i++)
295 : {
296 36 : len = pqTraceOutputInt32(f, message, cursor, false);
297 36 : if (len == -1)
298 UBC 0 : continue;
299 CBC 36 : pqTraceOutputNchar(f, len, message, cursor);
300 : }
301 : }
302 72 : }
303 :
304 : /* NoticeResponse / ErrorResponse */
305 : static void
306 8 : pqTraceOutputNR(FILE *f, const char *type, const char *message, int *cursor,
307 : bool regress)
308 : {
309 8 : fprintf(f, "%s\t", type);
310 : for (;;)
311 58 : {
312 : char field;
313 : bool suppress;
314 :
315 66 : pqTraceOutputByte1(f, message, cursor);
316 66 : field = message[*cursor - 1];
317 66 : if (field == '\0')
318 8 : break;
319 :
320 58 : suppress = regress && (field == 'L' || field == 'F' || field == 'R');
321 58 : pqTraceOutputString(f, message, cursor, suppress);
322 : }
323 8 : }
324 :
325 : /* Execute(F) or ErrorResponse(B) */
326 : static void
327 39 : pqTraceOutputE(FILE *f, bool toServer, const char *message, int *cursor, bool regress)
328 : {
329 39 : if (toServer)
330 : {
331 34 : fprintf(f, "Execute\t");
332 34 : pqTraceOutputString(f, message, cursor, false);
333 34 : pqTraceOutputInt32(f, message, cursor, false);
334 : }
335 : else
336 5 : pqTraceOutputNR(f, "ErrorResponse", message, cursor, regress);
337 39 : }
338 :
339 : /* CopyFail */
340 : static void
341 UBC 0 : pqTraceOutputf(FILE *f, const char *message, int *cursor)
342 : {
343 0 : fprintf(f, "CopyFail\t");
344 0 : pqTraceOutputString(f, message, cursor, false);
345 0 : }
346 :
347 : /* FunctionCall */
348 : static void
349 0 : pqTraceOutputF(FILE *f, const char *message, int *cursor, bool regress)
350 : {
351 : int nfields;
352 : int nbytes;
353 :
354 0 : fprintf(f, "FunctionCall\t");
355 0 : pqTraceOutputInt32(f, message, cursor, regress);
356 0 : nfields = pqTraceOutputInt16(f, message, cursor);
357 :
358 0 : for (int i = 0; i < nfields; i++)
359 0 : pqTraceOutputInt16(f, message, cursor);
360 :
361 0 : nfields = pqTraceOutputInt16(f, message, cursor);
362 :
363 0 : for (int i = 0; i < nfields; i++)
364 : {
365 0 : nbytes = pqTraceOutputInt32(f, message, cursor, false);
366 0 : if (nbytes == -1)
367 0 : continue;
368 0 : pqTraceOutputNchar(f, nbytes, message, cursor);
369 : }
370 :
371 0 : pqTraceOutputInt16(f, message, cursor);
372 0 : }
373 :
374 : /* CopyInResponse */
375 : static void
376 0 : pqTraceOutputG(FILE *f, const char *message, int *cursor)
377 : {
378 : int nfields;
379 :
380 0 : fprintf(f, "CopyInResponse\t");
381 0 : pqTraceOutputByte1(f, message, cursor);
382 0 : nfields = pqTraceOutputInt16(f, message, cursor);
383 :
384 0 : for (int i = 0; i < nfields; i++)
385 0 : pqTraceOutputInt16(f, message, cursor);
386 0 : }
387 :
388 : /* CopyOutResponse */
389 : static void
390 0 : pqTraceOutputH(FILE *f, const char *message, int *cursor)
391 : {
392 : int nfields;
393 :
394 0 : fprintf(f, "CopyOutResponse\t");
395 0 : pqTraceOutputByte1(f, message, cursor);
396 0 : nfields = pqTraceOutputInt16(f, message, cursor);
397 :
398 0 : for (int i = 0; i < nfields; i++)
399 0 : pqTraceOutputInt16(f, message, cursor);
400 0 : }
401 :
402 : /* BackendKeyData */
403 : static void
404 0 : pqTraceOutputK(FILE *f, const char *message, int *cursor, bool regress)
405 : {
406 0 : fprintf(f, "BackendKeyData\t");
407 0 : pqTraceOutputInt32(f, message, cursor, regress);
408 0 : pqTraceOutputInt32(f, message, cursor, regress);
409 0 : }
410 :
411 : /* Parse */
412 : static void
413 CBC 34 : pqTraceOutputP(FILE *f, const char *message, int *cursor, bool regress)
414 : {
415 : int nparams;
416 :
417 34 : fprintf(f, "Parse\t");
418 34 : pqTraceOutputString(f, message, cursor, false);
419 34 : pqTraceOutputString(f, message, cursor, false);
420 34 : nparams = pqTraceOutputInt16(f, message, cursor);
421 :
422 42 : for (int i = 0; i < nparams; i++)
423 8 : pqTraceOutputInt32(f, message, cursor, regress);
424 34 : }
425 :
426 : /* Query */
427 : static void
428 8 : pqTraceOutputQ(FILE *f, const char *message, int *cursor)
429 : {
430 8 : fprintf(f, "Query\t");
431 8 : pqTraceOutputString(f, message, cursor, false);
432 8 : }
433 :
434 : /* Authentication */
435 : static void
436 UBC 0 : pqTraceOutputR(FILE *f, const char *message, int *cursor)
437 : {
438 0 : fprintf(f, "Authentication\t");
439 0 : pqTraceOutputInt32(f, message, cursor, false);
440 0 : }
441 :
442 : /* ParameterStatus */
443 : static void
444 0 : pqTraceOutputS(FILE *f, const char *message, int *cursor)
445 : {
446 0 : fprintf(f, "ParameterStatus\t");
447 0 : pqTraceOutputString(f, message, cursor, false);
448 0 : pqTraceOutputString(f, message, cursor, false);
449 0 : }
450 :
451 : /* ParameterDescription */
452 : static void
453 CBC 1 : pqTraceOutputt(FILE *f, const char *message, int *cursor, bool regress)
454 : {
455 : int nfields;
456 :
457 1 : fprintf(f, "ParameterDescription\t");
458 1 : nfields = pqTraceOutputInt16(f, message, cursor);
459 :
460 2 : for (int i = 0; i < nfields; i++)
461 1 : pqTraceOutputInt32(f, message, cursor, regress);
462 1 : }
463 :
464 : /* RowDescription */
465 : static void
466 27 : pqTraceOutputT(FILE *f, const char *message, int *cursor, bool regress)
467 : {
468 : int nfields;
469 :
470 27 : fprintf(f, "RowDescription\t");
471 27 : nfields = pqTraceOutputInt16(f, message, cursor);
472 :
473 57 : for (int i = 0; i < nfields; i++)
474 : {
475 30 : pqTraceOutputString(f, message, cursor, false);
476 30 : pqTraceOutputInt32(f, message, cursor, regress);
477 30 : pqTraceOutputInt16(f, message, cursor);
478 30 : pqTraceOutputInt32(f, message, cursor, regress);
479 30 : pqTraceOutputInt16(f, message, cursor);
480 30 : pqTraceOutputInt32(f, message, cursor, false);
481 30 : pqTraceOutputInt16(f, message, cursor);
482 : }
483 27 : }
484 :
485 : /* NegotiateProtocolVersion */
486 : static void
487 UBC 0 : pqTraceOutputv(FILE *f, const char *message, int *cursor)
488 : {
489 0 : fprintf(f, "NegotiateProtocolVersion\t");
490 0 : pqTraceOutputInt32(f, message, cursor, false);
491 0 : pqTraceOutputInt32(f, message, cursor, false);
492 0 : }
493 :
494 : /* FunctionCallResponse */
495 : static void
496 0 : pqTraceOutputV(FILE *f, const char *message, int *cursor)
497 : {
498 : int len;
499 :
500 0 : fprintf(f, "FunctionCallResponse\t");
501 0 : len = pqTraceOutputInt32(f, message, cursor, false);
502 0 : if (len != -1)
503 0 : pqTraceOutputNchar(f, len, message, cursor);
504 0 : }
505 :
506 : /* CopyBothResponse */
507 : static void
508 0 : pqTraceOutputW(FILE *f, const char *message, int *cursor, int length)
509 : {
510 0 : fprintf(f, "CopyBothResponse\t");
511 0 : pqTraceOutputByte1(f, message, cursor);
512 :
513 0 : while (length > *cursor)
514 0 : pqTraceOutputInt16(f, message, cursor);
515 0 : }
516 :
517 : /* ReadyForQuery */
518 : static void
519 CBC 22 : pqTraceOutputZ(FILE *f, const char *message, int *cursor)
520 : {
521 22 : fprintf(f, "ReadyForQuery\t");
522 22 : pqTraceOutputByte1(f, message, cursor);
523 22 : }
524 :
525 : /*
526 : * Print the given message to the trace output stream.
527 : */
528 : void
529 365 : pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer)
530 : {
531 : char id;
532 : int length;
533 365 : char *prefix = toServer ? "F" : "B";
534 365 : int logCursor = 0;
535 : bool regress;
536 :
537 365 : if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0)
538 : {
539 : char timestr[128];
540 :
541 UBC 0 : pqTraceFormatTimestamp(timestr, sizeof(timestr));
542 0 : fprintf(conn->Pfdebug, "%s\t", timestr);
543 : }
544 CBC 365 : regress = (conn->traceFlags & PQTRACE_REGRESS_MODE) != 0;
545 :
546 365 : id = message[logCursor++];
547 :
548 365 : memcpy(&length, message + logCursor, 4);
549 365 : length = (int) pg_ntoh32(length);
550 365 : logCursor += 4;
551 :
552 : /*
553 : * In regress mode, suppress the length of ErrorResponse and
554 : * NoticeResponse. The F (file name), L (line number) and R (routine
555 : * name) fields can change as server code is modified, and if their
556 : * lengths differ from the originals, that would break tests.
557 : */
558 365 : if (regress && !toServer && (id == 'E' || id == 'N'))
559 8 : fprintf(conn->Pfdebug, "%s\tNN\t", prefix);
560 : else
561 357 : fprintf(conn->Pfdebug, "%s\t%d\t", prefix, length);
562 :
563 365 : switch (id)
564 : {
565 29 : case '1':
566 29 : fprintf(conn->Pfdebug, "ParseComplete");
567 : /* No message content */
568 29 : break;
569 27 : case '2':
570 27 : fprintf(conn->Pfdebug, "BindComplete");
571 : /* No message content */
572 27 : break;
573 UBC 0 : case '3':
574 0 : fprintf(conn->Pfdebug, "CloseComplete");
575 : /* No message content */
576 0 : break;
577 0 : case 'A': /* Notification Response */
578 0 : pqTraceOutputA(conn->Pfdebug, message, &logCursor, regress);
579 0 : break;
580 CBC 34 : case 'B': /* Bind */
581 34 : pqTraceOutputB(conn->Pfdebug, message, &logCursor);
582 34 : break;
583 UBC 0 : case 'c':
584 0 : fprintf(conn->Pfdebug, "CopyDone");
585 : /* No message content */
586 0 : break;
587 CBC 35 : case 'C': /* Close(F) or Command Complete(B) */
588 35 : pqTraceOutputC(conn->Pfdebug, toServer, message, &logCursor);
589 35 : break;
590 UBC 0 : case 'd': /* Copy Data */
591 : /* Drop COPY data to reduce the overhead of logging. */
592 0 : break;
593 CBC 72 : case 'D': /* Describe(F) or Data Row(B) */
594 72 : pqTraceOutputD(conn->Pfdebug, toServer, message, &logCursor);
595 72 : break;
596 39 : case 'E': /* Execute(F) or Error Response(B) */
597 39 : pqTraceOutputE(conn->Pfdebug, toServer, message, &logCursor,
598 : regress);
599 39 : break;
600 UBC 0 : case 'f': /* Copy Fail */
601 0 : pqTraceOutputf(conn->Pfdebug, message, &logCursor);
602 0 : break;
603 0 : case 'F': /* Function Call */
604 0 : pqTraceOutputF(conn->Pfdebug, message, &logCursor, regress);
605 0 : break;
606 0 : case 'G': /* Start Copy In */
607 0 : pqTraceOutputG(conn->Pfdebug, message, &logCursor);
608 0 : break;
609 CBC 6 : case 'H': /* Flush(F) or Start Copy Out(B) */
610 6 : if (!toServer)
611 UBC 0 : pqTraceOutputH(conn->Pfdebug, message, &logCursor);
612 : else
613 CBC 6 : fprintf(conn->Pfdebug, "Flush"); /* no message content */
614 6 : break;
615 UBC 0 : case 'I':
616 0 : fprintf(conn->Pfdebug, "EmptyQueryResponse");
617 : /* No message content */
618 0 : break;
619 0 : case 'K': /* secret key data from the backend */
620 0 : pqTraceOutputK(conn->Pfdebug, message, &logCursor, regress);
621 0 : break;
622 CBC 5 : case 'n':
623 5 : fprintf(conn->Pfdebug, "NoData");
624 : /* No message content */
625 5 : break;
626 3 : case 'N':
627 3 : pqTraceOutputNR(conn->Pfdebug, "NoticeResponse", message,
628 : &logCursor, regress);
629 3 : break;
630 34 : case 'P': /* Parse */
631 34 : pqTraceOutputP(conn->Pfdebug, message, &logCursor, regress);
632 34 : break;
633 8 : case 'Q': /* Query */
634 8 : pqTraceOutputQ(conn->Pfdebug, message, &logCursor);
635 8 : break;
636 UBC 0 : case 'R': /* Authentication */
637 0 : pqTraceOutputR(conn->Pfdebug, message, &logCursor);
638 0 : break;
639 0 : case 's':
640 0 : fprintf(conn->Pfdebug, "PortalSuspended");
641 : /* No message content */
642 0 : break;
643 CBC 14 : case 'S': /* Parameter Status(B) or Sync(F) */
644 14 : if (!toServer)
645 UBC 0 : pqTraceOutputS(conn->Pfdebug, message, &logCursor);
646 : else
647 CBC 14 : fprintf(conn->Pfdebug, "Sync"); /* no message content */
648 14 : break;
649 1 : case 't': /* Parameter Description */
650 1 : pqTraceOutputt(conn->Pfdebug, message, &logCursor, regress);
651 1 : break;
652 27 : case 'T': /* Row Description */
653 27 : pqTraceOutputT(conn->Pfdebug, message, &logCursor, regress);
654 27 : break;
655 UBC 0 : case 'v': /* Negotiate Protocol Version */
656 0 : pqTraceOutputv(conn->Pfdebug, message, &logCursor);
657 0 : break;
658 0 : case 'V': /* Function Call response */
659 0 : pqTraceOutputV(conn->Pfdebug, message, &logCursor);
660 0 : break;
661 0 : case 'W': /* Start Copy Both */
662 0 : pqTraceOutputW(conn->Pfdebug, message, &logCursor, length);
663 0 : break;
664 CBC 9 : case 'X':
665 9 : fprintf(conn->Pfdebug, "Terminate");
666 : /* No message content */
667 9 : break;
668 22 : case 'Z': /* Ready For Query */
669 22 : pqTraceOutputZ(conn->Pfdebug, message, &logCursor);
670 22 : break;
671 UBC 0 : default:
672 0 : fprintf(conn->Pfdebug, "Unknown message: %02x", id);
673 0 : break;
674 : }
675 :
676 CBC 365 : fputc('\n', conn->Pfdebug);
677 :
678 : /*
679 : * Verify the printing routine did it right. Note that the one-byte
680 : * message identifier is not included in the length, but our cursor does
681 : * include it.
682 : */
683 365 : if (logCursor - 1 != length)
684 UBC 0 : fprintf(conn->Pfdebug,
685 : "mismatched message length: consumed %d, expected %d\n",
686 : logCursor - 1, length);
687 CBC 365 : }
688 :
689 : /*
690 : * Print special messages (those containing no type byte) to the trace output
691 : * stream.
692 : */
693 : void
694 UBC 0 : pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message)
695 : {
696 : int length;
697 0 : int logCursor = 0;
698 :
699 0 : if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0)
700 : {
701 : char timestr[128];
702 :
703 0 : pqTraceFormatTimestamp(timestr, sizeof(timestr));
704 0 : fprintf(conn->Pfdebug, "%s\t", timestr);
705 : }
706 :
707 0 : memcpy(&length, message + logCursor, 4);
708 0 : length = (int) pg_ntoh32(length);
709 0 : logCursor += 4;
710 :
711 0 : fprintf(conn->Pfdebug, "F\t%d\t", length);
712 :
713 0 : switch (length)
714 : {
715 0 : case 16: /* CancelRequest */
716 0 : fprintf(conn->Pfdebug, "CancelRequest\t");
717 0 : pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false);
718 0 : pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false);
719 0 : pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false);
720 0 : break;
721 0 : case 8: /* GSSENCRequest or SSLRequest */
722 : /* These messages do not reach here. */
723 : default:
724 0 : fprintf(conn->Pfdebug, "Unknown message: length is %d", length);
725 0 : break;
726 : }
727 :
728 0 : fputc('\n', conn->Pfdebug);
729 0 : }
|
