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