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