Cleaned up the logging

10 files changed, 271 insertions, 170 deletions

diff --git a/NEWS b/NEWS
index 739e043..a9eee5f 100644
--- a/NEWS
+++ b/NEWS
@@ -8,10 +8,13 @@ Noteworthy changes in version 2.0.1 (unreleased)
  * Input and output notification handler can now really access the
    parsed fd as stated in the manual.
 
+ * Cleaned up the logging.
+
  * Interface changes relative to the 2.0.0 release:
  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  assuan_free               NEW.
  _assuan_w32ce_create_pipe NEW.
+ ASSUAN_LOG_CONTROL        NEW.
  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
 
 
diff --git a/doc/assuan.texi b/doc/assuan.texi
index 1b86768..be60ecd 100644
--- a/doc/assuan.texi
+++ b/doc/assuan.texi
@@ -655,7 +655,11 @@ for the context with @code{assuan_set_log_cb}, and a category
 @item ASSUAN_LOG_CTX
 @item ASSUAN_LOG_ENGINE
 @item ASSUAN_LOG_DATA
+RFU
 @item ASSUAN_LOG_SYSIO
+Log lowlevel I/O data.
+@item ASSUAN_LOG_CONTROL
+Log the control channel.
 @end table
 
 The user may then, depending on the category, write the message to a
@@ -973,23 +977,23 @@ The basic read and write functions are:
 
 @deftypefun gpg_error_t assuan_read_line (@w{assuan_context_t @var{ctx}}, @w{char **@var{line}}, @w{size_t *@var{linelen}})
 
-Read the next line written by the peer and store a pointer to the
-buffer holding that line at the address @var{line}.  The valid length
-of the lines is stored at the address of @var{linelen}.  This buffer
-is valid until the next read operation on the same context @var{ctx}.
-You may modify the context of this buffer.  The buffer is invalid
-(i.e. must not be used) if an error is returned.  This function
+Read the next line written by the peer to the control channel and store
+a pointer to the buffer holding that line at the address @var{line}.
+The valid length of the lines is stored at the address of @var{linelen}.
+This buffer is valid until the next read operation on the same context
+@var{ctx}.  You may modify the context of this buffer.  The buffer is
+invalid (i.e. must not be used) if an error is returned.  This function
 returns @code{0} on success or an error value.
 @end deftypefun
 
 @deftypefun gpg_error_t assuan_write_line (@w{assuan_context_t @var{ctx}}, @w{const char *@var{line}})
 
-Write the string @var{line} to the other end.  This string needs to be
-a proper formatted Assuan protocol line and should not include a
-linefeed.  Sending linefeed or @code{Nul} characters is not possible
-and not allowed by the assuan protocol.  This function shall not be
-used for sending data (@code{D}) lines.  This function returns
-@code{0} on success or an error value.
+Write the string @var{line} to the other end on the control channel.
+This string needs to be a proper formatted Assuan protocol line and
+should not include a linefeed.  Sending linefeed or @code{Nul}
+characters is not possible and not allowed by the assuan protocol.  This
+function shall not be used for sending data (@code{D}) lines.  This
+function returns @code{0} on success or an error value.
 @end deftypefun
 
 @noindent 
@@ -997,11 +1001,11 @@ To actually send bulk data lines a specialized function is available:
 
 @deftypefun gpg_error_t assuan_send_data (@w{assuan_context_t @var{ctx}}, @w{const void *@var{buffer}}, @w{size_t @var{length}})
 
-This function is used by a server or a client to send
-@var{length} bytes of bulk data in @var{buffer} to the other end.
-The data will be escaped as required by the Assuan protocol and
-may get buffered until a line is full.  To flush any pending data,
-@var{buffer} may be passed as @code{NULL} and @var{length} be @code{0}.
+This function is used by a server or a client to send @var{length} bytes
+of bulk data in @var{buffer} to the other end on the control channel.
+The data will be escaped as required by the Assuan protocol and may get
+buffered until a line is full.  To flush any pending data, @var{buffer}
+may be passed as @code{NULL} and @var{length} be @code{0}.
 
 @noindent
 When used by a client, this flush operation does also send the
diff --git a/src/ChangeLog b/src/ChangeLog
index d3af990..dd71683 100644
--- a/src/ChangeLog
+++ b/src/ChangeLog
@@ -1,3 +1,22 @@
+2010-03-11  Werner Koch  <[email protected]>
+
+	* assuan-defs.h [!HAVE_VASPRINTF]: Add macros vasprintf and asprintf.
+
+	* vasprintf.c (asprintf): Rename to _assuan_asprintf.
+	(vasprintf): Rename to _assuan_vasprintf.
+
+	* assuan.h (ASSUAN_LOG_CONTROL): New.
+	* assuan-logging.c (assuan_set_assuan_log_stream): Default to
+	ASSUAN_LOG_CONTROL.
+	(_assuan_log_print_buffer): Remove.
+	(_assuan_log_control_channel): New.
+	(assuan_set_assuan_log_stream): Factor envvar code out to ..
+	(_assuan_init_log_envvars): .. New.
+	* assuan.c (assuan_set_log_cb): Call _assuan_init_log_envvars.
+	* assuan-buffer.c (_assuan_read_line, _assuan_write_line)
+	(assuan_write_line, _assuan_cookie_write_data)
+	(_assuan_cookie_write_flush): Use _assuan_log_control_channel.
+
 2010-03-05  Werner Koch  <[email protected]>
 
 	* gpgcemgr.c: Add options to register a device and activate it.
@@ -370,7 +389,7 @@
 	* assuan.c (assuan_set_system_hooks): New function.
 	(assuan_new_ext): Initialize CTX->system.
 	(assuan_release): Always output trace message.
-	
+
 	* assuan-error.c (_assuan_error_is_eagain): Add ctx argument, pass
 	along to _assuan_usleep.
 	* assuan-inquire.c assuan-listen.c, assuan-socket-server.c,
@@ -424,7 +443,7 @@
 	(sock_ctx): New singleton.
 	(assuan_sock_init, assuan_sock_deinit): New functions to
 	initialize and deinitialize the singleton.
-		
+
 2009-10-14  Werner Koch  <[email protected]>
 
 	* assuan-defs.h (assuan_context_s): Add field CURRENT_CMD_NAME.
@@ -725,9 +744,9 @@
 	(_assuan_io_read, _assuan_simple_read): Add hook feature.
 	(do_io_write): Take all code from _assuan_io_write.
 	(_assuan_io_write, _assuan_simple_write): Add hook feature.
-	* assuan-io-pth.c (_assuan_simple_read, _assuan_simple_write) 
+	* assuan-io-pth.c (_assuan_simple_read, _assuan_simple_write)
 	(_assuan_io_read, _assuan_io_write): Add hook feature.
-	
+
 2007-10-05  Marcus Brinkmann  <[email protected]>
 
 	* assuan.h (_assuan_error_is_eagain): Add prefix macro.
@@ -812,7 +831,7 @@
 
 	* assuan-inquire.c (assuan_inquire_ext): If MAXLEN is 0, still
 	initialize MEMBUF.
-	
+
 	* assuan-inquire.c (_assuan_inquire_ext_cb): Clear CTX->in_inquire
 	before invoking callback and returning.
 
@@ -867,7 +886,7 @@
 	(_assuan_inquire_ext_cb, assuan_inquire_ext): New functions.
 	* assuan-pipe-server.c (_assuan_release_context): Call
 	_assuan_inquire_release.
-	
+
 2007-07-12  Werner Koch  <[email protected]>
 
 	* assuan.h (assuan_fd_t): New.
@@ -886,7 +905,7 @@
 
 	* assuan-io.c (_assuan_simple_write): Return EPIPE on a closed pipe.
 	(_assuan_simple_read): Likewise
-	
+
 2007-07-08  Marcus Brinkmann  <[email protected]>
 
 	* assuan-defs.h (struct assuan_context_s): Have full peercred
@@ -912,7 +931,7 @@
 
 2007-06-18  Werner Koch  <[email protected]>
 
-	* assuan-logging.c (load_libgpg_error, _assuan_gpg_strerror_r) 
+	* assuan-logging.c (load_libgpg_error, _assuan_gpg_strerror_r)
 	(_assuan_gpg_strsource): New.
 	* assuan-handler.c (process_request) [W32]: Use these new
 	functions for human understable error codes.
@@ -932,7 +951,7 @@
 
 	* assuan-io-pth.c: Include sys/socket.h only if available.  Remove
 	double inclusion of sys/wait.h
-	
+
 	* assuan-pipe-connect.c (build_w32_commandline): Make ARGV const.
 
 	* assuan-pipe-server.c (is_valid_socket) [W32]: Do not define.
@@ -985,7 +1004,7 @@
 
 	* libassuan.m4 (AM_CHECK_LIBASSUAN): New.
 
-	* assuan-handler.c (assuan_register_post_cmd_notify) 
+	* assuan-handler.c (assuan_register_post_cmd_notify)
 	(assuan_register_post_cmd_notify): New.
 	* assuan-util.c (assuan_set_io_monitor): New.
 	* assuan-buffer.c (_assuan_read_line): Use it.
@@ -1111,9 +1130,9 @@
 	* assuan-domain-server.c: Removed.
 	* assuan-domain-connect.c: Renamed to ..
 	* assuan-uds.c: this.
-	(domain_reader, domain_writer, domain_sendfd, domain_receivefd) 
-	(assuan_domain_connect, _assuan_domain_init): Removed. 
-	(uds_reader, uds_writer, uds_sendfd, uds_receivefd) 
+	(domain_reader, domain_writer, domain_sendfd, domain_receivefd)
+	(assuan_domain_connect, _assuan_domain_init): Removed.
+	(uds_reader, uds_writer, uds_sendfd, uds_receivefd)
 	(_assuan_init_uds_io): New.
 	(_assuan_uds_deinit): New.
 
@@ -1234,7 +1253,7 @@
 	* assuan-pipe-connect.c (fix_signals) [_ASSUAN_NO_FIXED_SIGNALS]: New.
 	(assuan_pipe_connect2) [_ASSUAN_USE_DOUBLE_FORK]: Use double fork.
 	(fix_signals) [_ASSUAN_USE_DOUBLE_FORK]: Do not wait..
-	
+
 2005-05-21  Werner Koch  <[email protected]>
 
 	* assuan-util.c (assuan_set_flag, assuan_get_flag): New.
@@ -1276,7 +1295,7 @@
 
 2004-12-18  Werner Koch  <[email protected]>
 
-	* assuan-logging.c (_assuan_w32_strerror): New. 
+	* assuan-logging.c (_assuan_w32_strerror): New.
 	* assuan-defs.h (w32_strerror): new.
 	* assuan-pipe-connect.c (assuan_pipe_connect2, fix_signals):
 	Factored signal code out to new function.
@@ -1327,7 +1346,7 @@
 	* assuan-socket-connect.c (assuan_socket_connect): Use DIRSEP_C
 	for a better portability.
 	(assuan-defs.h): Define DIRSEP_C.
-	
+
 2004-11-19  Werner Koch  <[email protected]>
 
 	* assuan-handler.c (assuan_write_status): Return an error code.
@@ -1339,7 +1358,7 @@
 	* assuan-socket.c (_assuan_close): New.
 	(_assuan_sock_new): New.
 	(_assuan_sock_bind): New.
-	
+
 2004-11-16  Werner Koch  <[email protected]>
 
 	* assuan-socket-connect.c (LOG): Fixed macro to print not only the
@@ -1506,7 +1525,7 @@
 	* isascii.c: Likewise.
 	* memrchr.c: Likewise.
 	* putc_unlocked.c: Likewise.
-	
+
 2003-02-18  Neal H. Walfield  <[email protected]>
 
 	* assuan-handler.c (_IO_cookie_io_functions_t): Remove.
@@ -1805,10 +1824,10 @@
 	* assuan-connect.c: Move all except assuan_get_pid to...
 	* assuan-pipe-connect.c: this.
 	(assuan_pipe_disconnect): Removed.
-	(do_finish, do_deinit): New 
+	(do_finish, do_deinit): New
 	(assuan_pipe_connect): and set them into the context.
 	* assuan-socket-connect.c: New.
-	
+
 	* assuan-util.c (_assuan_log_sanitized_string): New.
 
 	* assuan-pipe-server.c (assuan_init_pipe_server): Factored most
@@ -1901,7 +1920,7 @@
 
 	* assuan-connect.c (assuan_pipe_connect): Implemented the inital
 	handshake.
-	* assuan-client.c (read_from_server): Renamed to  
+	* assuan-client.c (read_from_server): Renamed to
 	(_assuan_read_from_server): this and made external.
 
 	* assuan-listen.c (assuan_set_hello_line): New.
@@ -1948,8 +1967,8 @@
 	than a line.
 	* assuan-defs.h: Add space in the context for this.
 
-	
- Copyright 2001, 2002, 2006, 2007 Free Software Foundation, Inc.
+
+ Copyright 2001, 2002, 2006, 2007, 2010 Free Software Foundation, Inc.
 
  This file is free software; as a special exception the author gives
  unlimited permission to copy and/or distribute it, with or without
diff --git a/src/assuan-buffer.c b/src/assuan-buffer.c
index db65e66..45dc08c 100644
--- a/src/assuan-buffer.c
+++ b/src/assuan-buffer.c
@@ -1,5 +1,5 @@
 /* assuan-buffer.c - read and send data
-   Copyright (C) 2001-2004, 2006, 2009 Free Software Foundation, Inc.
+   Copyright (C) 2001-2004, 2006, 2009, 2010 Free Software Foundation, Inc.
 
    This file is part of Assuan.
 
@@ -138,12 +138,10 @@ _assuan_read_line (assuan_context_t ctx)
   if (rc)
     {
       int saved_errno = errno;
+      char buf[100];
 
-      if (ctx->log_fp)
-	fprintf (ctx->log_fp, "%s[%u.%d] DBG: <- [Error: %s]\n",
-                 assuan_get_assuan_log_prefix (),
-                 (unsigned int)getpid (), (int)ctx->inbound.fd,
-                 strerror (errno));
+      snprintf (buf, sizeof buf, "error: %s", strerror (errno));
+      _assuan_log_control_channel (ctx, 0, buf, NULL, 0, NULL, 0);
 
       if (saved_errno == EAGAIN)
         {
@@ -161,11 +159,7 @@ _assuan_read_line (assuan_context_t ctx)
   if (!nread)
     {
       assert (ctx->inbound.eof);
-      if (ctx->log_fp)
-	fprintf (ctx->log_fp, "%s[%u.%d] DBG: <- [EOF]\n",
-		 assuan_get_assuan_log_prefix (),
-                 (unsigned int)getpid (), (int)ctx->inbound.fd);
-
+      _assuan_log_control_channel (ctx, 0, "eof", NULL, 0, NULL, 0);
       return _assuan_error (ctx, GPG_ERR_EOF);
     }
 
@@ -205,27 +199,16 @@ _assuan_read_line (assuan_context_t ctx)
       if (monitor_result & ASSUAN_IO_MONITOR_IGNORE)
         ctx->inbound.linelen = 0;
       
-      if (ctx->log_fp && !(monitor_result & ASSUAN_IO_MONITOR_NOLOG))
-	{
-	  fprintf (ctx->log_fp, "%s[%u.%d] DBG: <- ",
-		   assuan_get_assuan_log_prefix (),
-                   (unsigned int)getpid (), (int)ctx->inbound.fd);
-	  if (ctx->flags.confidential)
-	    fputs ("[Confidential data not shown]", ctx->log_fp);
-	  else
-	    _assuan_log_print_buffer (ctx->log_fp,
-				      ctx->inbound.line,
-				      ctx->inbound.linelen);
-	  putc ('\n', ctx->log_fp);
-	}
+      if ( !(monitor_result & ASSUAN_IO_MONITOR_NOLOG))
+        _assuan_log_control_channel (ctx, 0, NULL,
+                                     ctx->inbound.line, ctx->inbound.linelen,
+                                     NULL, 0);
       return 0;
     }
   else
     {
-      if (ctx->log_fp)
-	fprintf (ctx->log_fp, "%s[%u.%d] DBG: <- [Invalid line]\n",
-		 assuan_get_assuan_log_prefix (),
-                 (unsigned int)getpid (), (int)ctx->inbound.fd);
+      _assuan_log_control_channel (ctx, 0, "invalid line", 
+                                   NULL, 0, NULL, 0);
       *line = 0;
       ctx->inbound.linelen = 0;
       return _assuan_error (ctx, ctx->inbound.eof 
@@ -285,11 +268,9 @@ _assuan_write_line (assuan_context_t ctx, const char *prefix,
   /* Make sure that the line is short enough. */
   if (len + prefixlen + 2 > ASSUAN_LINELENGTH)
     {
-      if (ctx->log_fp)
-        fprintf (ctx->log_fp, "%s[%u.%d] DBG: -> "
-                 "[supplied line too long -truncated]\n",
-                 assuan_get_assuan_log_prefix (),
-                 (unsigned int)getpid (), (int)ctx->inbound.fd);
+      _assuan_log_control_channel (ctx, 1, 
+                                   "supplied line too long - truncated",
+                                   NULL, 0, NULL, 0);
       if (prefixlen > 5)
         prefixlen = 5;
       if (len > ASSUAN_LINELENGTH - prefixlen - 2)
@@ -301,21 +282,10 @@ _assuan_write_line (assuan_context_t ctx, const char *prefix,
     monitor_result = ctx->io_monitor (ctx, ctx->io_monitor_data, 1, line, len);
 
   /* Fixme: we should do some kind of line buffering.  */
-  if (ctx->log_fp && !(monitor_result & ASSUAN_IO_MONITOR_NOLOG))
-    {
-      fprintf (ctx->log_fp, "%s[%u.%d] DBG: -> ",
-	       assuan_get_assuan_log_prefix (),
-               (unsigned int)getpid (), (int)ctx->inbound.fd);
-      if (ctx->flags.confidential)
-	fputs ("[Confidential data not shown]", ctx->log_fp);
-      else
-        {
-          if (prefixlen)
-            _assuan_log_print_buffer (ctx->log_fp, prefix, prefixlen);
-          _assuan_log_print_buffer (ctx->log_fp, line, len);
-        }
-      putc ('\n', ctx->log_fp);
-    }
+  if (!(monitor_result & ASSUAN_IO_MONITOR_NOLOG))
+    _assuan_log_control_channel (ctx, 1, NULL,
+                                 prefixlen? prefix:NULL, prefixlen,
+                                 line, len);
 
   if (prefixlen && !(monitor_result & ASSUAN_IO_MONITOR_IGNORE))
     {
@@ -353,11 +323,10 @@ assuan_write_line (assuan_context_t ctx, const char *line)
   str = strchr (line, '\n');
   len = str ? (str - line) : strlen (line);
 
-  if (ctx->log_fp && str)
-    fprintf (ctx->log_fp, "%s[%u.%d] DBG: -> "
-             "[supplied line contained a LF - truncated]\n",
-             assuan_get_assuan_log_prefix (),
-             (unsigned int) getpid (), (int) ctx->inbound.fd);
+  if (str)
+    _assuan_log_control_channel (ctx, 1,
+                                 "supplied line with LF - truncated",
+                                 NULL, 0, NULL, 0);
 
   return _assuan_write_line (ctx, NULL, line, len);
 }
@@ -418,20 +387,11 @@ _assuan_cookie_write_data (void *cookie, const char *buffer, size_t orig_size)
 
       if (linelen >= LINELENGTH-2-2)
         {
-          if (ctx->log_fp && !(monitor_result & ASSUAN_IO_MONITOR_NOLOG))
-            {
-	      fprintf (ctx->log_fp, "%s[%u.%d] DBG: -> ",
-		       assuan_get_assuan_log_prefix (),
-                       (unsigned int)getpid (), (int)ctx->inbound.fd);
-
-              if (ctx->flags.confidential)
-                fputs ("[Confidential data not shown]", ctx->log_fp);
-              else 
-                _assuan_log_print_buffer (ctx->log_fp, 
-                                          ctx->outbound.data.line,
-                                          linelen);
-              putc ('\n', ctx->log_fp);
-            }
+          if (!(monitor_result & ASSUAN_IO_MONITOR_NOLOG))
+            _assuan_log_control_channel (ctx, 1, NULL,
+                                         ctx->outbound.data.line, linelen,
+                                         NULL, 0);
+
           *line++ = '\n';
           linelen++;
           if ( !(monitor_result & ASSUAN_IO_MONITOR_IGNORE)
@@ -474,18 +434,10 @@ _assuan_cookie_write_flush (void *cookie)
   
   if (linelen)
     {
-      if (ctx->log_fp && !(monitor_result & ASSUAN_IO_MONITOR_NOLOG))
-	{
-	  fprintf (ctx->log_fp, "%s[%u.%d] DBG: -> ",
-		   assuan_get_assuan_log_prefix (),
-                   (unsigned int)getpid (), (int)ctx->inbound.fd);
-	  if (ctx->flags.confidential)
-	    fputs ("[Confidential data not shown]", ctx->log_fp);
-	  else
-	    _assuan_log_print_buffer (ctx->log_fp,
-				      ctx->outbound.data.line, linelen);
-	  putc ('\n', ctx->log_fp);
-	}
+      if (!(monitor_result & ASSUAN_IO_MONITOR_NOLOG))
+        _assuan_log_control_channel (ctx, 1, NULL,
+                                     ctx->outbound.data.line, linelen,
+                                     NULL, 0);
       *line++ = '\n';
       linelen++;
       if (! (monitor_result & ASSUAN_IO_MONITOR_IGNORE)
diff --git a/src/assuan-defs.h b/src/assuan-defs.h
index 6478a71..dd91f09 100644
--- a/src/assuan-defs.h
+++ b/src/assuan-defs.h
@@ -302,7 +302,11 @@ char *_assuan_w32_strerror (assuan_context_t ctx, int ec);
 
 
 /*-- assuan-logging.c --*/
-void _assuan_log_print_buffer (FILE *fp, const void *buffer, size_t length);
+void _assuan_init_log_envvars (void);
+void _assuan_log_control_channel (assuan_context_t ctx, int outbound,
+                                  const char *string,
+                                  const void *buffer1, size_t length1,
+                                  const void *buffer2, size_t length2);
 
 
 /*-- assuan-io.c --*/
@@ -364,6 +368,13 @@ int setenv (const char *name, const char *value, int replace);
 #ifndef HAVE_PUTC_UNLOCKED
 int putc_unlocked (int c, FILE *stream);
 #endif
+#ifndef HAVE_VASPRINTF
+int _assuan_vasprintf (char **result, const char *format, va_list args);
+int _assuan_asprintf (char **buf, const char *fmt, ...);
+#define vasprintf _assuan_vasprintf
+#define asprintf  _assuan_asprintf
+#endif
+
 
 #define DIM(v)		     (sizeof(v)/sizeof((v)[0]))
 
diff --git a/src/assuan-logging.c b/src/assuan-logging.c
index b7b3895..14cebe2 100644
--- a/src/assuan-logging.c
+++ b/src/assuan-logging.c
@@ -1,5 +1,6 @@
 /* assuan-logging.c - Default logging function.
-   Copyright (C) 2002, 2003, 2004, 2007, 2009 Free Software Foundation, Inc.
+   Copyright (C) 2002, 2003, 2004, 2007, 2009,
+                 2010 Free Software Foundation, Inc.
 
    This file is part of Assuan.
 
@@ -41,35 +42,42 @@
 static char prefix_buffer[80];
 
 /* A global flag read from the environment to check if to enable full
-   logging of buffer data.  */
+   logging of buffer data.  This is also used by custom log
+   handlers.  */
 static int full_logging;
 
-/* A bitfield that specifies the categories to log.  Note that
-   assuan-buffer currently does not log through the default handler,
-   but directly.  This will be changed later.  Then the default here
-   should be to log that and only that.  */
+/* A bitfield that specifies the categories to log.  */
 static int log_cats;
 #define TEST_LOG_CAT(x) (!! (log_cats & (1 << (x - 1))))
 
 static FILE *_assuan_log;
 
+
 void
-assuan_set_assuan_log_stream (FILE *fp)
+_assuan_init_log_envvars (void)
 {
   char *flagstr;
 
-  _assuan_log = fp;
-
-  /* Set defaults.  */
   full_logging = !!getenv ("ASSUAN_FULL_LOGGING");
   flagstr = getenv ("ASSUAN_DEBUG");
   if (flagstr)
     log_cats = atoi (flagstr);
+  else /* Default to log the control channel.  */
+    log_cats = (1 << (ASSUAN_LOG_CONTROL - 1));
 
   _assuan_sysutils_blurb (); /* Make sure this code gets linked in.  */
 }
 
 
+void
+assuan_set_assuan_log_stream (FILE *fp)
+{
+  _assuan_log = fp;
+
+  _assuan_init_log_envvars ();
+}
+
+
 /* Set the per context log stream.  Also enable the default log stream
    if it has not been set.  */
 void
@@ -144,45 +152,148 @@ _assuan_log_handler (assuan_context_t ctx, void *hook, unsigned int cat,
   return 0;
 }
 
+
 
-/* Dump a possibly binary string (used for debugging).  Distinguish
-   ascii text from binary and print it accordingly.  This function
-   takes FILE pointer arg because logging may be enabled on a per
-   context basis.  */
+/* Log a control channel message.  This is either a STRING with a
+   diagnostic or actual data in (BUFFER1,LENGTH1) and
+   (BUFFER2,LENGTH2).  If OUTBOUND is true the data is intended for
+   the peer.  */
 void
-_assuan_log_print_buffer (FILE *fp, const void *buffer, size_t length)
+_assuan_log_control_channel (assuan_context_t ctx, int outbound,
+                             const char *string,
+                             const void *buffer1, size_t length1,
+                             const void *buffer2, size_t length2)
 {
-  const unsigned char *s;
-  unsigned int n;
+  int res;
+  char *outbuf;
+  int saved_errno;
 
-  for (n = length, s = buffer; n; n--, s++)
-    if  ((! isascii (*s) || iscntrl (*s) || ! isprint (*s)) && !(*s >= 0x80))
-      break;
+  /* Check whether logging is enabled and do a quick check to see
+     whether the callback supports our category.  */
+  if (!ctx || !ctx->log_cb 
+      || !(*ctx->log_cb) (ctx, ctx->log_cb_data, ASSUAN_LOG_CONTROL, NULL))
+    return;
 
-  s = buffer;
-  if (! n && *s != '[')
-    fwrite (buffer, length, 1, fp);
-  else
-    {
-#ifdef HAVE_FLOCKFILE
-      flockfile (fp);
+  saved_errno = errno;
+
+  /* Note that we use the inbound channel fd as the printed channel
+     number for both directions.  */
+#ifdef HAVE_W32_SYSTEM
+# define CHANNEL_FMT "%p"
+#else
+# define CHANNEL_FMT "%d"
 #endif
-      putc_unlocked ('[', fp);
-      if (length > 16 && ! full_logging)
+#define TOHEX(val) (((val) < 10) ? ((val) + '0') : ((val) - 10 + 'a'))
+
+  if (!buffer1 && buffer2)
+    {
+      buffer1 = buffer2;
+      length1 = length2;
+      buffer2 = NULL;
+      length2 = 0;
+    }
+
+  if (ctx->flags.confidential && !string && buffer1)
+    string = "[Confidential data not shown]";
+
+  if (string)
+    {
+      /* Print the diagnostic.  */
+      res = asprintf (&outbuf, "chan_" CHANNEL_FMT " %s [%s]\n",
+                      ctx->inbound.fd, outbound? "->":"<-", string);
+    }
+  else if (buffer1)
+    {
+      /* Print the control channel data.  */
+      const unsigned char *s;
+      unsigned int n, x;
+
+      for (n = length1, s = buffer1; n; n--, s++)
+        if ((!isascii (*s) || iscntrl (*s) || !isprint (*s) || !*s)
+            && !(*s >= 0x80))
+          break;
+      if (!n && buffer2)
+        {
+          for (n = length2, s = buffer2; n; n--, s++)
+            if ((!isascii (*s) || iscntrl (*s) || !isprint (*s) || !*s)
+                && !(*s >= 0x80))
+              break;
+        }
+      if (!buffer2)
+        length2 = 0;
+
+      if (!n && (length1 && *(const char*)buffer1 != '['))
         {
-          for (n = 0; n < 12; n++, s++)
-            fprintf (fp, " %02x", *s);
-          fprintf (fp, " ...(%d bytes skipped)", (int) length - 12);
+          /* No control characters and not starting with our error
+             message indicator.  Log it verbatim.  */
+          res = asprintf (&outbuf, "chan_" CHANNEL_FMT " %s %.*s%.*s\n",
+                          ctx->inbound.fd, outbound? "->":"<-",
+                          (int)length1, (const char*)buffer1,
+                          (int)length2, buffer2? (const char*)buffer2:"");
         }
       else
         {
-          for (n = 0; n < length; n++, s++)
-            fprintf (fp, " %02x", *s);
+          /* The buffer contains control characters - do a hex dump.
+             Even in full logging mode we limit the line length -
+             however this is no real limit because the provided
+             buffers will never be larger than the maximum assuan line
+             length. */
+          char *hp;
+          unsigned int nbytes;
+          unsigned int maxbytes = full_logging? (2*LINELENGTH) : 16;
+            
+          nbytes = length1 + length2;
+          if (nbytes > maxbytes)
+            nbytes = maxbytes;
+
+          if (!(outbuf = malloc (50 + 3*nbytes + 60 + 3 + 1)))
+            res = -1;
+          else
+            {
+              res = 0;
+              hp = outbuf;
+              snprintf (hp, 50, "chan_" CHANNEL_FMT " %s [",
+                        ctx->inbound.fd, outbound? "->":"<-");
+              hp += strlen (hp);
+              n = 0;
+              for (s = buffer1, x = 0; x < length1 && n < nbytes; x++, n++)
+                {
+                  *hp++ = ' ';
+                  *hp++ = TOHEX (*s >> 4);
+                  *hp++ = TOHEX (*s & 0x0f);
+                  s++;
+                }
+              for (s = buffer2, x = 0; x < length2 && n < nbytes; x++, n++)
+                {
+                  *hp++ = ' ';
+                  *hp++ = TOHEX (*s >> 4);
+                  *hp++ = TOHEX (*s & 0x0f);
+                  s++;
+                }
+              if (nbytes < length1 + length2)
+                {
+                  snprintf (hp, 60, " ...(%u byte(s) skipped)",
+                            (unsigned int)((length1+length2) - nbytes));
+                  hp += strlen (hp);
+                }
+              strcpy (hp, " ]\n");
+            }
         }
-      putc_unlocked (' ', fp);
-      putc_unlocked (']', fp);
-#ifdef HAVE_FUNLOCKFILE
-      funlockfile (fp);
-#endif
     }
+  else
+    {
+      res = 0;
+      outbuf = NULL;
+    }
+  if (res < 0)
+    ctx->log_cb (ctx, ctx->log_cb_data, ASSUAN_LOG_CONTROL,
+                 "[libassuan failed to format the log message]");
+  else if (outbuf)
+    {
+      ctx->log_cb (ctx, ctx->log_cb_data, ASSUAN_LOG_CONTROL, outbuf);
+      free (outbuf);
+    }
+#undef TOHEX
+#undef CHANNEL_FMT
+  gpg_err_set_errno (saved_errno);
 }
diff --git a/src/assuan.c b/src/assuan.c
index 21dd29d..b9d3143 100644
--- a/src/assuan.c
+++ b/src/assuan.c
@@ -80,6 +80,7 @@ assuan_set_log_cb (assuan_log_cb_t log_cb, void *log_cb_data)
 {
   _assuan_default_log_cb = log_cb;
   _assuan_default_log_cb_data = log_cb_data;
+  _assuan_init_log_envvars ();
 }
 
 
diff --git a/src/assuan.h b/src/assuan.h
index 6509310..c275287 100644
--- a/src/assuan.h
+++ b/src/assuan.h
@@ -159,6 +159,7 @@ typedef struct assuan_malloc_hooks *assuan_malloc_hooks_t;
 #define ASSUAN_LOG_ENGINE 3
 #define ASSUAN_LOG_DATA 4
 #define ASSUAN_LOG_SYSIO 5
+#define ASSUAN_LOG_CONTROL 8
 
 /* If MSG is NULL, return true/false depending on if this category is
    logged.  This is used to probe before expensive log message
diff --git a/src/debug.c b/src/debug.c
index 8c286e8..6ebc179 100644
--- a/src/debug.c
+++ b/src/debug.c
@@ -40,7 +40,7 @@
 #include "debug.h"
 
 
-/* Log the formatted string FORMAT at debug category CAT or higher.  */
+/* Log the formatted string FORMAT at debug category CAT higher.  */
 void
 _assuan_debug (assuan_context_t ctx, unsigned int cat, const char *format, ...)
 {
diff --git a/src/vasprintf.c b/src/vasprintf.c
index 77113a3..b46cdf7 100644
--- a/src/vasprintf.c
+++ b/src/vasprintf.c
@@ -135,34 +135,33 @@ int_vasprintf (result, format, args)
     return 0;
 }
 
+
+/* We use the _assuan prefix to keep our name space clean. */
 int
-vasprintf (result, format, args)
-     char **result;
-     const char *format;
-#if defined (_BSD_VA_LIST_) && defined (__FreeBSD__)
-     _BSD_VA_LIST_ args;
-#else
-     va_list args;
-#endif
+_assuan_vasprintf (char **result, const char *format, va_list args)
 {
   return int_vasprintf (result, format, &args);
 }
 
 
 int
-asprintf (char **buf, const char *fmt, ...)
+_assuan_asprintf (char **buf, const char *fmt, ...)
 {
   int status;
   va_list ap;
 
   va_start (ap, fmt);
-  status = vasprintf (buf, fmt, ap);
+  status = _assuan_vasprintf (buf, fmt, ap);
   va_end (ap);
   return status;
 }
 
 
 #ifdef TEST
+
+#define asprintf  _assuan_asprintf
+#define vasprintf _assuan_vasprintf
+
 void
 checkit (const char* format, ...)
 {