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