806573f1cc8917e42372c3579b21cba7b26cfde7
[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 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 * sa_unp ; (struct sockaddr_un *)&a;
336
337   if (getsockname(fd, &a, &alen) == 0)
338     switch (sinp->sin_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         if (getpeername(fd, &a, &alen) == 0)
345           g = string_fmt_append(g, " rmt [%s]:%u",
346             inet_ntoa(sinp->sin_addr), ntohs(sinp->sin_port));
347         break;
348       case AF_INET6:
349         {
350         uschar buf[46];
351         g = string_cat(g, US" domain AF_INET6");
352         g = string_fmt_append(g, " lcl [%s]:%u",
353           inet_ntop(AF_INET6, &sin6p->sin6_addr, CS buf, sizeof(buf)),
354           ntohs(sin6p->sin6_port));
355         if (getpeername(fd, &a, &alen) == 0)
356           g = string_fmt_append(g, " rmt [%s]:%u",
357             inet_ntop(AF_INET6, &sin6p->sin6_addr, CS buf, sizeof(buf)),
358             ntohs(sin6p->sin6_port));
359         break;
360         }
361       case AF_UNIX:
362         g = string_cat(g, US" domain AF_UNIX");
363         g = string_fmt_append(g, " lcl %s%s",
364           sa_unp->sun_path[0] ? US"" : US"@",
365           sa_unp->sun_path[0] ? sa_unp->sun_path : sa_unp->sun_path+1);
366         if (getpeername(fd, &a, &alen) == 0)
367           g = string_fmt_append(g, " rmt %s%s",
368             sa_unp->sun_path[0] ? US"" : US"@",
369             sa_unp->sun_path[0] ? sa_unp->sun_path : sa_unp->sun_path+1);
370         break;
371       default:
372         g = string_fmt_append(g, " domain %u", sinp->sin_family);
373         break;
374       }
375   if (getsockopt(fd, SOL_SOCKET, SO_TYPE, &val, &vlen) == 0)
376     switch (val)
377       {
378       case SOCK_STREAM: g = string_cat(g, US" type SOCK_STREAM"); break;
379       case SOCK_DGRAM:  g = string_cat(g, US" type SOCK_DGRAM"); break;
380       default:  g = string_fmt_append(g, " type %d", val); break;
381       }
382   if (getsockopt(fd, SOL_SOCKET, SO_PROTOCOL, &val, &vlen) == 0)
383     {
384     struct protoent * p = getprotobynumber(val);
385     g = p
386       ? string_fmt_append(g, " proto %s\n", p->p_name)
387       : string_fmt_append(g, " proto %d", val);
388     }
389   debug_printf_indent(" socket: %s\n", string_from_gstring(g));
390   }
391 else
392   debug_printf_indent(" fd st_mode 0%o\n", s.st_mode);
393 }
394
395
396 /* End of debug.c */