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 */