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