fee0b7a810c5fd6cee4fe2a1aeb57f6dc0e562f1
[users/heiko/exim.git] / src / src / debug.c
1 /*************************************************
2 *     Exim - an Internet mail transport agent    *
3 *************************************************/
4
5 /* Copyright (c) University of Cambridge 1995 - 2018 */
6 /* See the file NOTICE for conditions of use and distribution. */
7
8
9 #include "exim.h"
10
11 static uschar  debug_buffer[2048];
12 static uschar *debug_ptr = debug_buffer;
13 static int     debug_prefix_length = 0;
14
15
16
17 const uschar * rc_names[] = {           /* Mostly for debug output */
18   [OK] =                US"OK",
19   [DEFER] =             US"DEFER",
20   [FAIL] =              US"FAIL",
21   [ERROR] =             US"ERROR",
22   [FAIL_FORCED] =       US"FAIL_FORCED",
23   [DECLINE] =           US"DECLINE",
24   [PASS] =              US"PASS",
25   [DISCARD] =           US"DISCARD",
26   [SKIP] =              US"SKIP",
27   [REROUTED] =          US"REROUTED",
28   [PANIC] =             US"PANIC",
29   [BAD64] =             US"BAD64",
30   [UNEXPECTED] =        US"UNEXPECTED",
31   [CANCELLED] =         US"CANCELLED",
32   [FAIL_SEND] =         US"FAIL_SEND",
33   [FAIL_DROP] =         US"FAIL_DROP",
34   [DANE] =              US"DANE",
35 };
36
37 const uschar * dns_rc_names[] = {
38   [DNS_SUCCEED] =       US"DNS_SUCCEED",
39   [DNS_NOMATCH] =       US"DNS_NOMATCH",
40   [DNS_NODATA] =        US"DNS_NODATA",
41   [DNS_AGAIN] =         US"DNS_AGAIN",
42   [DNS_FAIL] =          US"DNS_FAIL",
43 };
44
45
46 /*************************************************
47 *               Print tree                       *
48 *************************************************/
49
50 /* Recursive tree-printing subroutine. It uses a static vector of uschar to
51 hold the line-drawing characters that need to be printed on every line as it
52 moves down the page. This function is used only in debugging circumstances. The
53 output is done via debug_printf(). */
54
55 #define TREE_PRINTLINESIZE 132   /* line size for printing */
56 static uschar tree_printline[TREE_PRINTLINESIZE];
57
58 /* Internal recursive subroutine.
59
60 Arguments:
61   p          tree node
62   pos        amount of indenting & vertical bars to print
63   barswitch  if TRUE print | at the pos value
64
65 Returns:     nothing
66 */
67
68 static void
69 tree_printsub(tree_node * p, int pos, int barswitch)
70 {
71 if (p->right) tree_printsub(p->right, pos+2, 1);
72 for (int i = 0; i <= pos-1; i++) debug_printf_indent(" %c", tree_printline[i]);
73 debug_printf_indent(" -->%s [%d]\n", p->name, p->balance);
74 tree_printline[pos] = barswitch ? '|' : ' ';
75 if (p->left)
76   {
77   tree_printline[pos+2] = '|';
78   tree_printsub(p->left, pos+2, 0);
79   }
80 }
81
82 /* The external function, with just a tree node argument. */
83
84 void
85 debug_print_tree(const char * title, tree_node * p)
86 {
87 debug_printf_indent("%s:\n", title);
88 for (int i = 0; i < TREE_PRINTLINESIZE; i++) tree_printline[i] = ' ';
89 if (!p) debug_printf_indent(" Empty Tree\n"); else tree_printsub(p, 0, 0);
90 debug_printf_indent("---- End of tree ----\n");
91 }
92
93
94
95 /*************************************************
96 *          Print an argv vector                  *
97 *************************************************/
98
99 /* Called when about to obey execv().
100
101 Argument:    the argv vector
102 Returns:     nothing
103 */
104
105 void
106 debug_print_argv(const uschar ** argv)
107 {
108 debug_printf("exec");
109 while (*argv) debug_printf(" %.256s", *argv++);
110 debug_printf("\n");
111 }
112
113
114
115 /*************************************************
116 *      Expand and print debugging string         *
117 *************************************************/
118
119 /* The string is expanded and written as debugging output. If
120 expansion fails, a message is written instead.
121
122 Argument:    the string
123 Returns:     nothing
124 */
125
126 void
127 debug_print_string(uschar *debug_string)
128 {
129 if (!debug_string) return;
130 HDEBUG(D_any|D_v)
131   {
132   uschar *s = expand_string(debug_string);
133   if (!s)
134     debug_printf("failed to expand debug_output \"%s\": %s\n", debug_string,
135       expand_string_message);
136   else if (s[0] != 0)
137     debug_printf("%s%s", s, (s[Ustrlen(s)-1] == '\n')? "" : "\n");
138   }
139 }
140
141
142
143 /*************************************************
144 *      Print current uids and gids               *
145 *************************************************/
146
147 /*
148 Argument:   an introductory string
149 Returns:    nothing
150 */
151
152 void
153 debug_print_ids(uschar *s)
154 {
155 debug_printf("%s uid=%ld gid=%ld euid=%ld egid=%ld\n", s,
156   (long int)getuid(), (long int)getgid(), (long int)geteuid(),
157   (long int)getegid());
158 }
159
160 /************************************************/
161
162 /* Give a string for a return-code */
163
164 const uschar *
165 rc_to_string(int rc)
166 {
167 return rc < 0 || rc >= nelem(rc_names) ? US"?" : rc_names[rc];
168 }
169
170
171
172
173
174 /*************************************************
175 *           Print debugging message              *
176 *************************************************/
177
178 /* There are two entries, one for use when being called directly from a
179 function with a variable argument list, one for prepending an indent.
180
181 If debug_pid is nonzero, print the pid at the start of each line. This is for
182 tidier output when running parallel remote deliveries with debugging turned on.
183 Must do the whole thing with a single printf and flush, as otherwise output may
184 get interleaved. Since some calls to debug_printf() don't end with newline,
185 we save up the text until we do get the newline.
186 Take care to not disturb errno. */
187
188
189 /* Debug printf indented by ACL nest depth */
190 void
191 debug_printf_indent(const char * format, ...)
192 {
193 va_list ap;
194 va_start(ap, format);
195 debug_vprintf(acl_level + expand_level, format, ap);
196 va_end(ap);
197 }
198
199 void
200 debug_printf(const char *format, ...)
201 {
202 va_list ap;
203 va_start(ap, format);
204 debug_vprintf(0, format, ap);
205 va_end(ap);
206 }
207
208 void
209 debug_vprintf(int indent, const char *format, va_list ap)
210 {
211 int save_errno = errno;
212
213 if (!debug_file) return;
214
215 /* Various things can be inserted at the start of a line. Don't use the
216 tod_stamp() function for the timestamp, because that will overwrite the
217 timestamp buffer, which may contain something useful. (This was a bug fix: the
218 +memory debugging with +timestamp did cause a problem.) */
219
220 if (debug_ptr == debug_buffer)
221   {
222   DEBUG(D_timestamp)
223     {
224     struct timeval now;
225     time_t tmp;
226     struct tm * t;
227
228     gettimeofday(&now, NULL);
229     tmp = now.tv_sec;
230     t = f.timestamps_utc ? gmtime(&tmp) : localtime(&tmp);
231     debug_ptr += sprintf(CS debug_ptr,
232       LOGGING(millisec) ? "%02d:%02d:%02d.%03d " : "%02d:%02d:%02d ",
233       t->tm_hour, t->tm_min, t->tm_sec, (int)(now.tv_usec/1000));
234     }
235
236   DEBUG(D_pid)
237     debug_ptr += sprintf(CS debug_ptr, "%5d ", (int)getpid());
238
239   /* Set up prefix if outputting for host checking and not debugging */
240
241   if (host_checking && debug_selector == 0)
242     {
243     Ustrcpy(debug_ptr, US">>> ");
244     debug_ptr += 4;
245     }
246
247   debug_prefix_length = debug_ptr - debug_buffer;
248   }
249
250 if (indent > 0)
251   {
252   for (int i = indent >> 2; i > 0; i--)
253     DEBUG(D_noutf8)
254       {
255       Ustrcpy(debug_ptr, US"   !");
256       debug_ptr += 4;   /* 3 spaces + shriek */
257       debug_prefix_length += 4;
258       }
259     else
260       {
261       Ustrcpy(debug_ptr, US"   " UTF8_VERT_2DASH);
262       debug_ptr += 6;   /* 3 spaces + 3 UTF-8 octets */
263       debug_prefix_length += 6;
264       }
265
266   Ustrncpy(debug_ptr, US"   ", indent &= 3);
267   debug_ptr += indent;
268   debug_prefix_length += indent;
269   }
270
271 /* Use the lengthchecked formatting routine to ensure that the buffer
272 does not overflow. Ensure there's space for a newline at the end.
273 However, use taint-unchecked routines for writing into the buffer
274 so that we can write tainted info into the static debug_buffer -
275 we trust that we will never expand the results. */
276
277   {
278   gstring gs = { .size = (int)sizeof(debug_buffer) - 1,
279                 .ptr = debug_ptr - debug_buffer,
280                 .s = debug_buffer };
281   if (!string_vformat(&gs, SVFMT_TAINT_NOCHK, format, ap))
282     {
283     uschar * s = US"**** debug string too long - truncated ****\n";
284     uschar * p = gs.s + gs.ptr;
285     int maxlen = gs.size - Ustrlen(s) - 2;
286     if (p > gs.s + maxlen) p = gs.s + maxlen;
287     if (p > gs.s && p[-1] != '\n') *p++ = '\n';
288     Ustrcpy(p, s);
289     while(*debug_ptr) debug_ptr++;
290     }
291   else
292     {
293     string_from_gstring(&gs);
294     debug_ptr = gs.s + gs.ptr;
295     }
296   }
297
298 /* Output the line if it is complete. If we added any prefix data and there
299 are internal newlines, make sure the prefix is on the continuation lines,
300 as long as there is room in the buffer. We want to do just a single fprintf()
301 so as to avoid interleaving. */
302
303 if (debug_ptr[-1] == '\n')
304   {
305   if (debug_prefix_length > 0)
306     {
307     uschar *p = debug_buffer;
308     int left = sizeof(debug_buffer) - (debug_ptr - debug_buffer) - 1;
309     while ((p = Ustrchr(p, '\n') + 1) != debug_ptr &&
310            left >= debug_prefix_length)
311       {
312       int len = debug_ptr - p;
313       memmove(p + debug_prefix_length, p, len + 1);
314       memmove(p, debug_buffer, debug_prefix_length);
315       debug_ptr += debug_prefix_length;
316       left -= debug_prefix_length;
317       }
318     }
319
320   fprintf(debug_file, "%s", CS debug_buffer);
321   fflush(debug_file);
322   debug_ptr = debug_buffer;
323   debug_prefix_length = 0;
324   }
325 errno = save_errno;
326 }
327
328
329
330 /* Output the details of a socket */
331
332 void
333 debug_print_socket(int fd)
334 {
335 struct stat s;
336 if (fstat(fd, &s) == 0 && (s.st_mode & S_IFMT) == S_IFSOCK)
337   {
338   gstring * g = NULL;
339   int val;
340   socklen_t vlen = sizeof(val);
341   struct sockaddr_storage a;
342   socklen_t alen = sizeof(a);
343   struct sockaddr_in * sinp = (struct sockaddr_in *)&a;
344   struct sockaddr_in6 * sin6p = (struct sockaddr_in6 *)&a;
345   struct sockaddr_un * sunp = (struct sockaddr_un *)&a;
346
347   if (getsockname(fd, (struct sockaddr*)&a, &alen) == 0)
348     switch (a.ss_family)
349       {
350       case AF_INET:
351         g = string_cat(g, US"domain AF_INET");
352         g = string_fmt_append(g, " lcl [%s]:%u",
353           inet_ntoa(sinp->sin_addr), ntohs(sinp->sin_port));
354         alen = sizeof(*sinp);
355         if (getpeername(fd, sinp, &alen) == 0)
356           g = string_fmt_append(g, " rmt [%s]:%u",
357             inet_ntoa(sinp->sin_addr), ntohs(sinp->sin_port));
358         break;
359       case AF_INET6:
360         {
361         uschar buf[46];
362         g = string_cat(g, US"domain AF_INET6");
363         g = string_fmt_append(g, " lcl [%s]:%u",
364           inet_ntop(AF_INET6, &sin6p->sin6_addr, CS buf, sizeof(buf)),
365           ntohs(sin6p->sin6_port));
366         alen = sizeof(*sin6p);
367         if (getpeername(fd, sin6p, &alen) == 0)
368           g = string_fmt_append(g, " rmt [%s]:%u",
369             inet_ntop(AF_INET6, &sin6p->sin6_addr, CS buf, sizeof(buf)),
370             ntohs(sin6p->sin6_port));
371         break;
372         }
373       case AF_UNIX:
374         g = string_cat(g, US"domain AF_UNIX");
375         if (alen > sizeof(sa_family_t)) /* not unix(7) "unnamed socket" */
376           g = string_fmt_append(g, " lcl %s%s",
377             sunp->sun_path[0] ? US"" : US"@",
378             sunp->sun_path[0] ? sunp->sun_path : sunp->sun_path+1);
379         alen = sizeof(*sunp);
380         if (getpeername(fd, sunp, &alen) == 0)
381           g = string_fmt_append(g, " rmt %s%s",
382             sunp->sun_path[0] ? US"" : US"@",
383             sunp->sun_path[0] ? sunp->sun_path : sunp->sun_path+1);
384         break;
385       default:
386         g = string_fmt_append(g, "domain %u", sinp->sin_family);
387         break;
388       }
389   if (getsockopt(fd, SOL_SOCKET, SO_TYPE, &val, &vlen) == 0)
390     switch (val)
391       {
392       case SOCK_STREAM: g = string_cat(g, US" type SOCK_STREAM"); break;
393       case SOCK_DGRAM:  g = string_cat(g, US" type SOCK_DGRAM"); break;
394       default:  g = string_fmt_append(g, " type %d", val); break;
395       }
396 #ifdef SO_PROTOCOL
397   if (getsockopt(fd, SOL_SOCKET, SO_PROTOCOL, &val, &vlen) == 0)
398     {
399     struct protoent * p = getprotobynumber(val);
400     g = p
401       ? string_fmt_append(g, " proto %s", p->p_name)
402       : string_fmt_append(g, " proto %d", val);
403     }
404 #endif
405   debug_printf_indent(" socket: %s\n", string_from_gstring(g));
406   }
407 else
408   debug_printf_indent(" fd st_mode 0%o\n", s.st_mode);
409 }
410
411
412 /* End of debug.c */