src/src/debug.c

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