Debugging: millisecond timestamps. Bug 2102

[exim.git] / src / src / debug.c

diff --git a/src/src/debug.c b/src/src/debug.c
index cc60b44a6378e620bb9350177c32787b75ea2735..f6c8b2f62eb7cd61480da828512aa2cb97f44895 100644 (file)
--- a/src/src/debug.c
+++ b/src/src/debug.c
@@ -137,27 +137,41 @@ debug_printf("%s uid=%ld gid=%ld euid=%ld egid=%ld\n", s,
 *************************************************/
 
 /* There are two entries, one for use when being called directly from a
-function with a variable argument list.
+function with a variable argument list, one for prepending an indent.
 
 If debug_pid is nonzero, print the pid at the start of each line. This is for
 tidier output when running parallel remote deliveries with debugging turned on.
 Must do the whole thing with a single printf and flush, as otherwise output may
 get interleaved. Since some calls to debug_printf() don't end with newline,
-we save up the text until we do get the newline. */
+we save up the text until we do get the newline.
+Take care to not disturb errno. */
+
+
+/* Debug printf indented by ACL nest depth */
+void
+debug_printf_indent(const char * format, ...)
+{
+va_list ap;
+va_start(ap, format);
+debug_vprintf(acl_level + expand_level, format, ap);
+va_end(ap);
+}
 
 void
 debug_printf(const char *format, ...)
 {
 va_list ap;
 va_start(ap, format);
-debug_vprintf(format, ap);
+debug_vprintf(0, format, ap);
 va_end(ap);
 }
 
 void
-debug_vprintf(const char *format, va_list ap)
+debug_vprintf(int indent, const char *format, va_list ap)
 {
-if (debug_file == NULL) return;
+int save_errno = errno;
+
+if (!debug_file) return;
 
 /* Various things can be inserted at the start of a line. Don't use the
 tod_stamp() function for the timestamp, because that will overwrite the
@@ -168,17 +182,21 @@ if (debug_ptr == debug_buffer)
   {
   DEBUG(D_timestamp)
     {
-    time_t now = time(NULL);
-    struct tm *t = timestamps_utc? gmtime(&now) : localtime(&now);
-    (void) sprintf(CS debug_ptr, "%02d:%02d:%02d ", t->tm_hour, t->tm_min,
-      t->tm_sec);
-    while(*debug_ptr != 0) debug_ptr++;
+    struct timeval now;
+    time_t tmp;
+    struct tm * t;
+
+    gettimeofday(&now, NULL);
+    tmp = now.tv_sec;
+    t = timestamps_utc ? gmtime(&now) : localtime(&now);
+    debug_ptr += sprintf(CS debug_ptr,
+      LOGGING(millisec) ? "%02d:%02d:%02d.%03d " : "%02d:%02d:%02d ",
+      t->tm_hour, t->tm_min, t->tm_sec, now.tv_usec/1000);
     }
 
   DEBUG(D_pid)
     {
-    sprintf(CS debug_ptr, "%5d ", (int)getpid());
-    while(*debug_ptr != 0) debug_ptr++;
+    debug_ptr += sprintf(CS debug_ptr, "%5d ", (int)getpid());
     }
 
   /* Set up prefix if outputting for host checking and not debugging */
@@ -192,6 +210,20 @@ if (debug_ptr == debug_buffer)
   debug_prefix_length = debug_ptr - debug_buffer;
   }
 
+if (indent > 0)
+  {
+  int i;
+  for (i = indent >> 2; i > 0; i--)
+    {
+    Ustrcpy(debug_ptr, "   " UTF8_VERT_2DASH);
+    debug_ptr += 6;    /* 3 spaces + 3 UTF-8 octets */
+    debug_prefix_length += 6;
+    }
+  Ustrncpy(debug_ptr, "   ", indent &= 3);
+  debug_ptr += indent;
+  debug_prefix_length += indent;
+  }
+
 /* Use the checked formatting routine to ensure that the buffer
 does not overflow. Ensure there's space for a newline at the end. */
 
@@ -235,6 +267,7 @@ if (debug_ptr[-1] == '\n')
   debug_ptr = debug_buffer;
   debug_prefix_length = 0;
   }
+errno = save_errno;
 }
 
 /* End of debug.c */