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