2007-07-17 Marcus Brinkmann <[email protected]>

	* debug.c:;5B Include <errno.h> and "debug.h".
	(_gpgme_debug): Save and restore ERRNO.
	(TOHEX): New macro.
	(_gpgme_debug_buffer): New function.
	* conversion.c, data-compat.c, data-mem.c, data.c, engine-gpgsm.c,
	gpgme.c, keylist.c, posix-io.c, rungpg.c, sign.c, version.c,
	w32-io.c, wait.c: Replace DEBUG macros by TRACE_* variants.  In
	most of these files, add many more tracepoints.

18 files changed, 1860 insertions, 1237 deletions

diff --git a/gpgme/ChangeLog b/gpgme/ChangeLog
index 126d7803..4ae4b2a7 100644
--- a/gpgme/ChangeLog
+++ b/gpgme/ChangeLog
@@ -1,3 +1,14 @@
+2007-07-17  Marcus Brinkmann  <[email protected]>
+
+	* debug.c:;5B Include <errno.h> and "debug.h".
+	(_gpgme_debug): Save and restore ERRNO.
+	(TOHEX): New macro.
+	(_gpgme_debug_buffer): New function.
+	* conversion.c, data-compat.c, data-mem.c, data.c, engine-gpgsm.c,
+	gpgme.c, keylist.c, posix-io.c, rungpg.c, sign.c, version.c,
+	w32-io.c, wait.c: Replace DEBUG macros by TRACE_* variants.  In
+	most of these files, add many more tracepoints.
+
 2007-07-16  Marcus Brinkmann  <[email protected]>
 
 	* engine-gpgsm.c (status_handler): Do not send BYE here.
diff --git a/gpgme/conversion.c b/gpgme/conversion.c
index bba62bde..a8d15899 100644
--- a/gpgme/conversion.c
+++ b/gpgme/conversion.c
@@ -1,6 +1,6 @@
 /* conversion.c - String conversion helper functions.
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2007 g10 Code GmbH
  
    This file is part of GPGME.
 
@@ -30,7 +30,7 @@
 
 #include "gpgme.h"
 #include "util.h"
-
+#include "debug.h"
 
 #define atoi_1(p)   (*(p) - '0' )
 #define atoi_2(p)   ((atoi_1(p) * 10) + atoi_1((p)+1))
@@ -392,23 +392,27 @@ static struct
     
 
 gpgme_error_t
-_gpgme_map_gnupg_error (char *err)
+_gpgme_map_gnupg_error (char *errstr)
 {
   unsigned int i;
+  gpgme_error_t err = gpg_err_make (GPG_ERR_SOURCE_GPG, GPG_ERR_GENERAL);
 
   /* Future version of GnuPG might return the error code directly, so
      we first test for a a numerical value and use that verbatim.
      Note that this numerical value might be followed by an
      underschore and the textual representation of the error code. */
-  if (*err >= '0' && *err <= '9')
-    return strtoul (err, NULL, 10);
+  if (*errstr >= '0' && *errstr <= '9')
+    return strtoul (errstr, NULL, 10);
 
   /* Well, this is a token, use the mapping table to get the error.
      The drawback is that we won't receive an error source and have to
      use GPG as source. */
   for (i = 0; i < DIM (gnupg_errors); i++)
-    if (!strcmp (gnupg_errors[i].name, err))
-      return gpg_err_make (GPG_ERR_SOURCE_GPG, gnupg_errors[i].err);
+    if (!strcmp (gnupg_errors[i].name, errstr))
+      err = gpg_err_make (GPG_ERR_SOURCE_GPG, gnupg_errors[i].err);
 
-  return gpg_err_make (GPG_ERR_SOURCE_GPG, GPG_ERR_GENERAL);
+  TRACE3 (DEBUG_CTX, "_gpgme_map_gnupg_error", 0,
+	  "mapped %s to %s <%s>", errstr, gpgme_strerror (err),
+	  gpgme_strsource (err));
+  return err;
 }
diff --git a/gpgme/data-compat.c b/gpgme/data-compat.c
index b808cbd2..cabe24e2 100644
--- a/gpgme/data-compat.c
+++ b/gpgme/data-compat.c
@@ -1,5 +1,5 @@
 /* data-compat.c - Compatibility interfaces for data objects.
-   Copyright (C) 2002, 2003, 2004 g10 Code GmbH
+   Copyright (C) 2002, 2003, 2004, 2007 g10 Code GmbH
  
    This file is part of GPGME.
  
@@ -29,26 +29,31 @@
 
 #include "data.h"
 #include "util.h"
+#include "debug.h"
 
 
 /* Create a new data buffer filled with LENGTH bytes starting from
    OFFSET within the file FNAME or stream STREAM (exactly one must be
    non-zero).  */
 gpgme_error_t
-gpgme_data_new_from_filepart (gpgme_data_t *dh, const char *fname,
+gpgme_data_new_from_filepart (gpgme_data_t *r_dh, const char *fname,
 			      FILE *stream, off_t offset, size_t length)
 {
   gpgme_error_t err;
   char *buf = NULL;
   int res;
 
+  TRACE_BEG4 (DEBUG_DATA, "gpgme_data_new_from_filepart", r_dh,
+	      "file_name=%s, stream=%p, offset=%lli, length=%u",
+	      fname, stream, offset, length);
+
   if (stream && fname)
-    return gpg_error (GPG_ERR_INV_VALUE);
+    return TRACE_ERR (gpg_error (GPG_ERR_INV_VALUE));
 
   if (fname)
     stream = fopen (fname, "rb");
   if (!stream)
-    return gpg_error_from_errno (errno);
+    return TRACE_ERR (gpg_error_from_errno (errno));
 
 #ifdef HAVE_FSEEKO
   res = fseeko (stream, offset, SEEK_SET);
@@ -62,7 +67,7 @@ gpgme_data_new_from_filepart (gpgme_data_t *dh, const char *fname,
       int saved_errno = errno;
       if (fname)
 	fclose (stream);
-      return gpg_error_from_errno (saved_errno);
+      return TRACE_ERR (gpg_error_from_errno (saved_errno));
     }
 
   buf = malloc (length);
@@ -71,7 +76,7 @@ gpgme_data_new_from_filepart (gpgme_data_t *dh, const char *fname,
       int saved_errno = errno;
       if (fname)
 	fclose (stream);
-      return gpg_error_from_errno (saved_errno);
+      return TRACE_ERR (gpg_error_from_errno (saved_errno));
     }
 
   while (fread (buf, length, 1, stream) < 1
@@ -83,13 +88,13 @@ gpgme_data_new_from_filepart (gpgme_data_t *dh, const char *fname,
 	free (buf);
       if (fname)
 	fclose (stream);
-      return gpg_error_from_errno (saved_errno);
+      return TRACE_ERR (gpg_error_from_errno (saved_errno));
     }
 
   if (fname)
     fclose (stream);
 
-  err = gpgme_data_new (dh);
+  err = gpgme_data_new (r_dh);
   if (err)
     {
       if (buf)
@@ -97,68 +102,80 @@ gpgme_data_new_from_filepart (gpgme_data_t *dh, const char *fname,
       return err;
     }
 
-  (*dh)->data.mem.buffer = buf;
-  (*dh)->data.mem.size = length;
-  (*dh)->data.mem.length = length;
-  return 0;
+  (*r_dh)->data.mem.buffer = buf;
+  (*r_dh)->data.mem.size = length;
+  (*r_dh)->data.mem.length = length;
+
+  return TRACE_SUC1 ("r_dh=%p", *r_dh);
 }
 
 
 /* Create a new data buffer filled with the content of file FNAME.
    COPY must be non-zero (delayed reads are not supported yet).  */
 gpgme_error_t
-gpgme_data_new_from_file (gpgme_data_t *dh, const char *fname, int copy)
+gpgme_data_new_from_file (gpgme_data_t *r_dh, const char *fname, int copy)
 {
+  gpgme_error_t err;
   struct stat statbuf;
+  TRACE_BEG3 (DEBUG_DATA, "gpgme_data_new_from_filepart", r_dh,
+	      "file_name=%s, copy=%i (%s)", fname, copy, copy ? "yes" : "no");
 
   if (!fname || !copy)
-    return gpg_error (GPG_ERR_INV_VALUE);
+    return TRACE_ERR (gpg_error (GPG_ERR_INV_VALUE));
 
   if (stat (fname, &statbuf) < 0)
-    return gpg_error_from_errno (errno);
+    return TRACE_ERR (gpg_error_from_errno (errno));
 
-  return gpgme_data_new_from_filepart (dh, fname, NULL, 0, statbuf.st_size);
+  err = gpgme_data_new_from_filepart (r_dh, fname, NULL, 0, statbuf.st_size);
+  return TRACE_ERR (err);
 }
 
 
 static int
 gpgme_error_to_errno (gpgme_error_t err)
 {
-  int no = gpg_err_code_to_errno (err);
+  int res = gpg_err_code_to_errno (err);
 
-  if (no)
+  if (!err)
     {
-      errno = no;
-      return -1;
-    }
-
-  switch (gpg_err_code (err))
-    {
-    case GPG_ERR_EOF:
-      return 0;
-    case GPG_ERR_INV_VALUE:
-      errno = EINVAL;
-      return -1;
-    case GPG_ERR_NOT_SUPPORTED:
-      errno = ENOSYS;
-      return -1;
-    default:
-      /* FIXME: Yeah, well.  */
-      errno = EINVAL;
-      return -1;
+      switch (gpg_err_code (err))
+	{
+	case GPG_ERR_EOF:
+	  res = 0;
+	  break;
+	case GPG_ERR_INV_VALUE:
+	  res = EINVAL;
+	  break;
+	case GPG_ERR_NOT_SUPPORTED:
+	  res = ENOSYS;
+	  break;
+	default:
+	  /* FIXME: Yeah, well.  */
+	  res = EINVAL;
+	  break;
+	}
     }
+  TRACE3 (DEBUG_DATA, "gpgme:gpgme_error_to_errno", 0,
+	  "mapping %s <%s> to: %s", gpgme_strerror (err),
+	  gpgme_strsource (err), strerror (res));
+  errno = res;
+  return res ? -1 : 0;
 }
 
 
 static ssize_t
 old_user_read (gpgme_data_t dh, void *buffer, size_t size)
 {
+  gpgme_error_t err;
   size_t amt;
-  gpgme_error_t err = (*dh->data.old_user.cb) (dh->data.old_user.handle,
-					       buffer, size, &amt);
+  TRACE_BEG2 (DEBUG_DATA, "gpgme:old_user_read", dh,
+	      "buffer=%p, size=%u", buffer, size);
+
+  err = (*dh->data.old_user.cb) (dh->data.old_user.handle,
+				 buffer, size, &amt);
   if (err)
-    return gpgme_error_to_errno (err);
-  return amt;
+    return TRACE_SYSRES (gpgme_error_to_errno (err));
+  return TRACE_SYSRES (amt);
 }
 
 
@@ -166,15 +183,18 @@ static off_t
 old_user_seek (gpgme_data_t dh, off_t offset, int whence)
 {
   gpgme_error_t err;
+  TRACE_BEG2 (DEBUG_DATA, "gpgme:old_user_seek", dh,
+	      "offset=%llu, whence=%i", offset, whence);
+
   if (whence != SEEK_SET || offset)
     {
       errno = EINVAL;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
   err = (*dh->data.old_user.cb) (dh->data.old_user.handle, NULL, 0, NULL);
   if (err)
-    return gpgme_error_to_errno (err);
-  return 0;
+    return TRACE_SYSRES (gpgme_error_to_errno (err));
+  return TRACE_SYSRES (0);
 }
 
 
@@ -190,23 +210,33 @@ static struct _gpgme_data_cbs old_user_cbs =
 /* Create a new data buffer which retrieves the data from the callback
    function READ_CB.  */
 gpgme_error_t
-gpgme_data_new_with_read_cb (gpgme_data_t *dh,
+gpgme_data_new_with_read_cb (gpgme_data_t *r_dh,
                              int (*read_cb) (void *, char *, size_t, size_t *),
                              void *read_cb_value)
 {
-  gpgme_error_t err = _gpgme_data_new (dh, &old_user_cbs);
+  gpgme_error_t err;
+  TRACE_BEG2 (DEBUG_DATA, "gpgme_data_new_with_read_cb", r_dh,
+	      "read_cb=%p/%p", read_cb, read_cb_value);
+
+  err = _gpgme_data_new (r_dh, &old_user_cbs);
+
   if (err)
-    return err;
+    return TRACE_ERR (err);
 
-  (*dh)->data.old_user.cb = read_cb;
-  (*dh)->data.old_user.handle = read_cb_value;
-  return 0;
+  (*r_dh)->data.old_user.cb = read_cb;
+  (*r_dh)->data.old_user.handle = read_cb_value;
+  return TRACE_ERR (0);
 }
 
 
 gpgme_error_t
 gpgme_data_rewind (gpgme_data_t dh)
 {
-  return (gpgme_data_seek (dh, 0, SEEK_SET) == -1)
+  gpgme_error_t err;
+  TRACE_BEG (DEBUG_DATA, "gpgme_data_rewind", dh);
+
+  err = (gpgme_data_seek (dh, 0, SEEK_SET) == -1)
     ? gpg_error_from_errno (errno) : 0;
+
+  return TRACE_ERR (err);
 }
diff --git a/gpgme/data-mem.c b/gpgme/data-mem.c
index c7698116..bc718065 100644
--- a/gpgme/data-mem.c
+++ b/gpgme/data-mem.c
@@ -1,5 +1,5 @@
 /* data-mem.c - A memory based data object.
-   Copyright (C) 2002, 2003, 2004 g10 Code GmbH
+   Copyright (C) 2002, 2003, 2004, 2007 g10 Code GmbH
  
    This file is part of GPGME.
  
@@ -30,6 +30,7 @@
 
 #include "data.h"
 #include "util.h"
+#include "debug.h"
 
 
 static ssize_t
@@ -164,13 +165,17 @@ static struct _gpgme_data_cbs mem_cbs =
 
 /* Create a new data buffer and return it in R_DH.  */
 gpgme_error_t
-gpgme_data_new (gpgme_data_t *dh)
+gpgme_data_new (gpgme_data_t *r_dh)
 {
-  gpgme_error_t err = _gpgme_data_new (dh, &mem_cbs);
+  gpgme_error_t err;
+  TRACE_BEG (DEBUG_DATA, "gpgme_data_new", r_dh);
+
+  err = _gpgme_data_new (r_dh, &mem_cbs);
+
   if (err)
-    return err;
+    return TRACE_ERR (err);
 
-  return 0;
+  return TRACE_SUC1 ("r_dh=%p", *r_dh);
 }
 
 
@@ -178,27 +183,36 @@ gpgme_data_new (gpgme_data_t *dh)
    BUFFER.  If COPY is zero, copying is delayed until necessary, and
    the data is taken from the original location when needed.  */
 gpgme_error_t
-gpgme_data_new_from_mem (gpgme_data_t *dh, const char *buffer,
+gpgme_data_new_from_mem (gpgme_data_t *r_dh, const char *buffer,
 			 size_t size, int copy)
 {
-  gpgme_error_t err = _gpgme_data_new (dh, &mem_cbs);
+  gpgme_error_t err;
+  TRACE_BEG4 (DEBUG_DATA, "gpgme_data_new_from_mem", r_dh,
+	      "buffer=%p, size=%u, copy=%i (%s)", buffer, size,
+	      copy, copy ? "yes" : "no");
+
+  err = _gpgme_data_new (r_dh, &mem_cbs);
   if (err)
-    return err;
+    return TRACE_ERR (err);
 
   if (copy)
     {
       char *bufcpy = malloc (size);
       if (!bufcpy)
-	_gpgme_data_release (*dh);
+	{
+	  int saved_errno = errno;
+	  _gpgme_data_release (*r_dh);
+	  return TRACE_ERR (gpg_error_from_errno (saved_errno));
+	}
       memcpy (bufcpy, buffer, size);
-      (*dh)->data.mem.buffer = bufcpy;
+      (*r_dh)->data.mem.buffer = bufcpy;
     }
   else
-    (*dh)->data.mem.orig_buffer = buffer;
+    (*r_dh)->data.mem.orig_buffer = buffer;
   
-  (*dh)->data.mem.size = size;
-  (*dh)->data.mem.length = size;
-  return 0;
+  (*r_dh)->data.mem.size = size;
+  (*r_dh)->data.mem.length = size;
+  return TRACE_SUC1 ("dh=%p", *r_dh);
 }
 
 
@@ -210,9 +224,13 @@ gpgme_data_release_and_get_mem (gpgme_data_t dh, size_t *r_len)
 {
   char *str = NULL;
 
+  TRACE_BEG1 (DEBUG_DATA, "gpgme_data_release_and_get_mem", dh,
+	      "r_len=%p", r_len);
+
   if (!dh || dh->cbs != &mem_cbs)
     {
       gpgme_data_release (dh);
+      TRACE_ERR (gpg_error (GPG_ERR_INV_VALUE));
       return NULL;
     }
 
@@ -222,7 +240,9 @@ gpgme_data_release_and_get_mem (gpgme_data_t dh, size_t *r_len)
       str = malloc (dh->data.mem.length);
       if (!str)
 	{
+	  int saved_errno = errno;
 	  gpgme_data_release (dh);
+	  TRACE_ERR (gpg_error_from_errno (saved_errno));
 	  return NULL;
 	}
       memcpy (str, dh->data.mem.orig_buffer, dh->data.mem.length);
@@ -237,6 +257,7 @@ gpgme_data_release_and_get_mem (gpgme_data_t dh, size_t *r_len)
 
   gpgme_data_release (dh);
 
+  TRACE_SUC2 ("buffer=%p, len=%u", str, *r_len);
   return str;
 }
 
@@ -245,7 +266,8 @@ gpgme_data_release_and_get_mem (gpgme_data_t dh, size_t *r_len)
 void
 gpgme_free (void *buffer)
 {
+  TRACE (DEBUG_DATA, "gpgme_free", buffer);
+
   if (buffer)
     free (buffer);
 }
-
diff --git a/gpgme/data.c b/gpgme/data.c
index 22768ff5..aa3eeb38 100644
--- a/gpgme/data.c
+++ b/gpgme/data.c
@@ -1,5 +1,5 @@
 /* data.c - An abstraction for data objects.
-   Copyright (C) 2002, 2003, 2004, 2005 g10 Code GmbH
+   Copyright (C) 2002, 2003, 2004, 2005, 2007 g10 Code GmbH
 
    This file is part of GPGME.
  
@@ -32,6 +32,7 @@
 #include "util.h"
 #include "ops.h"
 #include "priv-io.h"
+#include "debug.h"
 
 
 gpgme_error_t
@@ -72,17 +73,22 @@ _gpgme_data_release (gpgme_data_t dh)
 ssize_t
 gpgme_data_read (gpgme_data_t dh, void *buffer, size_t size)
 {
+  ssize_t res;
+  TRACE_BEG2 (DEBUG_DATA, "gpgme_data_read", dh,
+	      "buffer=%p, size=%u", buffer, size);
+
   if (!dh)
     {
       errno = EINVAL;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
   if (!dh->cbs->read)
     {
       errno = ENOSYS;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
-  return (*dh->cbs->read) (dh, buffer, size);
+  res = (*dh->cbs->read) (dh, buffer, size);
+  return TRACE_SYSRES (res);
 }
 
 
@@ -92,17 +98,22 @@ gpgme_data_read (gpgme_data_t dh, void *buffer, size_t size)
 ssize_t
 gpgme_data_write (gpgme_data_t dh, const void *buffer, size_t size)
 {
+  ssize_t res;
+  TRACE_BEG2 (DEBUG_DATA, "gpgme_data_write", dh,
+	      "buffer=%p, size=%u", buffer, size);
+
   if (!dh)
     {
       errno = EINVAL;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
   if (!dh->cbs->write)
     {
       errno = ENOSYS;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
-  return (*dh->cbs->write) (dh, buffer, size);
+  res = (*dh->cbs->write) (dh, buffer, size);
+  return TRACE_SYSRES (res);
 }
 
 
@@ -112,15 +123,18 @@ gpgme_data_write (gpgme_data_t dh, const void *buffer, size_t size)
 off_t
 gpgme_data_seek (gpgme_data_t dh, off_t offset, int whence)
 {
+  TRACE_BEG2 (DEBUG_DATA, "gpgme_data_seek", dh,
+	      "offset=%lli, whence=%i", offset, whence);
+
   if (!dh)
     {
       errno = EINVAL;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
   if (!dh->cbs->seek)
     {
       errno = ENOSYS;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
 
   /* For relative movement, we must take into account the actual
@@ -132,7 +146,7 @@ gpgme_data_seek (gpgme_data_t dh, off_t offset, int whence)
   if (offset >= 0)
     dh->pending_len = 0;
 
-  return offset;
+  return TRACE_SYSRES (offset);
 }
 
 
@@ -140,6 +154,8 @@ gpgme_data_seek (gpgme_data_t dh, off_t offset, int whence)
 void
 gpgme_data_release (gpgme_data_t dh)
 {
+  TRACE (DEBUG_DATA, "gpgme_data_release", dh);
+
   if (!dh)
     return;
 
@@ -154,6 +170,8 @@ gpgme_data_release (gpgme_data_t dh)
 gpgme_data_encoding_t
 gpgme_data_get_encoding (gpgme_data_t dh)
 {
+  TRACE1 (DEBUG_DATA, "gpgme_data_get_encoding", dh,
+	  "dh->encoding=%i", dh ? dh->encoding : GPGME_DATA_ENCODING_NONE);
   return dh ? dh->encoding : GPGME_DATA_ENCODING_NONE;
 }
 
@@ -163,12 +181,14 @@ gpgme_data_get_encoding (gpgme_data_t dh)
 gpgme_error_t
 gpgme_data_set_encoding (gpgme_data_t dh, gpgme_data_encoding_t enc)
 {
+  TRACE_BEG1 (DEBUG_DATA, "gpgme_data_set_encoding", dh,
+	      "encoding=%i", enc);
   if (!dh)
-    return gpg_error (GPG_ERR_INV_VALUE);
+    return TRACE_ERR (gpg_error (GPG_ERR_INV_VALUE));
   if (enc < 0 || enc > GPGME_DATA_ENCODING_ARMOR)
-    return gpg_error (GPG_ERR_INV_VALUE);
+    return TRACE_ERR (gpg_error (GPG_ERR_INV_VALUE));
   dh->encoding = enc;
-  return 0;
+  return TRACE_ERR (0);
 }
 
 
@@ -177,8 +197,11 @@ gpgme_data_set_encoding (gpgme_data_t dh, gpgme_data_encoding_t enc)
 gpgme_error_t
 gpgme_data_set_file_name (gpgme_data_t dh, const char *file_name)
 {
+  TRACE_BEG1 (DEBUG_DATA, "gpgme_data_set_file_name", dh,
+	      "file_name=%s", file_name);
+
   if (!dh)
-    return gpg_error (GPG_ERR_INV_VALUE);
+    return TRACE_ERR (gpg_error (GPG_ERR_INV_VALUE));
 
   if (dh->file_name)
     free (dh->file_name);
@@ -187,22 +210,28 @@ gpgme_data_set_file_name (gpgme_data_t dh, const char *file_name)
     {
       dh->file_name = strdup (file_name);
       if (!dh->file_name)
-	return gpg_error_from_errno (errno);
+	return TRACE_ERR (gpg_error_from_errno (errno));
     }
   else
     dh->file_name = 0;
 
-  return 0;
+  return TRACE_ERR (0);
 }
 
+
 /* Get the file name associated with the data object with handle DH,
    or NULL if there is none.  */
 char *
 gpgme_data_get_file_name (gpgme_data_t dh)
 {
   if (!dh)
-    return NULL;
+    {
+      TRACE (DEBUG_DATA, "gpgme_data_get_file_name", dh);
+      return NULL;
+    }
 
+  TRACE1 (DEBUG_DATA, "gpgme_data_get_file_name", dh,
+	  "dh->file_name=%s", dh->file_name);
   return dh->file_name;
 }
 
@@ -216,6 +245,8 @@ _gpgme_data_inbound_handler (void *opaque, int fd)
   char buffer[BUFFER_SIZE];
   char *bufp = buffer;
   ssize_t buflen;
+  TRACE_BEG1 (DEBUG_CTX, "_gpgme_data_inbound_handler", dh,
+	      "fd=0x%x", fd);
 
   buflen = _gpgme_io_read (fd, buffer, BUFFER_SIZE);
   if (buflen < 0)
@@ -223,19 +254,19 @@ _gpgme_data_inbound_handler (void *opaque, int fd)
   if (buflen == 0)
     {
       _gpgme_io_close (fd);
-      return 0;
+      return TRACE_ERR (0);
     }
 
   do
     {
       ssize_t amt = gpgme_data_write (dh, bufp, buflen);
       if (amt == 0 || (amt < 0 && errno != EINTR))
-	return gpg_error_from_errno (errno);
+	return TRACE_ERR (gpg_error_from_errno (errno));
       bufp += amt;
       buflen -= amt;
     }
   while (buflen > 0);
-  return 0;
+  return TRACE_ERR (0);
 }
 
 
@@ -244,23 +275,25 @@ _gpgme_data_outbound_handler (void *opaque, int fd)
 {
   gpgme_data_t dh = (gpgme_data_t) opaque;
   ssize_t nwritten;
+  TRACE_BEG1 (DEBUG_CTX, "_gpgme_data_outbound_handler", dh,
+	      "fd=0x%x", fd);
 
   if (!dh->pending_len)
     {
       ssize_t amt = gpgme_data_read (dh, dh->pending, BUFFER_SIZE);
       if (amt < 0)
-	return gpg_error_from_errno (errno);
+	return TRACE_ERR (gpg_error_from_errno (errno));
       if (amt == 0)
 	{
 	  _gpgme_io_close (fd);
-	  return 0;
+	  return TRACE_ERR (0);
 	}
       dh->pending_len = amt;
     }
 
   nwritten = _gpgme_io_write (fd, dh->pending, dh->pending_len);
   if (nwritten == -1 && errno == EAGAIN)
-    return 0;
+    return TRACE_ERR (0);
 
   if (nwritten == -1 && errno == EPIPE)
     {
@@ -269,16 +302,16 @@ _gpgme_data_outbound_handler (void *opaque, int fd)
 	 end is going to tell us what happened on some other channel.
 	 Silently close our end.  */
       _gpgme_io_close (fd);
-      return 0;
+      return TRACE_ERR (0);
     }
 
   if (nwritten <= 0)
-    return gpg_error_from_errno (errno);
+    return TRACE_ERR (gpg_error_from_errno (errno));
 
   if (nwritten < dh->pending_len)
     memmove (dh->pending, dh->pending + nwritten, dh->pending_len - nwritten);
   dh->pending_len -= nwritten;
-  return 0;
+  return TRACE_ERR (0);
 }
 
 
diff --git a/gpgme/debug.c b/gpgme/debug.c
index 870976c9..7280f635 100644
--- a/gpgme/debug.c
+++ b/gpgme/debug.c
@@ -1,6 +1,6 @@
 /* debug.c - helpful output in desperate situations
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004, 2005 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2005, 2007 g10 Code GmbH
  
    This file is part of GPGME.
 
@@ -28,6 +28,7 @@
 #include <stdarg.h>
 #include <unistd.h>
 #include <ctype.h>
+#include <errno.h>
 #ifndef HAVE_DOSISH_SYSTEM
   #include <sys/types.h>
   #include <sys/stat.h>
@@ -37,6 +38,7 @@
 
 #include "util.h"
 #include "sema.h"
+#include "debug.h"
 
 
 /* Lock to serialize initialization of the debug output subsystem and
@@ -147,6 +149,9 @@ void
 _gpgme_debug (int level, const char *format, ...)
 {
   va_list arg_ptr;
+  int saved_errno;
+
+  saved_errno = errno;
 
   debug_init ();
   if (debug_level < level)
@@ -160,6 +165,8 @@ _gpgme_debug (int level, const char *format, ...)
     putc ('\n', errfp);
   UNLOCK (debug_lock);
   fflush (errfp);
+
+  errno = saved_errno;
 }
 
 
@@ -219,3 +226,48 @@ _gpgme_debug_end (void **line)
   free (*line);
   *line = NULL;
 }
+
+
+#define TOHEX(val) (((val) < 10) ? ((val) + '0') : ((val) - 10 + 'a'))
+
+void
+_gpgme_debug_buffer (int lvl, const char *const fmt,
+		     const char *const func, const char *const tagname,
+		     void *tag, const char *const buffer, size_t len)
+{
+  int idx = 0;
+  int j;
+
+  if (!_gpgme_debug_trace ())
+    return;
+
+  while (idx < len)
+    {
+      char str[51];
+      char *strp = str;
+      char *strp2 = &str[34];
+      
+      for (j = 0; j < 16; j++)
+	{
+	  unsigned char val;
+	  if (idx < len)
+	    {
+	      val = buffer[idx++];
+	      *(strp++) = TOHEX (val >> 4);
+	      *(strp++) = TOHEX (val % 16);
+	      *(strp2++) = isprint (val) ? val : '.';
+	    }
+	  else
+	    {
+	      *(strp++) = ' ';
+	      *(strp++) = ' ';
+	    }
+	  if (j == 7)
+	    *(strp++) = ' ';
+	}
+      *(strp++) = ' ';
+      *(strp2) = '\0';
+
+      _gpgme_debug (lvl, fmt, func, tagname, tag, str);
+    }
+}
diff --git a/gpgme/debug.h b/gpgme/debug.h
index ef5a400e..72d6319a 100644
--- a/gpgme/debug.h
+++ b/gpgme/debug.h
@@ -1,5 +1,5 @@
 /* debug.h - interface to debugging functions
-   Copyright (C) 2002, 2004, 2005 g10 Code GmbH
+   Copyright (C) 2002, 2004, 2005, 2007 g10 Code GmbH
  
    This file is part of GPGME.
 
@@ -23,6 +23,21 @@
 
 #include <string.h>
 
+/* Indirect stringification, requires __STDC__ to work.  */
+#define STRINGIFY(v) #v
+#define XSTRINGIFY(v) STRINGIFY(v)
+
+
+/* The debug levels.  */
+
+#define DEBUG_INIT	1
+#define DEBUG_CTX	2
+#define DEBUG_ENGINE	3
+#define DEBUG_DATA	4
+#define DEBUG_ASSUAN	5
+#define DEBUG_SYSIO	6
+
+
 /* Remove path components from filenames (i.e. __FILE__) for cleaner
    logs. */
 static inline const char *_gpgme_debug_srcname (const char *file)
@@ -49,80 +64,160 @@ void _gpgme_debug_add (void **helper, const char *format, ...);
    stream.  */
 void _gpgme_debug_end (void **helper);
 
-/* Indirect stringification, requires __STDC__ to work.  */
-#define STRINGIFY(v) #v
-#define XSTRINGIFY(v) STRINGIFY(v)
+void _gpgme_debug_buffer (int lvl, const char *const fmt,
+			  const char *const func, const char *const tagname,
+			  void *tag, const char *const buffer, size_t len);
 
-#if 0
-/* Only works in GNU.  */
-#define DEBUG(fmt, arg...) \
-  _gpgme_debug (1, "%s:%s: " fmt, __FILE__, XSTRINGIFY (__LINE__) , ##arg)
-#define DEBUG_BEGIN(hlp, lvl, fmt, arg...) \
-  _gpgme_debug_begin (&(hlp), lvl, "%s:%s: " fmt, __FILE__, \
-		      XSTRINGIFY (__LINE__) , ##arg)
-#define DEBUG_ADD(hlp, fmt, arg...) \
-  _gpgme_debug_add (&(hlp), fmt , ##arg)
-#define DEBUG_END(hlp, fmt, arg...) \
-  _gpgme_debug_add (&(hlp), fmt , ##arg); \
-  _gpgme_debug_end (&(hlp))
-#elif 0
-/* Only works in C99.  */
-#define DEBUG0(fmt) \
-  _gpgme_debug (1, "%s:%s: " fmt, __FILE__, XSTRINGIFY (__LINE__))
-#define DEBUG(fmt, ...) \
-  _gpgme_debug (1, "%s:%s: " fmt, __FILE__, XSTRINGIFY (__LINE__), __VA_ARGS__)
-#define DEBUG_BEGIN(hlp, lvl, fmt) \
-  _gpgme_debug_begin (&(hlp), lvl, "%s:%s: " fmt, __FILE__, \
-		      XSTRINGIFY (__LINE__))
-#define DEBUG_BEGINX(hlp, lvl, fmt, ...) \
-  _gpgme_debug_begin (&(hlp), lvl, "%s:%s: " fmt, __FILE__, \
-		      XSTRINGIFY (__LINE__), __VA_ARGS__)
-#define DEBUG_ADD0(hlp, fmt) \
-  _gpgme_debug_add (&(hlp), fmt)
-#define DEBUG_ADD(hlp, fmt, ...) \
-  _gpgme_debug_add (&(hlp), fmt, __VA_ARGS__)
-#define DEBUG_END(hlp, fmt) \
-  _gpgme_debug_add (&(hlp), fmt); \
-  _gpgme_debug_end (&(hlp))
-#define DEBUG_ENDX(hlp, fmt, ...) \
-  _gpgme_debug_add (&(hlp), fmt, __VA_ARGS__); \
-  _gpgme_debug_end (&(hlp))
-#else
-/* This finally works everywhere, horror.  */
-#define DEBUG0(fmt) \
-  _gpgme_debug (1, "%s:%s: " fmt, _gpgme_debug_srcname (__FILE__), \
-                XSTRINGIFY (__LINE__))
-#define DEBUG1(fmt,a) \
-  _gpgme_debug (1, "%s:%s: " fmt, _gpgme_debug_srcname (__FILE__), \
-                XSTRINGIFY (__LINE__), (a))
-#define DEBUG2(fmt,a,b) \
-  _gpgme_debug (1, "%s:%s: " fmt, _gpgme_debug_srcname (__FILE__), \
-                XSTRINGIFY (__LINE__), (a), (b))
-#define DEBUG3(fmt,a,b,c) \
-  _gpgme_debug (1, "%s:%s: " fmt, _gpgme_debug_srcname (__FILE__), \
-                XSTRINGIFY (__LINE__), (a), (b), (c))
-#define DEBUG4(fmt,a,b,c,d) \
-  _gpgme_debug (1, "%s:%s: " fmt, _gpgme_debug_srcname (__FILE__), \
-                XSTRINGIFY (__LINE__), (a), (b), (c), (d))
-#define DEBUG5(fmt,a,b,c,d,e) \
-  _gpgme_debug (1, "%s:%s: " fmt, _gpgme_debug_srcname (__FILE__), \
-                XSTRINGIFY (__LINE__), (a), (b), (c), (d), (e))
-#define DEBUG_BEGIN(hlp,lvl,fmt) \
-  _gpgme_debug_begin (&(hlp), lvl, "%s:%s: " fmt, \
-                      _gpgme_debug_srcname (__FILE__), XSTRINGIFY (__LINE__))
-#define DEBUG_ADD0(hlp,fmt) \
+
+/* Trace support.  */
+
+/* FIXME: For now.  */
+#define _gpgme_debug_trace() 1
+
+#define _TRACE(lvl, name, tag)					\
+  int _gpgme_trace_level = lvl;					\
+  const char *const _gpgme_trace_func = name;			\
+  const char *const _gpgme_trace_tagname = STRINGIFY (tag);	\
+  void *_gpgme_trace_tag = (void *) tag
+
+#define TRACE_BEG(lvl, name, tag)			   \
+  _TRACE (lvl, name, tag);				   \
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): enter\n", \
+		_gpgme_trace_func, _gpgme_trace_tagname,   \
+		_gpgme_trace_tag), 0
+#define TRACE_BEG0(lvl, name, tag, fmt)					\
+  _TRACE (lvl, name, tag);						\
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): enter: " fmt "\n",	\
+		_gpgme_trace_func, _gpgme_trace_tagname,		\
+		_gpgme_trace_tag), 0
+#define TRACE_BEG1(lvl, name, tag, fmt, arg1)				\
+  _TRACE (lvl, name, tag);						\
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): enter: " fmt "\n",	\
+		_gpgme_trace_func, _gpgme_trace_tagname,		\
+		_gpgme_trace_tag, arg1), 0
+#define TRACE_BEG2(lvl, name, tag, fmt, arg1, arg2)		    \
+  _TRACE (lvl, name, tag);					    \
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): enter: " fmt "\n", \
+		_gpgme_trace_func, _gpgme_trace_tagname,	    \
+		_gpgme_trace_tag, arg1, arg2), 0
+#define TRACE_BEG3(lvl, name, tag, fmt, arg1, arg2, arg3)	    \
+  _TRACE (lvl, name, tag);					    \
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): enter: " fmt "\n", \
+		_gpgme_trace_func, _gpgme_trace_tagname,	    \
+		_gpgme_trace_tag, arg1, arg2, arg3), 0
+#define TRACE_BEG4(lvl, name, tag, fmt, arg1, arg2, arg3, arg4)	    \
+  _TRACE (lvl, name, tag);					    \
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): enter: " fmt "\n", \
+		_gpgme_trace_func, _gpgme_trace_tagname,	    \
+		_gpgme_trace_tag, arg1, arg2, arg3, arg4), 0
+
+#define TRACE(lvl, name, tag)						\
+  _gpgme_debug (lvl, "%s (%s=0x%x): call\n",				\
+		name, STRINGIFY (tag), (void *) tag), 0
+#define TRACE0(lvl, name, tag, fmt)					\
+  _gpgme_debug (lvl, "%s (%s=0x%x): call: " fmt "\n",			\
+		name, STRINGIFY (tag), (void *) tag), 0
+#define TRACE1(lvl, name, tag, fmt, arg1)			       \
+  _gpgme_debug (lvl, "%s (%s=0x%x): call: " fmt "\n",		       \
+		name, STRINGIFY (tag), (void *) tag, arg1), 0
+#define TRACE2(lvl, name, tag, fmt, arg1, arg2)			       \
+  _gpgme_debug (lvl, "%s (%s=0x%x): call: " fmt "\n",		       \
+		name, STRINGIFY (tag), (void *) tag, arg1, arg2), 0
+#define TRACE3(lvl, name, tag, fmt, arg1, arg2, arg3)		       \
+  _gpgme_debug (lvl, "%s (%s=0x%x): call: " fmt "\n",		       \
+		name, STRINGIFY (tag), (void *) tag, arg1, arg2,       \
+		arg3), 0
+#define TRACE6(lvl, name, tag, fmt, arg1, arg2, arg3, arg4, arg5, arg6)	\
+  _gpgme_debug (lvl, "%s (%s=0x%x): call: " fmt "\n",			\
+		name, STRINGIFY (tag), (void *) tag, arg1, arg2, arg3,	\
+		arg4, arg5, arg6), 0
+
+#define TRACE_ERR(err)							\
+  err == 0 ? (TRACE_SUC ()) :						\
+    (_gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): error: %s <%s>\n",	\
+		   _gpgme_trace_func, _gpgme_trace_tagname,		\
+		   _gpgme_trace_tag, gpgme_strerror (err),		\
+		   gpgme_strsource (err)), (err))
+/* The cast to void suppresses GCC warnings.  */
+#define TRACE_SYSRES(res)						\
+  res >= 0 ? ((void) (TRACE_SUC1 ("result=%i", res)), (res)) :		\
+    (_gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): error: %s\n",	\
+		   _gpgme_trace_func, _gpgme_trace_tagname,		\
+		   _gpgme_trace_tag, strerror (errno)), (res))
+#define TRACE_SYSERR(res)						\
+  res == 0 ? ((void) (TRACE_SUC1 ("result=%i", res)), (res)) :		\
+    (_gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): error: %s\n",	\
+		   _gpgme_trace_func, _gpgme_trace_tagname,		\
+		   _gpgme_trace_tag, strerror (res)), (res))
+
+#define TRACE_SUC()						 \
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): leave\n",       \
+		_gpgme_trace_func, _gpgme_trace_tagname,	 \
+		_gpgme_trace_tag), 0
+#define TRACE_SUC0(fmt)							\
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): leave: " fmt "\n",	\
+		_gpgme_trace_func, _gpgme_trace_tagname,		\
+		_gpgme_trace_tag), 0
+#define TRACE_SUC1(fmt, arg1)						\
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): leave: " fmt "\n",	\
+		_gpgme_trace_func, _gpgme_trace_tagname,		\
+		_gpgme_trace_tag, arg1), 0
+#define TRACE_SUC2(fmt, arg1, arg2)					\
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): leave: " fmt "\n",	\
+		_gpgme_trace_func, _gpgme_trace_tagname,		\
+		_gpgme_trace_tag, arg1, arg2), 0
+#define TRACE_SUC5(fmt, arg1, arg2, arg3, arg4, arg5)			\
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): leave: " fmt "\n",	\
+		_gpgme_trace_func, _gpgme_trace_tagname,		\
+		_gpgme_trace_tag, arg1, arg2, arg3, arg4, arg5), 0
+
+#define TRACE_LOG(fmt)							\
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): check: " fmt "\n",	\
+		_gpgme_trace_func, _gpgme_trace_tagname,		\
+		_gpgme_trace_tag), 0
+#define TRACE_LOG1(fmt, arg1)						\
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): check: " fmt "\n",	\
+		_gpgme_trace_func, _gpgme_trace_tagname,		\
+		_gpgme_trace_tag, arg1), 0
+#define TRACE_LOG2(fmt, arg1, arg2)				    \
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): check: " fmt "\n", \
+		_gpgme_trace_func, _gpgme_trace_tagname,	    \
+		_gpgme_trace_tag, arg1, arg2), 0
+#define TRACE_LOG3(fmt, arg1, arg2, arg3)			    \
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): check: " fmt "\n", \
+		_gpgme_trace_func, _gpgme_trace_tagname,	    \
+		_gpgme_trace_tag, arg1, arg2, arg3), 0
+#define TRACE_LOG4(fmt, arg1, arg2, arg3, arg4)			    \
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): check: " fmt "\n", \
+		_gpgme_trace_func, _gpgme_trace_tagname,	    \
+		_gpgme_trace_tag, arg1, arg2, arg3, arg4), 0
+#define TRACE_LOG6(fmt, arg1, arg2, arg3, arg4, arg5, arg6)	    \
+  _gpgme_debug (_gpgme_trace_level, "%s (%s=0x%x): check: " fmt "\n", \
+		_gpgme_trace_func, _gpgme_trace_tagname,	    \
+		_gpgme_trace_tag, arg1, arg2, arg3, arg4, arg5,	    \
+		arg6), 0
+
+#define TRACE_LOGBUF(buf, len)						\
+  _gpgme_debug_buffer (_gpgme_trace_level, "%s (%s=0x%x): check: %s",	\
+		       _gpgme_trace_func, _gpgme_trace_tagname,		\
+		       _gpgme_trace_tag, buf, len)
+
+#define TRACE_SEQ(hlp,fmt)						\
+  _gpgme_debug_begin (&(hlp), _gpgme_trace_level,			\
+		      "%s (%s=0x%x): check: " fmt,			\
+		      _gpgme_trace_func, _gpgme_trace_tagname,		\
+		      _gpgme_trace_tag)
+#define TRACE_ADD0(hlp,fmt) \
   _gpgme_debug_add (&(hlp), fmt)
-#define DEBUG_ADD1(hlp,fmt,a) \
+#define TRACE_ADD1(hlp,fmt,a) \
   _gpgme_debug_add (&(hlp), fmt, (a))
-#define DEBUG_ADD2(hlp,fmt,a,b) \
+#define TRACE_ADD2(hlp,fmt,a,b) \
   _gpgme_debug_add (&(hlp), fmt, (a), (b))
-#define DEBUG_ADD3(hlp,fmt,a,b,c) \
+#define TRACE_ADD3(hlp,fmt,a,b,c) \
   _gpgme_debug_add (&(hlp), fmt, (a), (b), (c))
-#define DEBUG_END(hlp,fmt) \
+#define TRACE_END(hlp,fmt) \
   _gpgme_debug_add (&(hlp), fmt); \
   _gpgme_debug_end (&(hlp))
-#endif
-
-#define DEBUG_ENABLED(hlp) (!!(hlp))
+#define TRACE_ENABLED(hlp) (!!(hlp))
 
 #endif	/* DEBUG_H */
diff --git a/gpgme/engine-gpgsm.c b/gpgme/engine-gpgsm.c
index e7853918..8c55a01e 100644
--- a/gpgme/engine-gpgsm.c
+++ b/gpgme/engine-gpgsm.c
@@ -1,6 +1,6 @@
 /* engine-gpgsm.c - GpgSM engine.
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004, 2005 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2005, 2007 g10 Code GmbH
  
    This file is part of GPGME.
 
@@ -807,12 +807,11 @@ status_handler (void *opaque, int fd)
       assuan_err = assuan_read_line (gpgsm->assuan_ctx, &line, &linelen);
       if (assuan_err)
 	{
-#if 0
 	  /* Try our best to terminate the connection friendly.  */
-	  assuan_write_line (gpgsm->assuan_ctx, "BYE");
-#endif
+	  /*	  assuan_write_line (gpgsm->assuan_ctx, "BYE"); */
 	  err = map_assuan_error (assuan_err);
-          DEBUG3 ("fd %d: error from assuan (%d) getting status line : %s \n",
+          TRACE3 (DEBUG_CTX, "gpgme:status_handler", gpgsm,
+		  "fd 0x%x: error from assuan (%d) getting status line : %s",
                   fd, assuan_err, gpg_strerror (err));
 	}
       else if (linelen >= 3
@@ -823,12 +822,11 @@ status_handler (void *opaque, int fd)
 	    err = map_assuan_error (atoi (&line[4]));
 	  else
 	    err = gpg_error (GPG_ERR_GENERAL);
-          DEBUG2 ("fd %d: ERR line - mapped to: %s\n",
-                  fd, err? gpg_strerror (err):"ok");
-#if 0
+          TRACE2 (DEBUG_CTX, "gpgme:status_handler", gpgsm,
+		  "fd 0x%x: ERR line - mapped to: %s",
+                  fd, err ? gpg_strerror (err) : "ok");
 	  /* Try our best to terminate the connection friendly.  */
-	  assuan_write_line (gpgsm->assuan_ctx, "BYE");
-#endif
+	  //	  assuan_write_line (gpgsm->assuan_ctx, "BYE");
 	}
       else if (linelen >= 2
 	       && line[0] == 'O' && line[1] == 'K'
@@ -848,9 +846,10 @@ status_handler (void *opaque, int fd)
               gpgsm->colon.any = 0;
               err = gpgsm->colon.fnc (gpgsm->colon.fnc_value, NULL);
             }
- 	  _gpgme_io_close (gpgsm->status_cb.fd);
-          DEBUG2 ("fd %d: OK line - final status: %s\n",
-                  fd, err? gpg_strerror (err):"ok");
+	  _gpgme_io_close (gpgsm->status_cb.fd);
+          TRACE2 (DEBUG_CTX, "gpgme:status_handler", gpgsm,
+		  "fd 0x%x: OK line - final status: %s",
+                  fd, err ? gpg_strerror (err) : "ok");
 	  return err;
 	}
       else if (linelen > 2
@@ -923,7 +922,8 @@ status_handler (void *opaque, int fd)
 		    dst++;
 		}
 	    }
-          DEBUG2 ("fd %d: D line; final status: %s\n",
+          TRACE2 (DEBUG_CTX, "gpgme:status_handler", gpgsm,
+		  "fd 0x%x: D line; final status: %s",
                   fd, err? gpg_strerror (err):"ok");
         }
       else if (linelen > 2
@@ -947,7 +947,8 @@ status_handler (void *opaque, int fd)
 	    }
 	  else
 	    fprintf (stderr, "[UNKNOWN STATUS]%s %s", line + 2, rest);
-          DEBUG3 ("fd %d: S line (%s) - final status: %s\n",
+          TRACE3 (DEBUG_CTX, "gpgme:status_handler", gpgsm,
+		  "fd 0x%x: S line (%s) - final status: %s",
                   fd, line+2, err? gpg_strerror (err):"ok");
 	}
     }
diff --git a/gpgme/gpgme.c b/gpgme/gpgme.c
index 36eefb20..3ae4c1a8 100644
--- a/gpgme/gpgme.c
+++ b/gpgme/gpgme.c
@@ -1,6 +1,6 @@
 /* gpgme.c - GnuPG Made Easy.
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004, 2005 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2005, 2007 g10 Code GmbH
 
    This file is part of GPGME.
  
@@ -33,6 +33,7 @@
 #include "context.h"
 #include "ops.h"
 #include "wait.h"
+#include "debug.h"
 
 
 /* The default locale.  */
@@ -47,16 +48,17 @@ gpgme_error_t
 gpgme_new (gpgme_ctx_t *r_ctx)
 {
   gpgme_ctx_t ctx;
+  TRACE_BEG (DEBUG_CTX, "gpgme_new", r_ctx);
 
   ctx = calloc (1, sizeof *ctx);
   if (!ctx)
-    return gpg_error_from_errno (errno);
+    return TRACE_ERR (gpg_error_from_errno (errno));
 
   _gpgme_engine_info_copy (&ctx->engine_info);
   if (!ctx->engine_info)
     {
       free (ctx);
-      return gpg_error_from_errno (errno);
+      return TRACE_ERR (gpg_error_from_errno (errno));
     }
 
   ctx->keylist_mode = GPGME_KEYLIST_MODE_LOCAL;
@@ -73,7 +75,7 @@ gpgme_new (gpgme_ctx_t *r_ctx)
 	  UNLOCK (def_lc_lock);
 	  _gpgme_engine_info_release (ctx->engine_info);
 	  free (ctx);
-	  return gpg_error_from_errno (errno);
+	  return TRACE_ERR (gpg_error_from_errno (errno));
 	}
     }
   else
@@ -89,7 +91,7 @@ gpgme_new (gpgme_ctx_t *r_ctx)
 	    free (ctx->lc_ctype);
 	  _gpgme_engine_info_release (ctx->engine_info);
 	  free (ctx);
-	  return gpg_error_from_errno (errno);
+	  return TRACE_ERR (gpg_error_from_errno (errno));
 	}
     }
   else
@@ -97,7 +99,8 @@ gpgme_new (gpgme_ctx_t *r_ctx)
   UNLOCK (def_lc_lock);
 
   *r_ctx = ctx;
-  return 0;
+
+  return TRACE_SUC1 ("ctx=%p", ctx);
 }
 
 
@@ -106,21 +109,24 @@ gpgme_error_t
 gpgme_cancel (gpgme_ctx_t ctx)
 {
   gpgme_error_t err;
+  TRACE_BEG (DEBUG_CTX, "gpgme_cancel", ctx);
 
   err = _gpgme_engine_cancel (ctx->engine);
   if (err)
-    return err;
+    return TRACE_ERR (err);
 
   err = gpg_error (GPG_ERR_CANCELED);
   _gpgme_engine_io_event (ctx->engine, GPGME_EVENT_DONE, &err);
 
-  return 0;
+  return TRACE_ERR (0);
 }
 
 /* Release all resources associated with the given context.  */
 void
 gpgme_release (gpgme_ctx_t ctx)
 {
+  TRACE (DEBUG_CTX, "gpgme_release", ctx);
+
   _gpgme_engine_release (ctx->engine);
   _gpgme_fd_table_deinit (&ctx->fdt);
   _gpgme_release_result (ctx);
@@ -156,27 +162,36 @@ _gpgme_release_result (gpgme_ctx_t ctx)
 gpgme_error_t
 gpgme_set_protocol (gpgme_ctx_t ctx, gpgme_protocol_t protocol)
 {
+  TRACE_BEG2 (DEBUG_CTX, "gpgme_set_protocol", ctx, "protocol=%i (%s)",
+	      protocol, gpgme_get_protocol_name (protocol)
+	      ? gpgme_get_protocol_name (protocol) : "unknown");
+
   if (protocol != GPGME_PROTOCOL_OpenPGP && protocol != GPGME_PROTOCOL_CMS)
-    return gpg_error (GPG_ERR_INV_VALUE);
+    return TRACE_ERR (gpg_error (GPG_ERR_INV_VALUE));
 
   if (ctx->protocol != protocol)
     {
       /* Shut down the engine when switching protocols.  */
       if (ctx->engine)
 	{
+	  TRACE_LOG1 ("releasing ctx->engine=%p", ctx->engine);
 	  _gpgme_engine_release (ctx->engine);
 	  ctx->engine = NULL;
 	}
 
       ctx->protocol = protocol;
     }
-  return 0;
+  return TRACE_ERR (0);
 }
 
 
 gpgme_protocol_t
 gpgme_get_protocol (gpgme_ctx_t ctx)
 {
+  TRACE2 (DEBUG_CTX, "gpgme_get_protocol", ctx,
+	  "ctx->protocol=%i (%s)", ctx->protocol,
+	  gpgme_get_protocol_name (ctx->protocol)
+	  ? gpgme_get_protocol_name (ctx->protocol) : "unknown");
   return ctx->protocol;
 }
 
@@ -199,9 +214,11 @@ gpgme_get_protocol_name (gpgme_protocol_t protocol)
 
 /* Enable or disable the use of an ascii armor for all output.  */
 void
-gpgme_set_armor (gpgme_ctx_t ctx, int yes)
+gpgme_set_armor (gpgme_ctx_t ctx, int use_armor)
 {
-  ctx->use_armor = yes;
+  TRACE2 (DEBUG_CTX, "gpgme_set_armor", ctx, "use_armor=%i (%s)",
+	  use_armor, use_armor ? "yes" : "no");
+  ctx->use_armor = use_armor;
 }
 
 
@@ -209,6 +226,8 @@ gpgme_set_armor (gpgme_ctx_t ctx, int yes)
 int
 gpgme_get_armor (gpgme_ctx_t ctx)
 {
+  TRACE2 (DEBUG_CTX, "gpgme_get_armor", ctx, "ctx->use_armor=%i (%s)",
+	  ctx->use_armor, ctx->use_armor ? "yes" : "no");
   return ctx->use_armor;
 }
 
@@ -218,15 +237,19 @@ gpgme_get_armor (gpgme_ctx_t ctx)
   3156 mandates that the MUA does some preparations so that textmode
   is not needed anymore.  */
 void
-gpgme_set_textmode (gpgme_ctx_t ctx, int yes)
+gpgme_set_textmode (gpgme_ctx_t ctx, int use_textmode)
 {
-  ctx->use_textmode = yes;
+  TRACE2 (DEBUG_CTX, "gpgme_set_textmode", ctx, "use_textmode=%i (%s)",
+	  use_textmode, use_textmode ? "yes" : "no");
+  ctx->use_textmode = use_textmode;
 }
 
 /* Return the state of the textmode flag.  */
 int
 gpgme_get_textmode (gpgme_ctx_t ctx)
 {
+  TRACE2 (DEBUG_CTX, "gpgme_get_textmode", ctx, "ctx->use_textmode=%i (%s)",
+	  ctx->use_textmode, ctx->use_textmode ? "yes" : "no");
   return ctx->use_textmode;
 }
 
@@ -243,6 +266,9 @@ gpgme_set_include_certs (gpgme_ctx_t ctx, int nr_of_certs)
     ctx->include_certs = -2;
   else
     ctx->include_certs = nr_of_certs;
+
+  TRACE2 (DEBUG_CTX, "gpgme_set_include_certs", ctx, "nr_of_certs=%i%s",
+	  nr_of_certs, nr_of_certs == ctx->include_certs ? "" : " (-2)");
 }
 
 
@@ -251,6 +277,8 @@ gpgme_set_include_certs (gpgme_ctx_t ctx, int nr_of_certs)
 int
 gpgme_get_include_certs (gpgme_ctx_t ctx)
 {
+  TRACE1 (DEBUG_CTX, "gpgme_get_include_certs", ctx, "ctx->include_certs=%i",
+	  ctx->include_certs);
   return ctx->include_certs;
 }
 
@@ -261,6 +289,9 @@ gpgme_get_include_certs (gpgme_ctx_t ctx)
 gpgme_error_t
 gpgme_set_keylist_mode (gpgme_ctx_t ctx, gpgme_keylist_mode_t mode)
 {
+  TRACE1 (DEBUG_CTX, "gpgme_set_keylist_mode", ctx, "keylist_mode=0x%x",
+	  mode);
+
   ctx->keylist_mode = mode;
   return 0;
 }
@@ -270,6 +301,8 @@ gpgme_set_keylist_mode (gpgme_ctx_t ctx, gpgme_keylist_mode_t mode)
 gpgme_keylist_mode_t
 gpgme_get_keylist_mode (gpgme_ctx_t ctx)
 {
+  TRACE1 (DEBUG_CTX, "gpgme_get_keylist_mode", ctx,
+	  "ctx->keylist_mode=0x%x", ctx->keylist_mode);
   return ctx->keylist_mode;
 }
 
@@ -280,6 +313,8 @@ void
 gpgme_set_passphrase_cb (gpgme_ctx_t ctx, gpgme_passphrase_cb_t cb,
 			 void *cb_value)
 {
+  TRACE2 (DEBUG_CTX, "gpgme_set_passphrase_cb", ctx,
+	  "passphrase_cb=%p/%p", cb, cb_value);
   ctx->passphrase_cb = cb;
   ctx->passphrase_cb_value = cb_value;
 }
@@ -291,6 +326,9 @@ void
 gpgme_get_passphrase_cb (gpgme_ctx_t ctx, gpgme_passphrase_cb_t *r_cb,
 			 void **r_cb_value)
 {
+  TRACE2 (DEBUG_CTX, "gpgme_get_passphrase_cb", ctx,
+	  "ctx->passphrase_cb=%p/%p",
+	  ctx->passphrase_cb, ctx->passphrase_cb_value);
   if (r_cb)
     *r_cb = ctx->passphrase_cb;
   if (r_cb_value)
@@ -303,6 +341,8 @@ gpgme_get_passphrase_cb (gpgme_ctx_t ctx, gpgme_passphrase_cb_t *r_cb,
 void
 gpgme_set_progress_cb (gpgme_ctx_t ctx, gpgme_progress_cb_t cb, void *cb_value)
 {
+  TRACE2 (DEBUG_CTX, "gpgme_set_progress_cb", ctx, "progress_cb=%p/%p",
+	  cb, cb_value);
   ctx->progress_cb = cb;
   ctx->progress_cb_value = cb_value;
 }
@@ -314,6 +354,8 @@ void
 gpgme_get_progress_cb (gpgme_ctx_t ctx, gpgme_progress_cb_t *r_cb,
 		       void **r_cb_value)
 {
+  TRACE2 (DEBUG_CTX, "gpgme_get_progress_cb", ctx, "ctx->progress_cb=%p/%p",
+	  ctx->progress_cb, ctx->progress_cb_value);
   if (r_cb)
     *r_cb = ctx->progress_cb;
   if (r_cb_value)
@@ -326,9 +368,17 @@ void
 gpgme_set_io_cbs (gpgme_ctx_t ctx, gpgme_io_cbs_t io_cbs)
 {
   if (io_cbs)
-    ctx->io_cbs = *io_cbs;
+    {
+      TRACE6 (DEBUG_CTX, "gpgme_set_io_cbs", ctx,
+	      "io_cbs=%p (add=%p/%p, remove=%p, event=%p/%p",
+	      io_cbs, io_cbs->add, io_cbs->add_priv, io_cbs->remove,
+	      io_cbs->event, io_cbs->event_priv);
+      ctx->io_cbs = *io_cbs;
+    }
   else
     {
+      TRACE1 (DEBUG_CTX, "gpgme_set_io_cbs", ctx,
+	      "io_cbs=%p (default)", io_cbs);
       ctx->io_cbs.add = NULL;
       ctx->io_cbs.add_priv = NULL;
       ctx->io_cbs.remove = NULL;
@@ -342,6 +392,11 @@ gpgme_set_io_cbs (gpgme_ctx_t ctx, gpgme_io_cbs_t io_cbs)
 void
 gpgme_get_io_cbs (gpgme_ctx_t ctx, gpgme_io_cbs_t io_cbs)
 {
+  TRACE6 (DEBUG_CTX, "gpgme_get_io_cbs", ctx,
+	  "io_cbs=%p, ctx->io_cbs.add=%p/%p, .remove=%p, .event=%p/%p",
+	  io_cbs, io_cbs->add, io_cbs->add_priv, io_cbs->remove,
+	  io_cbs->event, io_cbs->event_priv);
+
   *io_cbs = ctx->io_cbs;
 }
 
@@ -355,6 +410,9 @@ gpgme_set_locale (gpgme_ctx_t ctx, int category, const char *value)
   char *new_lc_ctype = NULL;
   char *new_lc_messages = NULL;
 
+  TRACE_BEG2 (DEBUG_CTX, "gpgme_set_locale", ctx,
+	       "category=%i, value=%s", category, value ? value : "(null)");
+
 #define PREPARE_ONE_LOCALE(lcat, ucat)				\
   if (!failed && value						\
       && (category == LC_ALL || category == LC_ ## ucat))	\
@@ -378,7 +436,7 @@ gpgme_set_locale (gpgme_ctx_t ctx, int category, const char *value)
       if (new_lc_messages)
 	free (new_lc_messages);
 
-      return gpg_error_from_errno (saved_errno);
+      return TRACE_ERR (gpg_error_from_errno (saved_errno));
     }
 
 #define SET_ONE_LOCALE(lcat, ucat)			\
@@ -407,7 +465,7 @@ gpgme_set_locale (gpgme_ctx_t ctx, int category, const char *value)
   if (!ctx)
     UNLOCK (def_lc_lock);
 
-  return 0;
+  return TRACE_ERR (0);
 }
 
 
@@ -417,6 +475,8 @@ gpgme_set_locale (gpgme_ctx_t ctx, int category, const char *value)
 gpgme_engine_info_t
 gpgme_ctx_get_engine_info (gpgme_ctx_t ctx)
 {
+  TRACE1 (DEBUG_CTX, "gpgme_ctx_get_engine_info", ctx,
+	  "ctx->engine_info=%p", ctx->engine_info);
   return ctx->engine_info;
 }
 
@@ -427,14 +487,24 @@ gpgme_error_t
 gpgme_ctx_set_engine_info (gpgme_ctx_t ctx, gpgme_protocol_t proto,
 			   const char *file_name, const char *home_dir)
 {
+  gpgme_error_t err;
+  TRACE_BEG4 (DEBUG_CTX, "gpgme_ctx_set_engine_info", ctx,
+	      "protocol=%i (%s), file_name=%s, home_dir=%s",
+	      proto, gpgme_get_protocol_name (proto)
+	      ? gpgme_get_protocol_name (proto) : "unknown",
+	      file_name ? file_name : "(default)",
+	      home_dir ? home_dir : "(default)");
+	      
   /* Shut down the engine when changing engine info.  */
   if (ctx->engine)
     {
+      TRACE_LOG1 ("releasing ctx->engine=%p", ctx->engine);
       _gpgme_engine_release (ctx->engine);
       ctx->engine = NULL;
     }
-  return _gpgme_set_engine_info (ctx->engine_info, proto,
-				 file_name, home_dir);
+  err = _gpgme_set_engine_info (ctx->engine_info, proto,
+				file_name, home_dir);
+  return TRACE_ERR (err);
 }
 
 
@@ -443,6 +513,7 @@ void
 gpgme_sig_notation_clear (gpgme_ctx_t ctx)
 {
   gpgme_sig_notation_t notation;
+  TRACE (DEBUG_CTX, "gpgme_sig_notation_clear", ctx);
 
   if (!ctx)
     return;
@@ -470,8 +541,13 @@ gpgme_sig_notation_add (gpgme_ctx_t ctx, const char *name,
   gpgme_sig_notation_t notation;
   gpgme_sig_notation_t *lastp;
 
+  TRACE_BEG3 (DEBUG_CTX, "gpgme_sig_notation_add", ctx,
+	      "name=%s, value=%s, flags=0x%x",
+	      name ? name : "(null)", value ? value : "(null)",
+	      flags);
+  
   if (!ctx)
-    return gpg_error (GPG_ERR_INV_VALUE);
+    return TRACE_ERR (gpg_error (GPG_ERR_INV_VALUE));
 
   if (name)
     flags |= GPGME_SIG_NOTATION_HUMAN_READABLE;
@@ -481,14 +557,14 @@ gpgme_sig_notation_add (gpgme_ctx_t ctx, const char *name,
   err = _gpgme_sig_notation_create (&notation, name, name ? strlen (name) : 0,
 				    value, value ? strlen (value) : 0, flags);
   if (err)
-    return err;
+    return TRACE_ERR (err);
 
   lastp = &ctx->sig_notations;
   while (*lastp)
     lastp = &(*lastp)->next;
 
   *lastp = notation;
-  return 0;
+  return TRACE_ERR (0);
 }
 
 
@@ -497,7 +573,12 @@ gpgme_sig_notation_t
 gpgme_sig_notation_get (gpgme_ctx_t ctx)
 {
   if (!ctx)
-    return NULL;
+    {
+      TRACE (DEBUG_CTX, "gpgme_sig_notation_get", ctx);
+      return NULL;
+    }
+  TRACE1 (DEBUG_CTX, "gpgme_sig_notation_get", ctx,
+	  "ctx->sig_notations=%p", ctx->sig_notations);
 
   return ctx->sig_notations;
 }
diff --git a/gpgme/keylist.c b/gpgme/keylist.c
index 1c60da5c..b56131ce 100644
--- a/gpgme/keylist.c
+++ b/gpgme/keylist.c
@@ -1,6 +1,6 @@
 /* keylist.c - Listing keys.
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004, 2006 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2006, 2007 g10 Code GmbH
 
    This file is part of GPGME.
  
@@ -393,8 +393,8 @@ keylist_colon_handler (void *priv, char *line)
 
   key = opd->tmp_key;
 
-  DEBUG3 ("keylist_colon_handler ctx = %p, key = %p, line = %s\n",
-	  ctx, key, line ? line : "(null)");
+  TRACE2 (DEBUG_CTX, "gpgme:keylist_colon_handler", ctx,
+	  "key = %p, line = %s", key, line ? line : "(null)");
 
   if (!line)
     {
diff --git a/gpgme/posix-io.c b/gpgme/posix-io.c
index c44879db..ca77cf46 100644
--- a/gpgme/posix-io.c
+++ b/gpgme/posix-io.c
@@ -1,6 +1,6 @@
 /* posix-io.c - Posix I/O functions
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2004, 2005 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2004, 2005, 2007 g10 Code GmbH
 
    This file is part of GPGME.
  
@@ -33,6 +33,7 @@
 #include <sys/time.h>
 #include <sys/types.h>
 #include <sys/wait.h>
+#include <ctype.h>
 
 #include "util.h"
 #include "priv-io.h"
@@ -73,44 +74,40 @@ static struct
   void *value;
 } notify_table[256];
 
+
 int
 _gpgme_io_read (int fd, void *buffer, size_t count)
 {
   int nread;
-  int saved_errno;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_read", fd,
+	      "buffer=%p, count=%u", buffer, count);
 
-  DEBUG2 ("fd %d: about to read %d bytes\n", fd, (int) count);
   do
     {
       nread = _gpgme_ath_read (fd, buffer, count);
     }
   while (nread == -1 && errno == EINTR);
-  saved_errno = errno;
-  DEBUG2 ("fd %d: got %d bytes\n", fd, nread);
-  if (nread > 0)
-    _gpgme_debug (2, "fd %d: got `%.*s'\n", fd, nread, buffer);
-  errno = saved_errno;
-  return nread;
+
+  TRACE_LOGBUF (buffer, nread);
+  return TRACE_SYSRES (nread);
 }
 
 
 int
 _gpgme_io_write (int fd, const void *buffer, size_t count)
 {
-  int saved_errno;
   int nwritten;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_write", fd,
+	      "buffer=%p, count=%u", buffer, count);
+  TRACE_LOGBUF (buffer, count);
 
-  DEBUG2 ("fd %d: about to write %d bytes\n", fd, (int) count);
-  _gpgme_debug (2, "fd %d: write `%.*s'\n", fd, (int) count, buffer);
   do
     {
       nwritten = _gpgme_ath_write (fd, buffer, count);
     }
   while (nwritten == -1 && errno == EINTR);
-  saved_errno = errno;
-  DEBUG2 ("fd %d:          wrote %d bytes\n", fd, (int) nwritten);
-  errno = saved_errno;
-  return nwritten;
+
+  return TRACE_SYSRES (nwritten);
 }
 
 
@@ -119,10 +116,14 @@ _gpgme_io_pipe (int filedes[2], int inherit_idx)
 {
   int saved_errno;
   int err;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_pipe", filedes,
+	      "inherit_idx=%i (GPGME uses it for %s)",
+	      inherit_idx, inherit_idx ? "writing" : "reading");
 
   err = pipe (filedes);
   if (err < 0)
-    return err;
+    return TRACE_SYSRES (err);
+
   /* FIXME: Should get the old flags first.  */
   err = fcntl (filedes[1 - inherit_idx], F_SETFD, FD_CLOEXEC);
   saved_errno = errno;
@@ -132,28 +133,41 @@ _gpgme_io_pipe (int filedes[2], int inherit_idx)
       close (filedes[1]);
     }
   errno = saved_errno;
-  return err;
+  if (err)
+    return TRACE_SYSRES (err);
+
+  return TRACE_SUC2 ("read=0x%x, write=0x%x", filedes[0], filedes[1]);
 }
 
 
 int
 _gpgme_io_close (int fd)
 {
+  int res;
+
+  TRACE_BEG (DEBUG_SYSIO, "_gpgme_io_close", fd);
+
   if (fd == -1)
-    return -1;
+    {
+      errno = EINVAL;
+      return TRACE_SYSRES (-1);
+    }
+
   /* First call the notify handler.  */
-  DEBUG1 ("closing fd %d", fd);
   if (fd >= 0 && fd < (int) DIM (notify_table))
     {
       if (notify_table[fd].handler)
 	{
+	  TRACE_LOG2 ("invoking close handler %p/%p",
+		      notify_table[fd].handler, notify_table[fd].value);
 	  notify_table[fd].handler (fd, notify_table[fd].value);
 	  notify_table[fd].handler = NULL;
 	  notify_table[fd].value = NULL;
         }
     }
   /* Then do the close.  */    
-  return close (fd);
+  res = close (fd);
+  return TRACE_SYSRES (res);
 }
 
 
@@ -161,14 +175,19 @@ int
 _gpgme_io_set_close_notify (int fd, _gpgme_close_notify_handler_t handler,
 			    void *value)
 {
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_set_close_notify", fd,
+	      "close_handler=%p/%p", handler, value);
+
   assert (fd != -1);
 
   if (fd < 0 || fd >= (int) DIM (notify_table))
-    return -1;
-  DEBUG1 ("set notification for fd %d", fd);
+    {
+      errno = EINVAL;
+      return TRACE_SYSRES (-1);
+    }
   notify_table[fd].handler = handler;
   notify_table[fd].value = value;
-  return 0;
+  return TRACE_SYSRES (0);
 }
 
 
@@ -176,12 +195,15 @@ int
 _gpgme_io_set_nonblocking (int fd)
 {
   int flags;
+  int res;
+  TRACE_BEG (DEBUG_SYSIO, "_gpgme_io_set_nonblocking", fd);
 
   flags = fcntl (fd, F_GETFL, 0);
   if (flags == -1)
-    return -1;
+    return TRACE_SYSRES (-1);
   flags |= O_NONBLOCK;
-  return fcntl (fd, F_SETFL, flags);
+  res = fcntl (fd, F_SETFL, flags);
+  return TRACE_SYSRES (res);
 }
 
 
@@ -217,12 +239,21 @@ _gpgme_io_spawn (const char *path, char **argv,
 {
   pid_t pid;
   int i;
-  int status, signo;
-
+  int status;
+  int signo;
+  TRACE_BEG1 (DEBUG_SYSIO, "_gpgme_io_spawn", path,
+	      "path=%s", path);
+  i = 0;
+  while (argv[i])
+    {
+      TRACE_LOG2 ("argv[%2i] = %s", i, argv[i]);
+      i++;
+    }
+  
   pid = fork ();
   if (pid == -1) 
-    return -1;
-
+    return TRACE_SYSRES (-1);
+  
   if (!pid)
     {
       /* Intermediate child to prevent zombie processes.  */
@@ -245,7 +276,12 @@ _gpgme_io_spawn (const char *path, char **argv,
 		  if (dup2 (fd_child_list[i].fd,
 			    fd_child_list[i].dup_to) == -1)
 		    {
-		      DEBUG1 ("dup2 failed in child: %s\n", strerror (errno));
+#if 0
+		      /* FIXME: The debug file descriptor is not
+			 dup'ed anyway, so we can't see this.  */
+		      TRACE_LOG1 ("dup2 failed in child: %s\n",
+				  strerror (errno));
+#endif
 		      _exit (8);
 		    }
 		  if (fd_child_list[i].dup_to == 0)
@@ -261,7 +297,12 @@ _gpgme_io_spawn (const char *path, char **argv,
 	      int fd = open ("/dev/null", O_RDWR);
 	      if (fd == -1)
 		{
-		  DEBUG1 ("can't open `/dev/null': %s\n", strerror (errno));
+#if 0
+		  /* FIXME: The debug file descriptor is not dup'ed
+		     anyway, so we can't see this.  */
+		  TRACE_LOG1 ("can't open `/dev/null': %s\n",
+			      strerror (errno));
+#endif
 		  _exit (8);
 		}
 	      /* Make sure that the process has a connected stdin.  */
@@ -269,16 +310,24 @@ _gpgme_io_spawn (const char *path, char **argv,
 		{
 		  if (dup2 (fd, 0) == -1)
 		    {
-		      DEBUG1("dup2(/dev/null, 0) failed: %s\n",
-			     strerror (errno));
+#if 0
+		  /* FIXME: The debug file descriptor is not dup'ed
+		     anyway, so we can't see this.  */
+		      TRACE_LOG1 ("dup2(/dev/null, 0) failed: %s\n",
+				  strerror (errno));
+#endif
 		      _exit (8);
 		    }
 		}
 	      if (!duped_stderr)
 		if (dup2 (fd, 2) == -1)
 		  {
-		    DEBUG1 ("dup2(dev/null, 2) failed: %s\n",
-			    strerror (errno));
+#if 0
+		    /* FIXME: The debug file descriptor is not dup'ed
+		       anyway, so we can't see this.  */
+		    TRACE_LOG1 ("dup2(dev/null, 2) failed: %s\n",
+				strerror (errno));
+#endif
 		    _exit (8);
 		  }
 	      close (fd);
@@ -287,7 +336,11 @@ _gpgme_io_spawn (const char *path, char **argv,
 	  execv ( path, argv );
 	  /* Hmm: in that case we could write a special status code to the
 	     status-pipe.  */
-	  DEBUG1 ("exec of `%s' failed\n", path);
+#if 0
+	  /* FIXME: The debug file descriptor is not dup'ed anyway, so
+	     we can't see this.  */
+	  TRACE_LOG1 ("exec of `%s' failed\n", path);
+#endif
 	  _exit (8);
 	} /* End child.  */
       if (pid == -1)
@@ -295,34 +348,37 @@ _gpgme_io_spawn (const char *path, char **argv,
       else
 	_exit (0);
     }
-    
+
+  TRACE_LOG1 ("waiting for child process pid=%i", pid);
   _gpgme_io_waitpid (pid, 1, &status, &signo);
   if (status)
-    return -1;
+    return TRACE_SYSRES (-1);
 
   /* .dup_to is not used in the parent list.  */
   for (i = 0; fd_parent_list[i].fd != -1; i++)
     _gpgme_io_close (fd_parent_list[i].fd);
 
-  return 0;
+  return TRACE_SYSRES (0);
 }
 
 
-/*
- * Select on the list of fds.
- * Returns: -1 = error
- *           0 = timeout or nothing to select
- *          >0 = number of signaled fds
- */
+/* Select on the list of fds.  Returns: -1 = error, 0 = timeout or
+   nothing to select, > 0 = number of signaled fds.  */
 int
 _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
 {
   fd_set readfds;
   fd_set writefds;
   unsigned int i;
-  int any, max_fd, n, count;
-  struct timeval timeout = { 1, 0 }; /* Use a 1s timeout.  */
+  int any;
+  int max_fd;
+  int n;
+  int count;
+  /* Use a 1s timeout.  */
+  struct timeval timeout = { 1, 0 };
   void *dbg_help = NULL;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_select", fds,
+	      "nfds=%u, nonblock=%u", nfds, nonblock);
 
   FD_ZERO (&readfds);
   FD_ZERO (&writefds);
@@ -330,21 +386,22 @@ _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
   if (nonblock)
     timeout.tv_sec = 0;
 
-  DEBUG_BEGIN (dbg_help, 3, "gpgme:select on [ ");
+  TRACE_SEQ (dbg_help, "select on [ ");
+
   any = 0;
   for (i = 0; i < nfds; i++)
     {
       if (fds[i].fd == -1) 
 	continue;
       if (fds[i].frozen)
-	DEBUG_ADD1 (dbg_help, "f%d ", fds[i].fd);
+	TRACE_ADD1 (dbg_help, "f0x%x ", fds[i].fd);
       else if (fds[i].for_read)
 	{
 	  assert (!FD_ISSET (fds[i].fd, &readfds));
 	  FD_SET (fds[i].fd, &readfds);
 	  if (fds[i].fd > max_fd)
 	    max_fd = fds[i].fd;
-	  DEBUG_ADD1 (dbg_help, "r%d ", fds[i].fd);
+	  TRACE_ADD1 (dbg_help, "r0x%x ", fds[i].fd);
 	  any = 1;
         }
       else if (fds[i].for_write)
@@ -353,14 +410,14 @@ _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
 	  FD_SET (fds[i].fd, &writefds);
 	  if (fds[i].fd > max_fd)
 	    max_fd = fds[i].fd;
-	  DEBUG_ADD1 (dbg_help, "w%d ", fds[i].fd);
+	  TRACE_ADD1 (dbg_help, "w0x%x ", fds[i].fd);
 	  any = 1;
         }
       fds[i].signaled = 0;
     }
-  DEBUG_END (dbg_help, "]"); 
+  TRACE_END (dbg_help, "]"); 
   if (!any)
-    return 0;
+    return TRACE_SYSRES (0);
 
   do
     {
@@ -369,27 +426,22 @@ _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
     }
   while (count < 0 && errno == EINTR);
   if (count < 0)
-    {
-      int saved_errno = errno;
-      DEBUG1 ("_gpgme_io_select failed: %s\n", strerror (errno));
-      errno = saved_errno;
-      return -1; /* error */
-    }
+    return TRACE_SYSRES (-1);
 
-  DEBUG_BEGIN (dbg_help, 3, "select OK [ ");
-  if (DEBUG_ENABLED (dbg_help))
+  TRACE_SEQ (dbg_help, "select OK [ ");
+  if (TRACE_ENABLED (dbg_help))
     {
       for (i = 0; i <= max_fd; i++)
 	{
 	  if (FD_ISSET (i, &readfds))
-	    DEBUG_ADD1 (dbg_help, "r%d ", i);
+	    TRACE_ADD1 (dbg_help, "r0x%x ", i);
 	  if (FD_ISSET (i, &writefds))
-	    DEBUG_ADD1 (dbg_help, "w%d ", i);
+	    TRACE_ADD1 (dbg_help, "w0x%x ", i);
         }
-      DEBUG_END (dbg_help, "]");
+      TRACE_END (dbg_help, "]");
     }
     
-  /* n is used to optimize it a little bit.  */
+  /* The variable N is used to optimize it a little bit.  */
   for (n = count, i = 0; i < nfds && n; i++)
     {
       if (fds[i].fd == -1)
@@ -411,7 +463,7 @@ _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
             }
         }
     }
-  return count;
+  return TRACE_SYSRES (count);
 }
 
 
@@ -421,6 +473,8 @@ _gpgme_io_recvmsg (int fd, struct msghdr *msg, int flags)
   int nread;
   int saved_errno;
   struct iovec *iov;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_recvmsg", fd,
+	      "msg=%p, flags=%i", msg, flags);
 
   nread = 0;
   iov = msg->msg_iov;
@@ -430,15 +484,14 @@ _gpgme_io_recvmsg (int fd, struct msghdr *msg, int flags)
       iov++;
     }
   
-  DEBUG2 ("fd %d: about to receive %d bytes\n",
-	  fd, (int) nread);
+  TRACE_LOG1 ("about to receive %d bytes", nread);
+
   do
     {
       nread = _gpgme_ath_recvmsg (fd, msg, flags);
     }
   while (nread == -1 && errno == EINTR);
   saved_errno = errno;
-  DEBUG2 ("fd %d: got %d bytes\n", fd, nread);
   if (nread > 0)
     {
       int nr = nread;
@@ -447,23 +500,23 @@ _gpgme_io_recvmsg (int fd, struct msghdr *msg, int flags)
       while (nr > 0)
 	{
 	  int len = nr > iov->iov_len ? iov->iov_len : nr;
-	  _gpgme_debug (2, "fd %d: got `%.*s'\n", fd, len,
-			msg->msg_iov->iov_base);
+	  TRACE_LOGBUF (msg->msg_iov->iov_base, len);
 	  iov++;
 	  nr -= len;
 	}
     }
   errno = saved_errno;
-  return nread;
+  return TRACE_SYSRES (nread);
 }
 
 
 int
 _gpgme_io_sendmsg (int fd, const struct msghdr *msg, int flags)
 {
-  int saved_errno;
   int nwritten;
   struct iovec *iov;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_sendmsg", fd,
+	      "msg=%p, flags=%i", msg, flags);
 
   nwritten = 0;
   iov = msg->msg_iov;
@@ -473,13 +526,12 @@ _gpgme_io_sendmsg (int fd, const struct msghdr *msg, int flags)
       iov++;
     }
 
-  DEBUG2 ("fd %d: about to write %d bytes\n", fd, (int) nwritten);
+  TRACE_LOG1 ("about to receive %d bytes", nwritten);
   iov = msg->msg_iov;
   while (nwritten > 0)
     {
       int len = nwritten > iov->iov_len ? iov->iov_len : nwritten;
-      _gpgme_debug (2, "fd %d: write `%.*s'\n", fd, len,
-		    msg->msg_iov->iov_base);
+      TRACE_LOGBUF (msg->msg_iov->iov_base, len);
       iov++;
       nwritten -= len;
     }
@@ -489,10 +541,7 @@ _gpgme_io_sendmsg (int fd, const struct msghdr *msg, int flags)
       nwritten = _gpgme_ath_sendmsg (fd, msg, flags);
     }
   while (nwritten == -1 && errno == EINTR);
-  saved_errno = errno;
-  DEBUG2 ("fd %d:          wrote %d bytes\n", fd, (int) nwritten);
-  errno = saved_errno;
-  return nwritten;
+  return TRACE_SYSRES (nwritten);
 }
 
 
diff --git a/gpgme/rungpg.c b/gpgme/rungpg.c
index d6fd8fe1..a8fc8ad1 100644
--- a/gpgme/rungpg.c
+++ b/gpgme/rungpg.c
@@ -1,6 +1,6 @@
 /* rungpg.c - Gpg Engine.
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004, 2005, 2006 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2005, 2006, 2007 g10 Code GmbH
  
    This file is part of GPGME.
  
@@ -1002,7 +1002,8 @@ read_status (engine_gpg_t gpg)
 			     received and the next thing will be that
 			     the command handler does its action.  */
 			  if (nread > 1)
-			    DEBUG0 ("ERROR, unexpected data in read_status");
+			    TRACE0 (DEBUG_CTX, "gpgme:read_status", 0,
+				    "error: unexpected data");
 
 			  add_io_cb (gpg, gpg->cmd.fd, 0,
 				     command_handler, gpg,
diff --git a/gpgme/sign.c b/gpgme/sign.c
index 310f9179..8405b690 100644
--- a/gpgme/sign.c
+++ b/gpgme/sign.c
@@ -1,6 +1,6 @@
 /* sign.c - Signing function.
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2007 g10 Code GmbH
 
    This file is part of GPGME.
  
@@ -30,6 +30,7 @@
 #include "context.h"
 #include "ops.h"
 #include "util.h"
+#include "debug.h"
 
 
 typedef struct
@@ -79,11 +80,56 @@ gpgme_op_sign_result (gpgme_ctx_t ctx)
   op_data_t opd;
   gpgme_error_t err;
 
+  TRACE_BEG (DEBUG_CTX, "gpgme_op_sign_result", ctx);
+
   err = _gpgme_op_data_lookup (ctx, OPDATA_SIGN, &hook, -1, NULL);
   opd = hook;
   if (err || !opd)
-    return NULL;
+    {
+      TRACE_SUC0 ("result=(null)");
+      return NULL;
+    }
 
+  if (_gpgme_debug_trace ())
+    {
+      gpgme_invalid_key_t inv_key = opd->result.invalid_signers;
+      gpgme_new_signature_t sig = opd->result.signatures;
+      int inv_signers = 0;
+      int signatures = 0;
+
+      while (inv_key)
+	{
+	  inv_signers++;
+	  inv_key = inv_key->next;
+	}
+      while (sig)
+	{
+	  signatures++;
+	  sig = sig->next;
+	}
+
+      TRACE_LOG2 ("result: invalid signers: %i, signatures: %i",
+		  inv_signers, signatures);
+      inv_key = opd->result.invalid_signers;
+      while (inv_key)
+	{
+	  TRACE_LOG3 ("result: invalid signer: fpr=%s, reason=%s <%s>",
+		      inv_key->fpr, gpgme_strerror (inv_key->reason),
+		      gpgme_strsource (inv_key->reason));
+	  inv_key = inv_key->next;
+	}
+      sig = opd->result.signatures;
+      while (sig)
+	{
+	  TRACE_LOG6 ("result: signature: type=%i, pubkey_algo=%i, "
+		      "hash_algo=%i, timestamp=%li, fpr=%s, sig_class=%i",
+		      sig->type, sig->pubkey_algo, sig->hash_algo,
+		      sig->timestamp, sig->fpr, sig->sig_class);
+	  sig = sig->next;
+	}
+    }
+
+  TRACE_SUC1 ("result=%p", &opd->result);
   return &opd->result;
 }
 
@@ -312,7 +358,9 @@ gpgme_error_t
 gpgme_op_sign_start (gpgme_ctx_t ctx, gpgme_data_t plain, gpgme_data_t sig,
 		     gpgme_sig_mode_t mode)
 {
-  return sign_start (ctx, 0, plain, sig, mode);
+  TRACE_BEG3 (DEBUG_CTX, "gpgme_op_sign_start", ctx,
+	      "plain=%p, sig=%p, mode=%i", plain, sig, mode);
+  return TRACE_ERR (sign_start (ctx, 0, plain, sig, mode));
 }
 
 
@@ -321,8 +369,12 @@ gpgme_error_t
 gpgme_op_sign (gpgme_ctx_t ctx, gpgme_data_t plain, gpgme_data_t sig,
 	       gpgme_sig_mode_t mode)
 {
-  gpgme_error_t err = sign_start (ctx, 1, plain, sig, mode);
+  gpgme_error_t err;
+
+  TRACE_BEG3 (DEBUG_CTX, "gpgme_op_sign_start", ctx,
+	      "plain=%p, sig=%p, mode=%i", plain, sig, mode);
+  err = sign_start (ctx, 1, plain, sig, mode);
   if (!err)
     err = _gpgme_wait_one (ctx);
-  return err;
+  return TRACE_ERR (err);
 }
diff --git a/gpgme/version.c b/gpgme/version.c
index ad893d84..415b5f8e 100644
--- a/gpgme/version.c
+++ b/gpgme/version.c
@@ -1,6 +1,6 @@
 /* version.c - Version check routines.
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004, 2005 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2005, 2007 g10 Code GmbH
  
    This file is part of GPGME.
  
@@ -31,6 +31,7 @@
 
 #include "gpgme.h"
 #include "priv-io.h"
+#include "debug.h"
 
 /* For _gpgme_sema_subsystem_init ().  */
 #include "sema.h"
@@ -169,6 +170,9 @@ _gpgme_compare_versions (const char *my_version,
 const char *
 gpgme_check_version (const char *req_version)
 {
+  TRACE2 (DEBUG_INIT, "gpgme_check_version: ", 0,
+	  "req_version=%s, VERSION=%s", req_version, VERSION);
+
   do_subsystem_inits ();
   return _gpgme_compare_versions (VERSION, req_version) ? VERSION : NULL;
 }
diff --git a/gpgme/w32-glib-io.c b/gpgme/w32-glib-io.c
index 813e807f..9b3e0dc3 100644
--- a/gpgme/w32-glib-io.c
+++ b/gpgme/w32-glib-io.c
@@ -135,17 +135,17 @@ _gpgme_io_read (int fd, void *buffer, size_t count)
   gsize nread;
   GIOChannel *chan;
   GIOStatus status;
-
-  DEBUG2 ("fd %d: about to read %d bytes\n", fd, (int) count);
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_read", fd,
+	      "buffer=%p, count=%u", buffer, count);
 
   chan = find_channel (fd, 0);
   if (!chan)
     {
-      DEBUG1 ("fd %d: no channel registered\n", fd);
+      TRACE_LOG ("no channel registered");
       errno = EINVAL;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
-  DEBUG2 ("fd %d: channel %p\n", fd, chan);
+  TRACE_LOG1 ("channel %p", chan);
 
   {
     GError *err = NULL;
@@ -153,7 +153,7 @@ _gpgme_io_read (int fd, void *buffer, size_t count)
 				      count, &nread, &err);
     if (err)
       {
-	DEBUG3 ("fd %d: status %i, err %s\n", fd, status, err->message);
+	TRACE_LOG2 ("status %i, err %s", status, err->message);
 	g_error_free (err);
       }
   }
@@ -162,17 +162,15 @@ _gpgme_io_read (int fd, void *buffer, size_t count)
     nread = 0;
   else if (status != G_IO_STATUS_NORMAL)
     {
-      DEBUG2 ("fd %d: status %d\n", fd, status);
+      TRACE_LOG1 ("status %d", status);
       nread = -1;
       saved_errno = EIO;
     }
 
-  DEBUG2 ("fd %d: got %d bytes\n", fd, nread);
-  if (nread > 0)
-    _gpgme_debug (2, "fd %d: got `%.*s'\n", fd, nread, buffer);
+  TRACE_LOGBUF (buffer, nread);
 
   errno = saved_errno;
-  return nread;
+  return TRACE_SYSRES (nread);
 }
 
 
@@ -183,14 +181,14 @@ _gpgme_io_write (int fd, const void *buffer, size_t count)
   gsize nwritten;
   GIOChannel *chan;
   GIOStatus status;
-
-  DEBUG2 ("fd %d: about to write %d bytes\n", fd, (int) count);
-  _gpgme_debug (2, "fd %d: write `%.*s'\n", fd, (int) count, buffer);
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_write", fd,
+	      "buffer=%p, count=%u", buffer, count);
+  TRACE_LOGBUF (buffer, count);
 
   chan = find_channel (fd, 0);
   if (!chan)
     {
-      DEBUG1 ("fd %d: no channel registered\n", fd);
+      TRACE_LOG ("fd %d: no channel registered");
       errno = EINVAL;
       return -1;
     }
@@ -202,9 +200,9 @@ _gpgme_io_write (int fd, const void *buffer, size_t count)
       nwritten = -1;
       saved_errno = EIO;
     }
-  DEBUG2 ("fd %d:          wrote %d bytes\n", fd, (int) nwritten);
   errno = saved_errno;
-  return nwritten;
+
+  return TRACE_SYSRES (nwritten);
 }
 
 
@@ -212,10 +210,13 @@ int
 _gpgme_io_pipe (int filedes[2], int inherit_idx)
 {
   GIOChannel *chan;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_pipe", filedes,
+	      "inherit_idx=%i (GPGME uses it for %s)",
+	      inherit_idx, inherit_idx ? "writing" : "reading");
 
 #define PIPEBUF_SIZE  4096
   if (_pipe (filedes, PIPEBUF_SIZE, O_NOINHERIT | O_BINARY) == -1)
-    return -1;
+    return TRACE_SYSRES (-1);
 
   /* Make one end inheritable. */
   if (inherit_idx == 0)
@@ -229,7 +230,7 @@ _gpgme_io_pipe (int filedes[2], int inherit_idx)
       if (new_read < 0)
 	{
 	  _close (filedes[1]);
-	  return -1;
+	  return TRACE_SYSRES (-1);
 	}
     }
   else if (inherit_idx == 1)
@@ -243,7 +244,7 @@ _gpgme_io_pipe (int filedes[2], int inherit_idx)
       if (new_write < 0)
 	{
 	  _close (filedes[0]);
-	  return -1;
+	  return TRACE_SYSRES (-1);
 	}
     }
 
@@ -252,18 +253,17 @@ _gpgme_io_pipe (int filedes[2], int inherit_idx)
   chan = find_channel (filedes[1 - inherit_idx], 1);
   if (!chan)
     {
-      DEBUG2 ("channel creation for %d failed: ec=%d\n",
-	      filedes[1 - inherit_idx], errno);
+      int saved_errno = errno;
       _close (filedes[0]);
       _close (filedes[1]);
-      return -1;
+      errno = saved_errno;
+      return TRACE_SYSRES (-1);
     }
 
-  DEBUG5 ("CreatePipe %d (%p) %d (%p) inherit=%p\n",
+  return TRACE_SUC5 ("read=0x%x/%p, write=0x%x/%p, channel=%p",
 	  filedes[0], (HANDLE) _get_osfhandle (filedes[0]),
 	  filedes[1], (HANDLE) _get_osfhandle (filedes[1]),
 	  chan);
-  return 0;
 }
 
 
@@ -271,15 +271,15 @@ int
 _gpgme_io_close (int fd)
 {
   GIOChannel *chan;
+  TRACE_BEG (DEBUG_SYSIO, "_gpgme_io_close", fd);
 
   if (fd < 0 || fd >= MAX_SLAFD)
     {
       errno = EBADF;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
 
   /* First call the notify handler.  */
-  DEBUG1 ("closing fd %d", fd);
   if (notify_table[fd].handler)
     {
       notify_table[fd].handler (fd, notify_table[fd].value);
@@ -306,14 +306,19 @@ int
 _gpgme_io_set_close_notify (int fd, _gpgme_close_notify_handler_t handler,
 			    void *value)
 {
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_set_close_notify", fd,
+	      "close_handler=%p/%p", handler, value);
+
   assert (fd != -1);
 
   if (fd < 0 || fd >= (int) DIM (notify_table))
-    return -1;
-  DEBUG1 ("set notification for fd %d", fd);
+    {
+      errno = EINVAL;
+      return TRACE_SYSRES (-1);
+    }
   notify_table[fd].handler = handler;
   notify_table[fd].value = value;
-  return 0;
+  return TRACE_SYSRES (0);
 }
 
 
@@ -323,12 +328,13 @@ _gpgme_io_set_nonblocking (int fd)
   GIOChannel *chan;
   GIOStatus status;
  
+  TRACE_BEG (DEBUG_SYSIO, "_gpgme_io_set_nonblocking", fd);
+
   chan = find_channel (fd, 0);
   if (!chan)
     {
-      DEBUG1 ("set nonblocking for fd %d failed: channel not found", fd);
       errno = EIO;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
 
    status = g_io_channel_set_flags (chan,
@@ -336,14 +342,18 @@ _gpgme_io_set_nonblocking (int fd)
 				   G_IO_FLAG_NONBLOCK, NULL);
   if (status != G_IO_STATUS_NORMAL)
     {
-      /* glib 1.9.2 does not implement set_flags and returns an error. */
-      DEBUG2 ("set nonblocking for fd %d failed: status=%d - ignored",
-              fd, status);
-/*       errno = EIO; */
-/*       return -1; */
+#if 0
+      /* glib 1.9.2 does not implement set_flags and returns an
+	 error.  */
+      errno = EIO;
+      return TRACE_SYSRES (-1);
+#else
+      TRACE_LOG1 ("g_io_channel_set_flags failed: status=%d (ignored)",
+		  status);
+#endif
     }
 
-  return 0;
+  return TRACE_SYSRES (0);
 }
 
 
@@ -351,7 +361,6 @@ static char *
 build_commandline (char **argv)
 {
   int i;
-  int j;
   int n = 0;
   char *buf;
   char *p;
@@ -404,158 +413,181 @@ build_commandline (char **argv)
 
 
 int
-_gpgme_io_spawn ( const char *path, char **argv,
-                  struct spawn_fd_item_s *fd_child_list,
-                  struct spawn_fd_item_s *fd_parent_list )
+_gpgme_io_spawn (const char *path, char **argv,
+		 struct spawn_fd_item_s *fd_child_list,
+		 struct spawn_fd_item_s *fd_parent_list)
 {
-    SECURITY_ATTRIBUTES sec_attr;
-    PROCESS_INFORMATION pi = {
-        NULL,      /* returns process handle */
-        0,         /* returns primary thread handle */
-        0,         /* returns pid */
-        0         /* returns tid */
+  SECURITY_ATTRIBUTES sec_attr;
+  PROCESS_INFORMATION pi =
+    {
+      NULL,      /* returns process handle */
+      0,         /* returns primary thread handle */
+      0,         /* returns pid */
+      0         /* returns tid */
     };
-    STARTUPINFO si;
-    char *envblock = NULL;
-    int cr_flags = CREATE_DEFAULT_ERROR_MODE
-                 | GetPriorityClass (GetCurrentProcess ());
-    int i;
-    char *arg_string;
-    int duped_stdin = 0;
-    int duped_stderr = 0;
-    HANDLE hnul = INVALID_HANDLE_VALUE;
-    /* FIXME.  */
-    int debug_me = 0;
-
-    memset (&sec_attr, 0, sizeof sec_attr);
-    sec_attr.nLength = sizeof sec_attr;
-    sec_attr.bInheritHandle = FALSE;
-
-    arg_string = build_commandline (argv);
-    if (!arg_string )
-        return -1; 
-
-    memset (&si, 0, sizeof si);
-    si.cb = sizeof (si);
-    si.dwFlags = STARTF_USESTDHANDLES | STARTF_USESHOWWINDOW;
-    si.wShowWindow = debug_me? SW_SHOW : SW_HIDE;
-    si.hStdInput = GetStdHandle (STD_INPUT_HANDLE);
-    si.hStdOutput = GetStdHandle (STD_OUTPUT_HANDLE);
-    si.hStdError = GetStdHandle (STD_ERROR_HANDLE);
-
-    for (i=0; fd_child_list[i].fd != -1; i++ ) {
-        if (fd_child_list[i].dup_to == 0 ) {
-            si.hStdInput = (HANDLE) _get_osfhandle (fd_child_list[i].fd);
-            DEBUG2 ("using %d (%p) for stdin", fd_child_list[i].fd,
-		    _get_osfhandle (fd_child_list[i].fd));
-            duped_stdin=1;
-        }
-        else if (fd_child_list[i].dup_to == 1 ) {
-            si.hStdOutput = (HANDLE) _get_osfhandle (fd_child_list[i].fd);
-            DEBUG2 ("using %d (%p) for stdout", fd_child_list[i].fd,
-		    _get_osfhandle (fd_child_list[i].fd));
-        }
-        else if (fd_child_list[i].dup_to == 2 ) {
-            si.hStdError = (HANDLE) _get_osfhandle (fd_child_list[i].fd);
-            DEBUG2 ("using %d (%p) for stderr", fd_child_list[i].fd,
-		    _get_osfhandle (fd_child_list[i].fd));
-            duped_stderr = 1;
-        }
+  STARTUPINFO si;
+  char *envblock = NULL;
+  int cr_flags = CREATE_DEFAULT_ERROR_MODE
+    | GetPriorityClass (GetCurrentProcess ());
+  int i;
+  char *arg_string;
+  int duped_stdin = 0;
+  int duped_stderr = 0;
+  HANDLE hnul = INVALID_HANDLE_VALUE;
+  /* FIXME.  */
+  int debug_me = 0;
+  TRACE_BEG1 (DEBUG_SYSIO, "_gpgme_io_spawn", path,
+	      "path=%s", path);
+  i = 0;
+  while (argv[i])
+    {
+      TRACE_LOG2 ("argv[%2i] = %s", i, argv[i]);
+      i++;
     }
-
-    if( !duped_stdin || !duped_stderr ) {
-        SECURITY_ATTRIBUTES sa;
-
-        memset (&sa, 0, sizeof sa );
-        sa.nLength = sizeof sa;
-        sa.bInheritHandle = TRUE;
-        hnul = CreateFile ( "nul",
-                            GENERIC_READ|GENERIC_WRITE,
-                            FILE_SHARE_READ|FILE_SHARE_WRITE,
-                            &sa,
-                            OPEN_EXISTING,
-                            FILE_ATTRIBUTE_NORMAL,
-                            NULL );
-        if ( hnul == INVALID_HANDLE_VALUE ) {
-            DEBUG1 ("can't open `nul': ec=%d\n", (int)GetLastError ());
-            free (arg_string);
-            return -1;
-        }
-        /* Make sure that the process has a connected stdin */
-        if ( !duped_stdin ) {
-            si.hStdInput = hnul;
-            DEBUG1 ("using %d for dummy stdin", (int)hnul );
+  
+  memset (&sec_attr, 0, sizeof sec_attr);
+  sec_attr.nLength = sizeof sec_attr;
+  sec_attr.bInheritHandle = FALSE;
+  
+  arg_string = build_commandline (argv);
+  if (!arg_string)
+    return TRACE_SYSRES (-1);
+  
+  memset (&si, 0, sizeof si);
+  si.cb = sizeof (si);
+  si.dwFlags = STARTF_USESTDHANDLES | STARTF_USESHOWWINDOW;
+  si.wShowWindow = debug_me? SW_SHOW : SW_HIDE;
+  si.hStdInput = GetStdHandle (STD_INPUT_HANDLE);
+  si.hStdOutput = GetStdHandle (STD_OUTPUT_HANDLE);
+  si.hStdError = GetStdHandle (STD_ERROR_HANDLE);
+  
+  for (i = 0; fd_child_list[i].fd != -1; i++)
+    {
+      if (fd_child_list[i].dup_to == 0)
+	{
+	  si.hStdInput = (HANDLE) _get_osfhandle (fd_child_list[i].fd);
+	  TRACE_LOG2 ("using 0x%x/%p for stdin", fd_child_list[i].fd,
+		      _get_osfhandle (fd_child_list[i].fd));
+	  duped_stdin = 1;
         }
-        /* We normally don't want all the normal output */
-        if ( !duped_stderr ) {
-            si.hStdError = hnul;
-            DEBUG1 ("using %d for dummy stderr", (int)hnul );
+      else if (fd_child_list[i].dup_to == 1)
+	{
+	  si.hStdOutput = (HANDLE) _get_osfhandle (fd_child_list[i].fd);
+	  TRACE_LOG2 ("using 0x%x/%p for stdout", fd_child_list[i].fd,
+		      _get_osfhandle (fd_child_list[i].fd));
+	}
+      else if (fd_child_list[i].dup_to == 2)
+	{
+	  si.hStdError = (HANDLE) _get_osfhandle (fd_child_list[i].fd);
+	  TRACE_LOG2 ("using 0x%x/%p for stderr", fd_child_list[i].fd,
+		      _get_osfhandle (fd_child_list[i].fd));
+	  duped_stderr = 1;
         }
     }
-
-    DEBUG2 ("CreateProcess, path=`%s' args=`%s'", path, arg_string);
-    cr_flags |= CREATE_SUSPENDED; 
-    if ( !CreateProcessA (path,
-                          arg_string,
-                          &sec_attr,     /* process security attributes */
-                          &sec_attr,     /* thread security attributes */
-                          TRUE,          /* inherit handles */
-                          cr_flags,      /* creation flags */
-                          envblock,      /* environment */
-                          NULL,          /* use current drive/directory */
-                          &si,           /* startup information */
-                          &pi            /* returns process information */
-        ) ) {
-        DEBUG1 ("CreateProcess failed: ec=%d\n", (int) GetLastError ());
-        free (arg_string);
-        return -1;
-    }
-
-    /* Close the /dev/nul handle if used. */
-    if (hnul != INVALID_HANDLE_VALUE ) {
-        if ( !CloseHandle ( hnul ) )
-            DEBUG1 ("CloseHandle(hnul) failed: ec=%d\n", (int)GetLastError());
+  
+  if (!duped_stdin || !duped_stderr)
+    {
+      SECURITY_ATTRIBUTES sa;
+      
+      memset (&sa, 0, sizeof sa);
+      sa.nLength = sizeof sa;
+      sa.bInheritHandle = TRUE;
+      hnul = CreateFile ("nul",
+			 GENERIC_READ|GENERIC_WRITE,
+			 FILE_SHARE_READ|FILE_SHARE_WRITE,
+			 &sa,
+			 OPEN_EXISTING,
+			 FILE_ATTRIBUTE_NORMAL,
+			 NULL);
+      if (hnul == INVALID_HANDLE_VALUE)
+	{
+	  TRACE_LOG1 ("CreateFile (\"nul\") failed: ec=%d",
+		      (int) GetLastError ());
+	  free (arg_string);
+	  /* FIXME: Should translate the error code.  */
+	  errno = EIO;
+	  return TRACE_SYSRES (-1);
+        }
+      /* Make sure that the process has a connected stdin.  */
+      if (!duped_stdin)
+	{
+	  si.hStdInput = hnul;
+	  TRACE_LOG1 ("using 0x%x for dummy stdin", (int) hnul);
+	}
+      /* We normally don't want all the normal output.  */
+      if (!duped_stderr)
+	{
+	  si.hStdError = hnul;
+	  TRACE_LOG1 ("using %d for dummy stderr", (int)hnul);
+	}
     }
-
-    /* Close the other ends of the pipes. */
-    for (i = 0; fd_parent_list[i].fd != -1; i++)
-      _gpgme_io_close (fd_parent_list[i].fd);
-
-    DEBUG4 ("CreateProcess ready\n"
-            "-   hProcess=%p  hThread=%p\n"
-            "-   dwProcessID=%d dwThreadId=%d\n",
-            pi.hProcess, pi.hThread, 
-            (int) pi.dwProcessId, (int) pi.dwThreadId);
-
-    if ( ResumeThread ( pi.hThread ) < 0 ) {
-        DEBUG1 ("ResumeThread failed: ec=%d\n", (int)GetLastError ());
+  
+  cr_flags |= CREATE_SUSPENDED; 
+  if (!CreateProcessA (path,
+		       arg_string,
+		       &sec_attr,     /* process security attributes */
+		       &sec_attr,     /* thread security attributes */
+		       TRUE,          /* inherit handles */
+		       cr_flags,      /* creation flags */
+		       envblock,      /* environment */
+		       NULL,          /* use current drive/directory */
+		       &si,           /* startup information */
+		       &pi))          /* returns process information */
+    {
+      TRACE_LOG1 ("CreateProcess failed: ec=%d", (int) GetLastError ());
+      free (arg_string);
+      /* FIXME: Should translate the error code.  */
+      errno = EIO;
+      return TRACE_SYSRES (-1);
     }
-
-    if ( !CloseHandle (pi.hThread) ) { 
-        DEBUG1 ("CloseHandle of thread failed: ec=%d\n",
-                 (int)GetLastError ());
+  
+  /* Close the /dev/nul handle if used.  */
+  if (hnul != INVALID_HANDLE_VALUE)
+    {
+      if (!CloseHandle (hnul))
+	TRACE_LOG1 ("CloseHandle (hnul) failed: ec=%d (ignored)",
+		    (int) GetLastError ());
     }
+  
+  /* Close the other ends of the pipes.  */
+  for (i = 0; fd_parent_list[i].fd != -1; i++)
+    _gpgme_io_close (fd_parent_list[i].fd);
+  
+  TRACE_LOG4 ("CreateProcess ready: hProcess=%p, hThread=%p, "
+	      "dwProcessID=%d, dwThreadId=%d",
+	      pi.hProcess, pi.hThread, 
+	      (int) pi.dwProcessId, (int) pi.dwThreadId);
+  
+  if (ResumeThread (pi.hThread) < 0)
+    TRACE_LOG1 ("ResumeThread failed: ec=%d", (int) GetLastError ());
+  
+  if (!CloseHandle (pi.hThread))
+    TRACE_LOG1 ("CloseHandle of thread failed: ec=%d",
+		(int) GetLastError ());
 
-    return 0;
+  TRACE_SUC1 ("process=%p", pi.hProcess);
+  return 0;
 }
 
 
-/*
- * Select on the list of fds.
- * Returns: -1 = error
- *           0 = timeout or nothing to select
- *          >0 = number of signaled fds
- */
+/* Select on the list of fds.  Returns: -1 = error, 0 = timeout or
+   nothing to select, > 0 = number of signaled fds.  */
 int
 _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
 {
-  int     npollfds;
+  int npollfds;
   GPollFD *pollfds;
-  int     *pollfds_map; 
-  int i, j;
-  int any, n, count;
-  int timeout = 1000;  /* Use a 1s timeout.  */
+  int *pollfds_map; 
+  int i;
+  int j;
+  int any;
+  int n;
+  int count;
+  /* Use a 1s timeout.  */
+  int timeout = 1000;
   void *dbg_help = NULL;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_select", fds,
+	      "nfds=%u, nonblock=%u", nfds, nonblock);
 
   if (nonblock)
     timeout = 0;
@@ -571,21 +603,21 @@ _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
     }
   npollfds = 0;
 
-  DEBUG_BEGIN (dbg_help, 3, "gpgme:select on [ ");
+  TRACE_SEQ (dbg_help, "select on [ ");
   any = 0;
   for (i = 0; i < nfds; i++)
     {
       if (fds[i].fd == -1) 
 	continue;
       if (fds[i].frozen)
-	DEBUG_ADD1 (dbg_help, "f%d ", fds[i].fd);
+	TRACE_ADD1 (dbg_help, "f0x%x ", fds[i].fd);
       else if (fds[i].for_read )
 	{
           GIOChannel *chan = find_channel (fds[i].fd, 0);
           assert (chan);
           g_io_channel_win32_make_pollfd (chan, G_IO_IN, pollfds + npollfds);
           pollfds_map[npollfds] = i;
-	  DEBUG_ADD2 (dbg_help, "r%d<%d> ", fds[i].fd, pollfds[npollfds].fd);
+	  TRACE_ADD2 (dbg_help, "r0x%x<%d> ", fds[i].fd, pollfds[npollfds].fd);
           npollfds++;
 	  any = 1;
         }
@@ -595,13 +627,13 @@ _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
           assert (chan);
           g_io_channel_win32_make_pollfd (chan, G_IO_OUT, pollfds + npollfds);
           pollfds_map[npollfds] = i;
-	  DEBUG_ADD2 (dbg_help, "w%d<%d> ", fds[i].fd, pollfds[npollfds].fd);
+	  TRACE_ADD2 (dbg_help, "w0x%x<%d> ", fds[i].fd, pollfds[npollfds].fd);
           npollfds++;
 	  any = 1;
         }
       fds[i].signaled = 0;
     }
-  DEBUG_END (dbg_help, "]"); 
+  TRACE_END (dbg_help, "]"); 
   if (!any)
     {
       count = 0;
@@ -613,22 +645,21 @@ _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
   if (count < 0)
     {
       int saved_errno = errno;
-      DEBUG1 ("_gpgme_io_select failed: %s\n", strerror (errno));
       errno = saved_errno;
       goto leave;
     }
 
-  DEBUG_BEGIN (dbg_help, 3, "select OK [ ");
-  if (DEBUG_ENABLED (dbg_help))
+  TRACE_SEQ (dbg_help, "select OK [ ");
+  if (TRACE_ENABLED (dbg_help))
     {
       for (i = 0; i < npollfds; i++)
 	{
 	  if ((pollfds[i].revents & G_IO_IN))
-	    DEBUG_ADD1 (dbg_help, "r%d ", fds[pollfds_map[i]].fd);
+	    TRACE_ADD1 (dbg_help, "r0x%x ", fds[pollfds_map[i]].fd);
           if ((pollfds[i].revents & G_IO_OUT))
-            DEBUG_ADD1 (dbg_help, "w%d ", fds[pollfds_map[i]].fd);
+            TRACE_ADD1 (dbg_help, "w0x%x ", fds[pollfds_map[i]].fd);
         }
-      DEBUG_END (dbg_help, "]");
+      TRACE_END (dbg_help, "]");
     }
     
   /* COUNT is used to stop the lop as soon as possible.  */
@@ -659,7 +690,7 @@ _gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
 leave:
   free (pollfds);
   free (pollfds_map);
-  return count;
+  return TRACE_SYSRES (count);
 }
 
 
diff --git a/gpgme/w32-io.c b/gpgme/w32-io.c
index 9ae22f54..4a76d75b 100644
--- a/gpgme/w32-io.c
+++ b/gpgme/w32-io.c
@@ -1,6 +1,6 @@
 /* w32-io.c - W32 API I/O functions.
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2007 g10 Code GmbH
 
    This file is part of GPGME.
  
@@ -65,65 +65,71 @@ static struct
 DEFINE_STATIC_LOCK (notify_table_lock);
 
 
-struct reader_context_s {
-    HANDLE file_hd;
-    HANDLE thread_hd;	
-    int refcount;
-
-    DECLARE_LOCK (mutex);
+struct reader_context_s
+{
+  HANDLE file_hd;
+  HANDLE thread_hd;	
+  int refcount;
 
-    int stop_me;
-    int eof;
-    int eof_shortcut;
-    int error;
-    int error_code;
+  DECLARE_LOCK (mutex);
 
-    HANDLE have_data_ev;  /* manually reset */
-    HANDLE have_space_ev; /* auto reset */
-    HANDLE stopped;
-    size_t readpos, writepos;
-    char buffer[READBUF_SIZE];
+  int stop_me;
+  int eof;
+  int eof_shortcut;
+  int error;
+  int error_code;
+  
+  /* This is manually reset.  */
+  HANDLE have_data_ev;
+  /* This is automatically reset.  */
+  HANDLE have_space_ev;
+  HANDLE stopped;
+  size_t readpos, writepos;
+  char buffer[READBUF_SIZE];
 };
 
 
-static struct {
-    volatile int used;
-    int fd;
-    struct reader_context_s *context;
+static struct
+{
+  volatile int used;
+  int fd;
+  struct reader_context_s *context;
 } reader_table[MAX_READERS];
 static int reader_table_size= MAX_READERS;
 DEFINE_STATIC_LOCK (reader_table_lock);
 
 
-struct writer_context_s {
-    HANDLE file_hd;
-    HANDLE thread_hd;	
-    int refcount;
-
-    DECLARE_LOCK (mutex);
-
-    int stop_me;
-    int error;
-    int error_code;
+struct writer_context_s
+{
+  HANDLE file_hd;
+  HANDLE thread_hd;	
+  int refcount;
 
-    HANDLE have_data;  /* manually reset */
-    HANDLE is_empty;
-    HANDLE stopped;
-    size_t nbytes; 
-    char buffer[WRITEBUF_SIZE];
+  DECLARE_LOCK (mutex);
+  
+  int stop_me;
+  int error;
+  int error_code;
+
+  /* This is manually reset.  */
+  HANDLE have_data;
+  HANDLE is_empty;
+  HANDLE stopped;
+  size_t nbytes; 
+  char buffer[WRITEBUF_SIZE];
 };
 
 
-static struct {
-    volatile int used;
-    int fd;
-    struct writer_context_s *context;
+static struct
+{
+  volatile int used;
+  int fd;
+  struct writer_context_s *context;
 } writer_table[MAX_WRITERS];
 static int writer_table_size= MAX_WRITERS;
 DEFINE_STATIC_LOCK (writer_table_lock);
 
 
-
 static int
 get_desired_thread_priority (void)
 {
@@ -132,197 +138,225 @@ get_desired_thread_priority (void)
   if (!_gpgme_get_conf_int ("IOThreadPriority", &value))
     {
       value = THREAD_PRIORITY_HIGHEST;
-      DEBUG1 ("** Using standard IOThreadPriority of %d\n", value);
+      TRACE1 (DEBUG_SYSIO, "gpgme:get_desired_thread_priority", 0,
+	      "%d (default)", value);
     }
   else
-    DEBUG1 ("** Configured IOThreadPriority is %d\n", value);
-
+    {
+      TRACE1 (DEBUG_SYSIO, "gpgme:get_desired_thread_priority", 0,
+	      "%d (configured)", value);
+    }
   return value;
 }
 
 
 static HANDLE
-set_synchronize (HANDLE h)
+set_synchronize (HANDLE hd)
 {
-    HANDLE tmp;
-    
-    /* For NT we have to set the sync flag.  It seems that the only
-     * way to do it is by duplicating the handle.  Tsss.. */
-    if (!DuplicateHandle( GetCurrentProcess(), h,
-                          GetCurrentProcess(), &tmp,
-                          EVENT_MODIFY_STATE|SYNCHRONIZE, FALSE, 0 ) ) {
-        DEBUG1 ("** Set SYNCRONIZE failed: ec=%d\n", (int)GetLastError());
-    }
-    else {
-        CloseHandle (h);
-        h = tmp;
+  HANDLE new_hd;
+
+  /* For NT we have to set the sync flag.  It seems that the only way
+     to do it is by duplicating the handle.  Tsss...  */
+  if (!DuplicateHandle (GetCurrentProcess (), hd,
+			GetCurrentProcess (), &new_hd,
+			EVENT_MODIFY_STATE | SYNCHRONIZE, FALSE, 0))
+    {
+      TRACE1 (DEBUG_SYSIO, "gpgme:set_synchronize", hd,
+	      "DuplicateHandle failed: ec=%d", (int) GetLastError ());
+      /* FIXME: Should translate the error code.  */
+      errno = EIO;
+      return INVALID_HANDLE_VALUE;
     }
-    return h;
-}
 
+  CloseHandle (hd);
+  return new_hd;
+}
 
 
 static DWORD CALLBACK 
 reader (void *arg)
 {
-    struct reader_context_s *c = arg;
-    int nbytes;
-    DWORD nread;
-
-    DEBUG2 ("reader thread %p for file %p started", c->thread_hd, c->file_hd );
-    for (;;) {
-        LOCK (c->mutex);
-        /* leave a 1 byte gap so that we can see whether it is empty or full*/
-        if ((c->writepos + 1) % READBUF_SIZE == c->readpos) { 
-            /* wait for space */
-            if (!ResetEvent (c->have_space_ev) )
-                DEBUG1 ("ResetEvent failed: ec=%d", (int)GetLastError ());
-            UNLOCK (c->mutex);
-            DEBUG1 ("reader thread %p: waiting for space ...", c->thread_hd );
-            WaitForSingleObject (c->have_space_ev, INFINITE);
-            DEBUG1 ("reader thread %p: got space", c->thread_hd );
-            LOCK (c->mutex);
+  struct reader_context_s *ctx = arg;
+  int nbytes;
+  DWORD nread;
+  TRACE_BEG1 (DEBUG_SYSIO, "gpgme:reader", ctx->file_hd,
+	      "thread=%p", ctx->thread_hd);
+
+  for (;;)
+    {
+      LOCK (ctx->mutex);
+      /* Leave a 1 byte gap so that we can see whether it is empty or
+	 full.  */
+      if ((ctx->writepos + 1) % READBUF_SIZE == ctx->readpos)
+	{ 
+	  /* Wait for space.  */
+	  if (!ResetEvent (ctx->have_space_ev))
+	    TRACE_LOG1 ("ResetEvent failed: ec=%d", (int) GetLastError ());
+	  UNLOCK (ctx->mutex);
+	  TRACE_LOG ("waiting for space");
+	  WaitForSingleObject (ctx->have_space_ev, INFINITE);
+	  TRACE_LOG ("got space");
+	  LOCK (ctx->mutex);
        	}
-        if ( c->stop_me ) {
-            UNLOCK (c->mutex);
-            break;
+      if (ctx->stop_me)
+	{
+	  UNLOCK (ctx->mutex);
+	  break;
         }
-        nbytes = (c->readpos + READBUF_SIZE - c->writepos-1) % READBUF_SIZE;
-        if ( nbytes > READBUF_SIZE - c->writepos )
-            nbytes = READBUF_SIZE - c->writepos;
-        UNLOCK (c->mutex);
-
-        DEBUG2 ("reader thread %p: reading %d bytes", c->thread_hd, nbytes );
-        if ( !ReadFile ( c->file_hd,
-                         c->buffer+c->writepos, nbytes, &nread, NULL) ) {
-            c->error_code = (int)GetLastError ();
-            if (c->error_code == ERROR_BROKEN_PIPE ) {
-                c->eof=1;
-                DEBUG1 ("reader thread %p: got eof (broken pipe)",
-                        c->thread_hd );
+      nbytes = (ctx->readpos + READBUF_SIZE
+		- ctx->writepos - 1) % READBUF_SIZE;
+      if (nbytes > READBUF_SIZE - ctx->writepos)
+	nbytes = READBUF_SIZE - ctx->writepos;
+      UNLOCK (ctx->mutex);
+      
+      TRACE_LOG1 ("reading %d bytes", nbytes);
+      if (!ReadFile (ctx->file_hd,
+		     ctx->buffer + ctx->writepos, nbytes, &nread, NULL))
+	{
+	  ctx->error_code = (int) GetLastError ();
+	  if (ctx->error_code == ERROR_BROKEN_PIPE)
+	    {
+	      ctx->eof = 1;
+	      TRACE_LOG ("got EOF (broken pipe)");
             }
-            else {
-                c->error = 1;
-                DEBUG2 ("reader thread %p: read error: ec=%d",
-                        c->thread_hd, c->error_code );
+	  else
+	    {
+	      ctx->error = 1;
+	      TRACE_LOG1 ("read error: ec=%d", ctx->error_code);
             }
-            break;
+	  break;
         }
-        if ( !nread ) {
-            c->eof = 1;
-            DEBUG1 ("reader thread %p: got eof", c->thread_hd );
-            break;
+      if (!nread)
+	{
+	  ctx->eof = 1;
+	  TRACE_LOG ("got eof");
+	  break;
         }
-        DEBUG2 ("reader thread %p: got %d bytes", c->thread_hd, (int)nread );
+      TRACE_LOG1 ("got %u bytes", nread);
       
-        LOCK (c->mutex);
-        if (c->stop_me) {
-            UNLOCK (c->mutex);
-            break;
+      LOCK (ctx->mutex);
+      if (ctx->stop_me)
+	{
+	  UNLOCK (ctx->mutex);
+	  break;
         }
-        c->writepos = (c->writepos + nread) % READBUF_SIZE;
-        if ( !SetEvent (c->have_data_ev) )
-            DEBUG1 ("SetEvent failed: ec=%d", (int)GetLastError ());
-        UNLOCK (c->mutex);
+      ctx->writepos = (ctx->writepos + nread) % READBUF_SIZE;
+      if (!SetEvent (ctx->have_data_ev))
+	TRACE_LOG1 ("SetEvent failed: ec=%d", (int) GetLastError ());
+      UNLOCK (ctx->mutex);
     }
-    /* indicate that we have an error or eof */
-    if ( !SetEvent (c->have_data_ev) )
-        DEBUG1 ("SetEvent failed: ec=%d", (int)GetLastError ());
-    DEBUG1 ("reader thread %p ended", c->thread_hd );
-    SetEvent (c->stopped);
-
-    return 0;
+  /* Indicate that we have an error or EOF.  */
+  if (!SetEvent (ctx->have_data_ev))
+    TRACE_LOG1 ("SetEvent failed: ec=%d", (int) GetLastError ());
+  SetEvent (ctx->stopped);
+  
+  return TRACE_SUC ();
 }
 
 
 static struct reader_context_s *
 create_reader (HANDLE fd)
 {
-    struct reader_context_s *c;
-    SECURITY_ATTRIBUTES sec_attr;
-    DWORD tid;
-
-    DEBUG1 ("creating new read thread for file handle %p", fd );
-    memset (&sec_attr, 0, sizeof sec_attr );
-    sec_attr.nLength = sizeof sec_attr;
-    sec_attr.bInheritHandle = FALSE;
-
-    c = calloc (1, sizeof *c );
-    if (!c)
-        return NULL;
-
-    c->file_hd = fd;
-    c->refcount = 1;
-    c->have_data_ev = CreateEvent (&sec_attr, TRUE, FALSE, NULL);
-    c->have_space_ev = CreateEvent (&sec_attr, FALSE, TRUE, NULL);
-    c->stopped = CreateEvent (&sec_attr, TRUE, FALSE, NULL);
-    if (!c->have_data_ev || !c->have_space_ev || !c->stopped ) {
-        DEBUG1 ("** CreateEvent failed: ec=%d\n", (int)GetLastError ());
-        if (c->have_data_ev)
-            CloseHandle (c->have_data_ev);
-        if (c->have_space_ev)
-            CloseHandle (c->have_space_ev);
-        if (c->stopped)
-            CloseHandle (c->stopped);
-        free (c);
-        return NULL;
+  struct reader_context_s *ctx;
+  SECURITY_ATTRIBUTES sec_attr;
+  DWORD tid;
+
+  TRACE_BEG (DEBUG_SYSIO, "gpgme:create_reader", fd);
+
+  memset (&sec_attr, 0, sizeof sec_attr);
+  sec_attr.nLength = sizeof sec_attr;
+  sec_attr.bInheritHandle = FALSE;
+  
+  ctx = calloc (1, sizeof *ctx);
+  if (!ctx)
+    {
+      TRACE_SYSERR (errno);
+      return NULL;
     }
 
-    c->have_data_ev = set_synchronize (c->have_data_ev);
-    INIT_LOCK (c->mutex);
-
-    c->thread_hd = CreateThread (&sec_attr, 0, reader, c, 0, &tid );
-    if (!c->thread_hd) {
-        DEBUG1 ("** failed to create reader thread: ec=%d\n",
-                 (int)GetLastError ());
-        DESTROY_LOCK (c->mutex);
-        if (c->have_data_ev)
-            CloseHandle (c->have_data_ev);
-        if (c->have_space_ev)
-            CloseHandle (c->have_space_ev);
-        if (c->stopped)
-            CloseHandle (c->stopped);
-        free (c);
-        return NULL;
+  ctx->file_hd = fd;
+  ctx->refcount = 1;
+  ctx->have_data_ev = CreateEvent (&sec_attr, TRUE, FALSE, NULL);
+  if (ctx->have_data_ev)
+    ctx->have_space_ev = CreateEvent (&sec_attr, FALSE, TRUE, NULL);
+  if (ctx->have_space_ev)
+    ctx->stopped = CreateEvent (&sec_attr, TRUE, FALSE, NULL);
+  if (!ctx->have_data_ev || !ctx->have_space_ev || !ctx->stopped)
+    {
+      TRACE_LOG1 ("CreateEvent failed: ec=%d", (int) GetLastError ());
+      if (ctx->have_data_ev)
+	CloseHandle (ctx->have_data_ev);
+      if (ctx->have_space_ev)
+	CloseHandle (ctx->have_space_ev);
+      if (ctx->stopped)
+	CloseHandle (ctx->stopped);
+      free (ctx);
+      /* FIXME: Translate the error code.  */
+      TRACE_SYSERR (EIO);
+      return NULL;
+    }
+
+  ctx->have_data_ev = set_synchronize (ctx->have_data_ev);
+  INIT_LOCK (ctx->mutex);
+
+  ctx->thread_hd = CreateThread (&sec_attr, 0, reader, ctx, 0, &tid);
+  if (!ctx->thread_hd)
+    {
+      TRACE_LOG1 ("CreateThread failed: ec=%d", (int) GetLastError ());
+      DESTROY_LOCK (ctx->mutex);
+      if (ctx->have_data_ev)
+	CloseHandle (ctx->have_data_ev);
+      if (ctx->have_space_ev)
+	CloseHandle (ctx->have_space_ev);
+      if (ctx->stopped)
+	CloseHandle (ctx->stopped);
+      free (ctx);
+      TRACE_SYSERR (EIO);
+      return NULL;
     }    
-    else {
+  else
+    {
       /* We set the priority of the thread higher because we know that
-         it only runs for a short time.  This greatly helps to increase
-         the performance of the I/O. */
-      SetThreadPriority (c->thread_hd, get_desired_thread_priority ());
+         it only runs for a short time.  This greatly helps to
+         increase the performance of the I/O.  */
+      SetThreadPriority (ctx->thread_hd, get_desired_thread_priority ());
     }
 
-    return c;
+  TRACE_SUC ();
+  return ctx;
 }
 
+
 static void
-destroy_reader (struct reader_context_s *c)
+destroy_reader (struct reader_context_s *ctx)
 {
-    LOCK (c->mutex);
-    c->refcount--;
-    if (c->refcount != 0)
-      {
-	UNLOCK (c->mutex);
-	return;
-      }
-    c->stop_me = 1;
-    if (c->have_space_ev) 
-        SetEvent (c->have_space_ev);
-    UNLOCK (c->mutex);
-
-    DEBUG1 ("waiting for thread %p termination ...", c->thread_hd );
-    WaitForSingleObject (c->stopped, INFINITE);
-    DEBUG1 ("thread %p has terminated", c->thread_hd );
+  LOCK (ctx->mutex);
+  ctx->refcount--;
+  if (ctx->refcount != 0)
+    {
+      UNLOCK (ctx->mutex);
+      return;
+    }
+  ctx->stop_me = 1;
+  if (ctx->have_space_ev) 
+    SetEvent (ctx->have_space_ev);
+  UNLOCK (ctx->mutex);
+
+  TRACE1 (DEBUG_SYSIO, "gpgme:destroy_reader", ctx->file_hd,
+	  "waiting for termination of thread %p", ctx->thread_hd);
+  WaitForSingleObject (ctx->stopped, INFINITE);
+  TRACE1 (DEBUG_SYSIO, "gpgme:destroy_reader", ctx->file_hd,
+	  "thread %p has terminated", ctx->thread_hd);
     
-    if (c->stopped)
-        CloseHandle (c->stopped);
-    if (c->have_data_ev)
-        CloseHandle (c->have_data_ev);
-    if (c->have_space_ev)
-        CloseHandle (c->have_space_ev);
-    CloseHandle (c->thread_hd);
-    DESTROY_LOCK (c->mutex);
-    free (c);
+  if (ctx->stopped)
+    CloseHandle (ctx->stopped);
+  if (ctx->have_data_ev)
+    CloseHandle (ctx->have_data_ev);
+  if (ctx->have_space_ev)
+    CloseHandle (ctx->have_space_ev);
+  CloseHandle (ctx->thread_hd);
+  DESTROY_LOCK (ctx->mutex);
+  free (ctx);
 }
 
 
@@ -383,224 +417,251 @@ kill_reader (int fd)
 
 
 int
-_gpgme_io_read ( int fd, void *buffer, size_t count )
+_gpgme_io_read (int fd, void *buffer, size_t count)
 {
-    int nread;
-    struct reader_context_s *c = find_reader (fd,1);
-
-    DEBUG2 ("fd %d: about to read %d bytes\n", fd, (int)count );
-    if ( !c ) {
-        DEBUG0 ( "no reader thread\n");
-	errno = EBADF;
-        return -1;
-    }
-    if (c->eof_shortcut) {
-        DEBUG1 ("fd %d: EOF (again)", fd );
-        return 0;
+  int nread;
+  struct reader_context_s *ctx;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_read", fd,
+	      "buffer=%p, count=%u", buffer, count);
+  
+  ctx = find_reader (fd, 1);
+  if (!ctx)
+    {
+      errno = EBADF;
+      return TRACE_SYSRES (-1);
     }
+  if (ctx->eof_shortcut)
+    return TRACE_SYSRES (0);
 
-    LOCK (c->mutex);
-    if (c->readpos == c->writepos && !c->error) { /*no data avail*/
-        UNLOCK (c->mutex);
-        DEBUG2 ("fd %d: waiting for data from thread %p", fd, c->thread_hd);
-        WaitForSingleObject (c->have_data_ev, INFINITE);
-        DEBUG2 ("fd %d: data from thread %p available", fd, c->thread_hd);
-        LOCK (c->mutex);
+  LOCK (ctx->mutex);
+  if (ctx->readpos == ctx->writepos && !ctx->error)
+    {
+      /* No data available.  */
+      UNLOCK (ctx->mutex);
+      TRACE_LOG1 ("waiting for data from thread %p", ctx->thread_hd);
+      WaitForSingleObject (ctx->have_data_ev, INFINITE);
+      TRACE_LOG1 ("data from thread %p available", ctx->thread_hd);
+      LOCK (ctx->mutex);
     }
-    
-    if (c->readpos == c->writepos || c->error) {
-        UNLOCK (c->mutex);
-        c->eof_shortcut = 1;
-        if (c->eof) {
-            DEBUG1 ("fd %d: EOF", fd );
-            return 0;
-        }
-        if (!c->error) {
-            DEBUG1 ("fd %d: EOF but eof flag not set", fd );
-            return 0;
-        }
-        DEBUG1 ("fd %d: read error", fd );
-	errno = c->error_code;
-        return -1;
+  
+  if (ctx->readpos == ctx->writepos || ctx->error)
+    {
+      UNLOCK (ctx->mutex);
+      ctx->eof_shortcut = 1;
+      if (ctx->eof)
+	return TRACE_SYSRES (0);
+      if (!ctx->error)
+	{
+	  TRACE_LOG ("EOF but ctx->eof flag not set");
+	  return 0;
+	}
+      errno = ctx->error_code;
+      return TRACE_SYSRES (-1);
     }
-      
-    nread = c->readpos < c->writepos? c->writepos - c->readpos
-                                    : READBUF_SIZE - c->readpos;
-    if (nread > count)
-        nread = count;
-    memcpy (buffer, c->buffer+c->readpos, nread);
-    c->readpos = (c->readpos + nread) % READBUF_SIZE;
-    if (c->readpos == c->writepos && !c->eof) {
-        if ( !ResetEvent (c->have_data_ev) )
-            DEBUG1 ("ResetEvent failed: ec=%d", (int)GetLastError ());
+  
+  nread = ctx->readpos < ctx->writepos
+    ? ctx->writepos - ctx->readpos
+    : READBUF_SIZE - ctx->readpos;
+  if (nread > count)
+    nread = count;
+  memcpy (buffer, ctx->buffer + ctx->readpos, nread);
+  ctx->readpos = (ctx->readpos + nread) % READBUF_SIZE;
+  if (ctx->readpos == ctx->writepos && !ctx->eof)
+    {
+      if (!ResetEvent (ctx->have_data_ev))
+	{
+	  TRACE_LOG1 ("ResetEvent failed: ec=%d", (int) GetLastError ());
+	  UNLOCK (ctx->mutex);
+	  /* FIXME: Should translate the error code.  */
+	  errno = EIO;
+	  return TRACE_SYSRES (-1);
+	}
+    }
+  if (!SetEvent (ctx->have_space_ev))
+    {
+      TRACE_LOG1 ("SetEvent failed: ec=%d", (int) GetLastError ());
+      UNLOCK (ctx->mutex);
+      /* FIXME: Should translate the error code.  */
+      errno = EIO;
+      return TRACE_SYSRES (-1);
     }
-    if (!SetEvent (c->have_space_ev))
-        DEBUG1 ("SetEvent failed: ec=%d", (int)GetLastError ());
-    UNLOCK (c->mutex);
+  UNLOCK (ctx->mutex);
+  
+  TRACE_LOGBUF (buffer, nread);
+  return TRACE_SYSRES (nread);
+}
 
-    DEBUG2 ("fd %d: got %d bytes\n", fd, nread );
-    if (nread > 0)
-      _gpgme_debug (2, "fd %d: got `%.*s'\n", fd, nread, buffer);
 
-    return nread;
-}
-/*
- * The writer does use a simple buffering strategy so that we are
- * informed about write errors as soon as possible (i.e. with the the
- * next call to the write function
- */
+/* The writer does use a simple buffering strategy so that we are
+   informed about write errors as soon as possible (i. e. with the the
+   next call to the write function.  */
 static DWORD CALLBACK 
 writer (void *arg)
 {
-    struct writer_context_s *c = arg;
-    DWORD nwritten;
-
-    DEBUG2 ("writer thread %p for file %p started", c->thread_hd, c->file_hd );
-    for (;;) {
-        LOCK (c->mutex);
-        if ( c->stop_me ) {
-            UNLOCK (c->mutex);
-            break;
+  struct writer_context_s *ctx = arg;
+  DWORD nwritten;
+  TRACE_BEG1 (DEBUG_SYSIO, "gpgme:writer", ctx->file_hd,
+	      "thread=%p", ctx->thread_hd);
+
+  for (;;)
+    {
+      LOCK (ctx->mutex);
+      if (ctx->stop_me)
+	{
+	  UNLOCK (ctx->mutex);
+	  break;
         }
-        if ( !c->nbytes ) { 
-            if (!SetEvent (c->is_empty))
-                DEBUG1 ("SetEvent failed: ec=%d", (int)GetLastError ());
-            if (!ResetEvent (c->have_data) )
-                DEBUG1 ("ResetEvent failed: ec=%d", (int)GetLastError ());
-            UNLOCK (c->mutex);
-            DEBUG1 ("writer thread %p: idle ...", c->thread_hd );
-            WaitForSingleObject (c->have_data, INFINITE);
-            DEBUG1 ("writer thread %p: got data to send", c->thread_hd );
-            LOCK (c->mutex);
+      if (!ctx->nbytes)
+	{ 
+	  if (!SetEvent (ctx->is_empty))
+	    TRACE_LOG1 ("SetEvent failed: ec=%d", (int) GetLastError ());
+	  if (!ResetEvent (ctx->have_data))
+	    TRACE_LOG1 ("ResetEvent failed: ec=%d", (int) GetLastError ());
+	  UNLOCK (ctx->mutex);
+	  TRACE_LOG ("idle");
+	  WaitForSingleObject (ctx->have_data, INFINITE);
+	  TRACE_LOG ("got data to send");
+	  LOCK (ctx->mutex);
        	}
-        if ( c->stop_me ) {
-            UNLOCK (c->mutex);
-            break;
+      if (ctx->stop_me)
+	{
+	  UNLOCK (ctx->mutex);
+	  break;
         }
-        UNLOCK (c->mutex);
-
-        DEBUG2 ("writer thread %p: writing %d bytes",
-                c->thread_hd, c->nbytes );
-        if ( c->nbytes && !WriteFile ( c->file_hd,  c->buffer, c->nbytes,
-                                       &nwritten, NULL)) {
-            c->error_code = (int)GetLastError ();
-            c->error = 1;
-            DEBUG2 ("writer thread %p: write error: ec=%d",
-                    c->thread_hd, c->error_code );
+      UNLOCK (ctx->mutex);
+      
+      TRACE_LOG1 ("writing %d bytes", ctx->nbytes);
+        if (ctx->nbytes
+	    && !WriteFile (ctx->file_hd, ctx->buffer,
+			   ctx->nbytes, &nwritten, NULL))
+	  {
+            ctx->error_code = (int) GetLastError ();
+            ctx->error = 1;
+            TRACE_LOG1 ("write error: ec=%d", ctx->error_code);
             break;
-        }
-        DEBUG2 ("writer thread %p: wrote %d bytes",
-                c->thread_hd, (int)nwritten );
+	  }
+        TRACE_LOG1 ("wrote %d bytes", (int) nwritten);
       
-        LOCK (c->mutex);
-        c->nbytes -= nwritten;
-        UNLOCK (c->mutex);
+        LOCK (ctx->mutex);
+        ctx->nbytes -= nwritten;
+        UNLOCK (ctx->mutex);
     }
-    /* indicate that we have an error  */
-    if ( !SetEvent (c->is_empty) )
-        DEBUG1 ("SetEvent failed: ec=%d", (int)GetLastError ());
-    DEBUG1 ("writer thread %p ended", c->thread_hd );
-    SetEvent (c->stopped);
+  /* Indicate that we have an error.  */
+  if (!SetEvent (ctx->is_empty))
+    TRACE_LOG1 ("SetEvent failed: ec=%d", (int) GetLastError ());
+  SetEvent (ctx->stopped);
 
-    return 0;
+  return TRACE_SUC ();
 }
 
 
 static struct writer_context_s *
 create_writer (HANDLE fd)
 {
-    struct writer_context_s *c;
-    SECURITY_ATTRIBUTES sec_attr;
-    DWORD tid;
-
-    DEBUG1 ("creating new write thread for file handle %p", fd );
-    memset (&sec_attr, 0, sizeof sec_attr );
-    sec_attr.nLength = sizeof sec_attr;
-    sec_attr.bInheritHandle = FALSE;
-
-    c = calloc (1, sizeof *c );
-    if (!c)
-        return NULL;
-
-    c->file_hd = fd;
-    c->refcount = 1;
-    c->have_data = CreateEvent (&sec_attr, TRUE, FALSE, NULL);
-    c->is_empty  = CreateEvent (&sec_attr, TRUE, TRUE, NULL);
-    c->stopped = CreateEvent (&sec_attr, TRUE, FALSE, NULL);
-    if (!c->have_data || !c->is_empty || !c->stopped ) {
-        DEBUG1 ("** CreateEvent failed: ec=%d\n", (int)GetLastError ());
-        if (c->have_data)
-            CloseHandle (c->have_data);
-        if (c->is_empty)
-            CloseHandle (c->is_empty);
-        if (c->stopped)
-            CloseHandle (c->stopped);
-        free (c);
-        return NULL;
+  struct writer_context_s *ctx;
+  SECURITY_ATTRIBUTES sec_attr;
+  DWORD tid;
+
+  TRACE_BEG (DEBUG_SYSIO, "gpgme:create_writer", fd);
+
+  memset (&sec_attr, 0, sizeof sec_attr);
+  sec_attr.nLength = sizeof sec_attr;
+  sec_attr.bInheritHandle = FALSE;
+
+  ctx = calloc (1, sizeof *ctx);
+  if (!ctx)
+    {
+      TRACE_SYSERR (errno);
+      return NULL;
     }
+  
+  ctx->file_hd = fd;
+  ctx->refcount = 1;
+  ctx->have_data = CreateEvent (&sec_attr, TRUE, FALSE, NULL);
+  if (ctx->have_data)
+    ctx->is_empty  = CreateEvent (&sec_attr, TRUE, TRUE, NULL);
+  if (ctx->is_empty)
+    ctx->stopped = CreateEvent (&sec_attr, TRUE, FALSE, NULL);
+  if (!ctx->have_data || !ctx->is_empty || !ctx->stopped)
+    {
+      TRACE_LOG1 ("CreateEvent failed: ec=%d", (int) GetLastError ());
+      if (ctx->have_data)
+	CloseHandle (ctx->have_data);
+      if (ctx->is_empty)
+	CloseHandle (ctx->is_empty);
+      if (ctx->stopped)
+	CloseHandle (ctx->stopped);
+      free (ctx);
+      /* FIXME: Translate the error code.  */
+      TRACE_SYSERR (EIO);
+      return NULL;
+    }
+
+  ctx->is_empty = set_synchronize (ctx->is_empty);
+  INIT_LOCK (ctx->mutex);
 
-    c->is_empty = set_synchronize (c->is_empty);
-    INIT_LOCK (c->mutex);
-
-    c->thread_hd = CreateThread (&sec_attr, 0, writer, c, 0, &tid );
-    if (!c->thread_hd) {
-        DEBUG1 ("** failed to create writer thread: ec=%d\n",
-                 (int)GetLastError ());
-        DESTROY_LOCK (c->mutex);
-        if (c->have_data)
-            CloseHandle (c->have_data);
-        if (c->is_empty)
-            CloseHandle (c->is_empty);
-        if (c->stopped)
-            CloseHandle (c->stopped);
-        free (c);
-        return NULL;
+  ctx->thread_hd = CreateThread (&sec_attr, 0, writer, ctx, 0, &tid );
+  if (!ctx->thread_hd)
+    {
+      TRACE_LOG1 ("CreateThread failed: ec=%d", (int) GetLastError ());
+      DESTROY_LOCK (ctx->mutex);
+      if (ctx->have_data)
+	CloseHandle (ctx->have_data);
+      if (ctx->is_empty)
+	CloseHandle (ctx->is_empty);
+      if (ctx->stopped)
+	CloseHandle (ctx->stopped);
+      free (ctx);
+      TRACE_SYSERR (EIO);
+      return NULL;
     }    
-    else {
-      /* We set the priority of the thread higher because we know that
-         it only runs for a short time.  This greatly helps to increase
-         the performance of the I/O. */
-      SetThreadPriority (c->thread_hd, get_desired_thread_priority ());
+  else
+    {
+      /* We set the priority of the thread higher because we know
+	 that it only runs for a short time.  This greatly helps to
+	 increase the performance of the I/O.  */
+      SetThreadPriority (ctx->thread_hd, get_desired_thread_priority ());
     }
 
-    return c;
+  TRACE_SUC ();
+  return ctx;
 }
 
 static void
-destroy_writer (struct writer_context_s *c)
+destroy_writer (struct writer_context_s *ctx)
 {
-    LOCK (c->mutex);
-    c->refcount--;
-    if (c->refcount != 0)
-      {
-	UNLOCK (c->mutex);
-	return;
-      }
-    c->stop_me = 1;
-    if (c->have_data) 
-        SetEvent (c->have_data);
-    UNLOCK (c->mutex);
-
-    DEBUG1 ("waiting for thread %p termination ...", c->thread_hd );
-    WaitForSingleObject (c->stopped, INFINITE);
-    DEBUG1 ("thread %p has terminated", c->thread_hd );
-    
-    if (c->stopped)
-        CloseHandle (c->stopped);
-    if (c->have_data)
-        CloseHandle (c->have_data);
-    if (c->is_empty)
-        CloseHandle (c->is_empty);
-    CloseHandle (c->thread_hd);
-    DESTROY_LOCK (c->mutex);
-    free (c);
+  LOCK (ctx->mutex);
+  ctx->refcount--;
+  if (ctx->refcount != 0)
+    {
+      UNLOCK (ctx->mutex);
+      return;
+    }
+  ctx->stop_me = 1;
+  if (ctx->have_data) 
+    SetEvent (ctx->have_data);
+  UNLOCK (ctx->mutex);
+  
+  TRACE1 (DEBUG_SYSIO, "gpgme:destroy_writer", ctx->file_hd,
+	  "waiting for termination of thread %p", ctx->thread_hd);
+  WaitForSingleObject (ctx->stopped, INFINITE);
+  TRACE1 (DEBUG_SYSIO, "gpgme:destroy_writer", ctx->file_hd,
+	  "thread %p has terminated", ctx->thread_hd);
+  
+  if (ctx->stopped)
+    CloseHandle (ctx->stopped);
+  if (ctx->have_data)
+    CloseHandle (ctx->have_data);
+  if (ctx->is_empty)
+    CloseHandle (ctx->is_empty);
+  CloseHandle (ctx->thread_hd);
+  DESTROY_LOCK (ctx->mutex);
+  free (ctx);
 }
 
 
-/* 
- * Find a writer context or create a new one 
- * Note that the writer context will last until a io_close.
- */
+/* Find a writer context or create a new one.  Note that the writer
+   context will last until a _gpgme_io_close.  */
 static struct writer_context_s *
 find_writer (int fd, int start_it)
 {
@@ -655,185 +716,228 @@ kill_writer (int fd)
 }
 
 
-
-
 int
-_gpgme_io_write ( int fd, const void *buffer, size_t count )
+_gpgme_io_write (int fd, const void *buffer, size_t count)
 {
-    struct writer_context_s *c = find_writer (fd,1);
-
-    DEBUG2 ("fd %d: about to write %d bytes\n", fd, (int)count );
-    _gpgme_debug (2, "fd %d: write `%.*s'\n", fd, (int) count, buffer);
-    if ( !c ) {
-        DEBUG0 ( "no writer thread\n");
-	errno = EBADF;
-        return -1;
+  struct writer_context_s *ctx;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_write", fd,
+	      "buffer=%p, count=%u", buffer, count);
+  TRACE_LOGBUF (buffer, count);
+
+  ctx = find_writer (fd, 1);
+  if (!ctx)
+    return TRACE_SYSRES (-1);
+
+  LOCK (ctx->mutex);
+  if (!ctx->error && ctx->nbytes)
+    {
+      /* Bytes are pending for send.  */
+
+      /* Reset the is_empty event.  Better safe than sorry.  */
+      if (!ResetEvent (ctx->is_empty))
+	{
+	  TRACE_LOG1 ("ResetEvent failed: ec=%d", (int) GetLastError ());
+	  UNLOCK (ctx->mutex);
+	  /* FIXME: Should translate the error code.  */
+	  errno = EIO;
+	  return TRACE_SYSRES (-1);
+	}
+      UNLOCK (ctx->mutex);
+      TRACE_LOG1 ("waiting for empty buffer in thread %p", ctx->thread_hd);
+      WaitForSingleObject (ctx->is_empty, INFINITE);
+      TRACE_LOG1 ("thread %p buffer is empty", ctx->thread_hd);
+      LOCK (ctx->mutex);
     }
 
-    LOCK (c->mutex);
-    if ( !c->error && c->nbytes ) { /* bytes are pending for send */
-        /* Reset the is_empty event.  Better safe than sorry.  */
-        if (!ResetEvent (c->is_empty))
-            DEBUG1 ("ResetEvent failed: ec=%d", (int)GetLastError ());
-        UNLOCK (c->mutex);
-        DEBUG2 ("fd %d: waiting for empty buffer in thread %p",
-                fd, c->thread_hd);
-        WaitForSingleObject (c->is_empty, INFINITE);
-        DEBUG2 ("fd %d: thread %p buffer is empty", fd, c->thread_hd);
-        LOCK (c->mutex);
+  if (ctx->error)
+    {
+      UNLOCK (ctx->mutex);
+      errno = ctx->error_code;
+      return TRACE_SYSRES (-1);
     }
-    
-    if ( c->error) {
-        UNLOCK (c->mutex);
-        DEBUG1 ("fd %d: write error", fd );
-	errno = c->error_code;
-        return -1;
+
+  /* If no error occured, the number of bytes in the buffer must be
+     zero.  */
+  assert (!ctx->nbytes);
+
+  if (count > WRITEBUF_SIZE)
+    count = WRITEBUF_SIZE;
+  memcpy (ctx->buffer, buffer, count);
+  ctx->nbytes = count;
+
+  /* We have to reset the is_empty event early, because it is also
+     used by the select() implementation to probe the channel.  */
+  if (!ResetEvent (ctx->is_empty))
+    {
+      TRACE_LOG1 ("ResetEvent failed: ec=%d", (int) GetLastError ());
+      UNLOCK (ctx->mutex);
+      /* FIXME: Should translate the error code.  */
+      errno = EIO;
+      return TRACE_SYSRES (-1);
     }
+  if (!SetEvent (ctx->have_data))
+    {
+      TRACE_LOG1 ("SetEvent failed: ec=%d", (int) GetLastError ());
+      UNLOCK (ctx->mutex);
+      /* FIXME: Should translate the error code.  */
+      errno = EIO;
+      return TRACE_SYSRES (-1);
+    }
+  UNLOCK (ctx->mutex);
 
-    /* If no error occured, the number of bytes in the buffer must be
-       zero.  */
-    assert (!c->nbytes);
-
-    if (count > WRITEBUF_SIZE)
-        count = WRITEBUF_SIZE;
-    memcpy (c->buffer, buffer, count);
-    c->nbytes = count;
-
-    /* We have to reset the is_empty event early, because it is also
-       used by the select() implementation to probe the channel.  */
-    if (!ResetEvent (c->is_empty))
-        DEBUG1 ("ResetEvent failed: ec=%d", (int)GetLastError ());
-    if (!SetEvent (c->have_data))
-        DEBUG1 ("SetEvent failed: ec=%d", (int)GetLastError ());
-    UNLOCK (c->mutex);
-
-    DEBUG2 ("fd %d:         copied %d bytes\n",
-                   fd, (int)count );
-    return (int)count;
+  return TRACE_SYSRES ((int) count);
 }
 
 
 int
-_gpgme_io_pipe ( int filedes[2], int inherit_idx )
+_gpgme_io_pipe (int filedes[2], int inherit_idx)
 {
-    HANDLE r, w;
-    SECURITY_ATTRIBUTES sec_attr;
+  HANDLE rh;
+  HANDLE wh;
+  SECURITY_ATTRIBUTES sec_attr;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_pipe", filedes,
+	      "inherit_idx=%i (GPGME uses it for %s)",
+	      inherit_idx, inherit_idx ? "writing" : "reading");
+
+  memset (&sec_attr, 0, sizeof (sec_attr));
+  sec_attr.nLength = sizeof (sec_attr);
+  sec_attr.bInheritHandle = FALSE;
+  
+  if (!CreatePipe (&rh, &wh, &sec_attr, PIPEBUF_SIZE))
+    {
+      TRACE_LOG1 ("CreatePipe failed: ec=%d", (int) GetLastError ());
+      /* FIXME: Should translate the error code.  */
+      errno = EIO;
+      return TRACE_SYSRES (-1);
+    }
 
-    memset (&sec_attr, 0, sizeof sec_attr );
-    sec_attr.nLength = sizeof sec_attr;
-    sec_attr.bInheritHandle = FALSE;
-    
-    if (!CreatePipe ( &r, &w, &sec_attr, PIPEBUF_SIZE))
-        return -1;
-    /* Make one end inheritable. */
-    if ( inherit_idx == 0 ) {
-        HANDLE h;
-        if (!DuplicateHandle( GetCurrentProcess(), r,
-                              GetCurrentProcess(), &h, 0,
-                              TRUE, DUPLICATE_SAME_ACCESS ) ) {
-            DEBUG1 ("DuplicateHandle failed: ec=%d\n", (int)GetLastError());
-            CloseHandle (r);
-            CloseHandle (w);
-            return -1;
+  /* Make one end inheritable.  */
+  if (inherit_idx == 0)
+    {
+      HANDLE hd;
+      if (!DuplicateHandle (GetCurrentProcess(), rh,
+			    GetCurrentProcess(), &hd, 0,
+			    TRUE, DUPLICATE_SAME_ACCESS))
+	{
+	  TRACE_LOG1 ("DuplicateHandle failed: ec=%d",
+		      (int) GetLastError ());
+	  CloseHandle (rh);
+	  CloseHandle (wh);
+	  /* FIXME: Should translate the error code.  */
+	  errno = EIO;
+	  return TRACE_SYSRES (-1);
         }
-        CloseHandle (r);
-        r = h;
+      CloseHandle (rh);
+      rh = hd;
     }
-    else if ( inherit_idx == 1 ) {
-        HANDLE h;
-        if (!DuplicateHandle( GetCurrentProcess(), w,
-                              GetCurrentProcess(), &h, 0,
-                              TRUE, DUPLICATE_SAME_ACCESS ) ) {
-            DEBUG1 ("DuplicateHandle failed: ec=%d\n", (int)GetLastError());
-            CloseHandle (r);
-            CloseHandle (w);
-            return -1;
+  else if (inherit_idx == 1)
+    {
+      HANDLE hd;
+      if (!DuplicateHandle( GetCurrentProcess(), wh,
+			    GetCurrentProcess(), &hd, 0,
+			    TRUE, DUPLICATE_SAME_ACCESS))
+	{
+	  TRACE_LOG1 ("DuplicateHandle failed: ec=%d",
+		      (int) GetLastError ());
+	  CloseHandle (rh);
+	  CloseHandle (wh);
+	  /* FIXME: Should translate the error code.  */
+	  errno = EIO;
+	  return TRACE_SYSRES (-1);
         }
-        CloseHandle (w);
-        w = h;
+      CloseHandle (wh);
+      wh = hd;
     }
-
-    filedes[0] = handle_to_fd (r);
-    filedes[1] = handle_to_fd (w);
-    DEBUG5 ("CreatePipe %p %p %d %d inherit=%d\n", r, w,
-                   filedes[0], filedes[1], inherit_idx );
-    return 0;
+  
+  filedes[0] = handle_to_fd (rh);
+  filedes[1] = handle_to_fd (wh);
+  return TRACE_SUC2 ("read=%p, write=%p", rh, wh);
 }
 
+
 int
-_gpgme_io_close ( int fd )
+_gpgme_io_close (int fd)
 {
-    int i;
-    _gpgme_close_notify_handler_t handler = NULL;
-    void *value = NULL;
-
-    if ( fd == -1 )
-        return -1;
-
-    DEBUG1 ("** closing handle for fd %d\n", fd);
-    kill_reader (fd);
-    kill_writer (fd);
-    LOCK (notify_table_lock);
-    for ( i=0; i < DIM (notify_table); i++ ) {
-        if (notify_table[i].inuse && notify_table[i].fd == fd) {
-	    handler = notify_table[i].handler;
-            value   = notify_table[i].value;
-            notify_table[i].handler = NULL;
-            notify_table[i].value = NULL;
-            notify_table[i].inuse = 0;
-            break;
-        }
+  int i;
+  _gpgme_close_notify_handler_t handler = NULL;
+  void *value = NULL;
+  TRACE_BEG (DEBUG_SYSIO, "_gpgme_io_close", fd);
+
+  if (fd == -1)
+    {
+      errno = EBADF;
+      return TRACE_SYSRES (-1);
+    }
+
+  kill_reader (fd);
+  kill_writer (fd);
+  LOCK (notify_table_lock);
+  for (i = 0; i < DIM (notify_table); i++)
+    {
+      if (notify_table[i].inuse && notify_table[i].fd == fd)
+	{
+	  handler = notify_table[i].handler;
+	  value   = notify_table[i].value;
+	  notify_table[i].handler = NULL;
+	  notify_table[i].value = NULL;
+	  notify_table[i].inuse = 0;
+	  break;
+	}
     }
-    UNLOCK (notify_table_lock);
-    if (handler)
-        handler (fd, value);
-
-    if ( !CloseHandle (fd_to_handle (fd)) ) { 
-        DEBUG2 ("CloseHandle for fd %d failed: ec=%d\n",
-                 fd, (int)GetLastError ());
-        return -1;
+  UNLOCK (notify_table_lock);
+  if (handler)
+    handler (fd, value);
+
+  if (!CloseHandle (fd_to_handle (fd)))
+    { 
+      TRACE_LOG1 ("CloseHandle failed: ec=%d", (int) GetLastError ());
+      /* FIXME: Should translate the error code.  */
+      errno = EIO;
+      return TRACE_SYSRES (-1);
     }
 
-    return 0;
+  return TRACE_SYSRES (0);
 }
 
+
 int
 _gpgme_io_set_close_notify (int fd, _gpgme_close_notify_handler_t handler,
 			    void *value)
 {
-    int i;
+  int i;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_set_close_notify", fd,
+	      "close_handler=%p/%p", handler, value);
 
-    assert (fd != -1);
+  assert (fd != -1);
 
-    LOCK (notify_table_lock);
-    for (i=0; i < DIM (notify_table); i++ ) {
-        if ( notify_table[i].inuse && notify_table[i].fd == fd )
-            break;
-    }
-    if ( i == DIM (notify_table) ) {
-        for (i=0; i < DIM (notify_table); i++ ) {
-            if ( !notify_table[i].inuse )
-                break;
-        }
-    }
-    if ( i == DIM (notify_table) ) {
-        UNLOCK (notify_table_lock);
-        return -1;
+  LOCK (notify_table_lock);
+  for (i=0; i < DIM (notify_table); i++)
+    if (notify_table[i].inuse && notify_table[i].fd == fd)
+      break;
+  if (i == DIM (notify_table))
+    for (i = 0; i < DIM (notify_table); i++)
+      if (!notify_table[i].inuse)
+	break;
+  if (i == DIM (notify_table))
+    {
+      UNLOCK (notify_table_lock);
+      errno = EINVAL;
+      return TRACE_SYSRES (-1);
     }
-    notify_table[i].fd = fd;
-    notify_table[i].handler = handler;
-    notify_table[i].value = value;
-    notify_table[i].inuse = 1;
-    UNLOCK (notify_table_lock);
-    DEBUG2 ("set notification for fd %d (idx=%d)", fd, i );
-    return 0;
+  notify_table[i].fd = fd;
+  notify_table[i].handler = handler;
+  notify_table[i].value = value;
+  notify_table[i].inuse = 1;
+  UNLOCK (notify_table_lock);
+  return TRACE_SYSRES (0);
 }
 
 
 int
-_gpgme_io_set_nonblocking ( int fd )
+_gpgme_io_set_nonblocking (int fd)
 {
-    return 0;
+  TRACE (DEBUG_SYSIO, "_gpgme_io_set_nonblocking", fd);
+  return 0;
 }
 
 
@@ -841,7 +945,6 @@ static char *
 build_commandline (char **argv)
 {
   int i;
-  int j;
   int n = 0;
   char *buf;
   char *p;
@@ -894,279 +997,327 @@ build_commandline (char **argv)
 
 
 int
-_gpgme_io_spawn ( const char *path, char **argv,
-                  struct spawn_fd_item_s *fd_child_list,
-                  struct spawn_fd_item_s *fd_parent_list )
+_gpgme_io_spawn (const char *path, char **argv,
+		 struct spawn_fd_item_s *fd_child_list,
+		 struct spawn_fd_item_s *fd_parent_list)
 {
-    SECURITY_ATTRIBUTES sec_attr;
-    PROCESS_INFORMATION pi = {
-        NULL,      /* returns process handle */
-        0,         /* returns primary thread handle */
-        0,         /* returns pid */
-        0         /* returns tid */
+  SECURITY_ATTRIBUTES sec_attr;
+  PROCESS_INFORMATION pi =
+    {
+      NULL,      /* returns process handle */
+      0,         /* returns primary thread handle */
+      0,         /* returns pid */
+      0         /* returns tid */
     };
-    STARTUPINFO si;
-    char *envblock = NULL;
-    int cr_flags = CREATE_DEFAULT_ERROR_MODE
-                 | GetPriorityClass (GetCurrentProcess ());
-    int i;
-    char *arg_string;
-    int duped_stdin = 0;
-    int duped_stderr = 0;
-    HANDLE hnul = INVALID_HANDLE_VALUE;
-    /* FIXME.  */
-    int debug_me = 0;
-
-    memset (&sec_attr, 0, sizeof sec_attr );
-    sec_attr.nLength = sizeof sec_attr;
-    sec_attr.bInheritHandle = FALSE;
-
-    arg_string = build_commandline ( argv );
-    if (!arg_string )
-        return -1; 
-
-    memset (&si, 0, sizeof si);
-    si.cb = sizeof (si);
-    si.dwFlags = STARTF_USESTDHANDLES | STARTF_USESHOWWINDOW;
-    si.wShowWindow = debug_me? SW_SHOW : SW_HIDE;
-    si.hStdInput = GetStdHandle (STD_INPUT_HANDLE);
-    si.hStdOutput = GetStdHandle (STD_OUTPUT_HANDLE);
-    si.hStdError = GetStdHandle (STD_ERROR_HANDLE);
-
-    for (i=0; fd_child_list[i].fd != -1; i++ ) {
-        if (fd_child_list[i].dup_to == 0 ) {
-            si.hStdInput = fd_to_handle (fd_child_list[i].fd);
-            DEBUG1 ("using %d for stdin", fd_child_list[i].fd );
-            duped_stdin=1;
+  STARTUPINFO si;
+  char *envblock = NULL;
+  int cr_flags = CREATE_DEFAULT_ERROR_MODE
+    | GetPriorityClass (GetCurrentProcess ());
+  int i;
+  char *arg_string;
+  int duped_stdin = 0;
+  int duped_stderr = 0;
+  HANDLE hnul = INVALID_HANDLE_VALUE;
+  /* FIXME.  */
+  int debug_me = 0;
+  TRACE_BEG1 (DEBUG_SYSIO, "_gpgme_io_spawn", path,
+	      "path=%s", path);
+  i = 0;
+  while (argv[i])
+    {
+      TRACE_LOG2 ("argv[%2i] = %s", i, argv[i]);
+      i++;
+    }
+
+  memset (&sec_attr, 0, sizeof sec_attr);
+  sec_attr.nLength = sizeof sec_attr;
+  sec_attr.bInheritHandle = FALSE;
+  
+  arg_string = build_commandline (argv);
+  if (!arg_string)
+    return TRACE_SYSRES (-1);
+  
+  memset (&si, 0, sizeof si);
+  si.cb = sizeof (si);
+  si.dwFlags = STARTF_USESTDHANDLES | STARTF_USESHOWWINDOW;
+  si.wShowWindow = debug_me ? SW_SHOW : SW_HIDE;
+  si.hStdInput = GetStdHandle (STD_INPUT_HANDLE);
+  si.hStdOutput = GetStdHandle (STD_OUTPUT_HANDLE);
+  si.hStdError = GetStdHandle (STD_ERROR_HANDLE);
+
+  for (i = 0; fd_child_list[i].fd != -1; i++)
+    {
+      if (fd_child_list[i].dup_to == 0)
+	{
+	  si.hStdInput = fd_to_handle (fd_child_list[i].fd);
+	  TRACE_LOG1 ("using 0x%x for stdin", fd_child_list[i].fd);
+	  duped_stdin = 1;
         }
-        else if (fd_child_list[i].dup_to == 1 ) {
-            si.hStdOutput = fd_to_handle (fd_child_list[i].fd);
-            DEBUG1 ("using %d for stdout", fd_child_list[i].fd );
+      else if (fd_child_list[i].dup_to == 1)
+	{
+	  si.hStdOutput = fd_to_handle (fd_child_list[i].fd);
+	  TRACE_LOG1 ("using 0x%x for stdout", fd_child_list[i].fd);
         }
-        else if (fd_child_list[i].dup_to == 2 ) {
-            si.hStdError = fd_to_handle (fd_child_list[i].fd);
-            DEBUG1 ("using %d for stderr", fd_child_list[i].fd );
-            duped_stderr = 1;
+      else if (fd_child_list[i].dup_to == 2)
+	{
+	  si.hStdError = fd_to_handle (fd_child_list[i].fd);
+	  TRACE_LOG1 ("using 0x%x for stderr", fd_child_list[i].fd);
+	  duped_stderr = 1;
         }
     }
-
-    if( !duped_stdin || !duped_stderr ) {
-        SECURITY_ATTRIBUTES sa;
-
-        memset (&sa, 0, sizeof sa );
-        sa.nLength = sizeof sa;
-        sa.bInheritHandle = TRUE;
-        hnul = CreateFile ( "nul",
-                            GENERIC_READ|GENERIC_WRITE,
-                            FILE_SHARE_READ|FILE_SHARE_WRITE,
-                            &sa,
-                            OPEN_EXISTING,
-                            FILE_ATTRIBUTE_NORMAL,
-                            NULL );
-        if ( hnul == INVALID_HANDLE_VALUE ) {
-            DEBUG1 ("can't open `nul': ec=%d\n", (int)GetLastError ());
-            free (arg_string);
-            return -1;
+  
+  if (!duped_stdin || !duped_stderr)
+    {
+      SECURITY_ATTRIBUTES sa;
+      
+      memset (&sa, 0, sizeof sa);
+      sa.nLength = sizeof sa;
+      sa.bInheritHandle = TRUE;
+      hnul = CreateFile ("nul",
+			 GENERIC_READ|GENERIC_WRITE,
+			 FILE_SHARE_READ|FILE_SHARE_WRITE,
+			 &sa,
+			 OPEN_EXISTING,
+			 FILE_ATTRIBUTE_NORMAL,
+			 NULL);
+      if (hnul == INVALID_HANDLE_VALUE)
+	{
+	  TRACE_LOG1 ("CreateFile (\"nul\") failed: ec=%d",
+		      (int) GetLastError ());
+	  free (arg_string);
+	  /* FIXME: Should translate the error code.  */
+	  errno = EIO;
+	  return TRACE_SYSRES (-1);
         }
-        /* Make sure that the process has a connected stdin */
-        if ( !duped_stdin ) {
-            si.hStdInput = hnul;
-            DEBUG1 ("using %d for dummy stdin", (int)hnul );
+      /* Make sure that the process has a connected stdin.  */
+      if (!duped_stdin)
+	{
+	  si.hStdInput = hnul;
+	  TRACE_LOG1 ("using 0x%x for dummy stdin", (int) hnul);
         }
-        /* We normally don't want all the normal output */
-        if ( !duped_stderr ) {
-            si.hStdError = hnul;
-            DEBUG1 ("using %d for dummy stderr", (int)hnul );
+      /* We normally don't want all the normal output.  */
+      if (!duped_stderr)
+	{
+	  si.hStdError = hnul;
+	  TRACE_LOG1 ("using 0x%x for dummy stderr", (int) hnul);
         }
     }
-
-    DEBUG2 ("CreateProcess, path=`%s' args=`%s'", path, arg_string);
-    cr_flags |= CREATE_SUSPENDED; 
-    if ( !CreateProcessA (path,
-                          arg_string,
-                          &sec_attr,     /* process security attributes */
-                          &sec_attr,     /* thread security attributes */
-                          TRUE,          /* inherit handles */
-                          cr_flags,      /* creation flags */
-                          envblock,      /* environment */
-                          NULL,          /* use current drive/directory */
-                          &si,           /* startup information */
-                          &pi            /* returns process information */
-        ) ) {
-        DEBUG1 ("CreateProcess failed: ec=%d\n", (int) GetLastError ());
-        free (arg_string);
-        return -1;
-    }
-
-    /* Close the /dev/nul handle if used. */
-    if (hnul != INVALID_HANDLE_VALUE ) {
-        if ( !CloseHandle ( hnul ) )
-            DEBUG1 ("CloseHandle(hnul) failed: ec=%d\n", (int)GetLastError());
-    }
-
-    /* Close the other ends of the pipes. */
-    for (i = 0; fd_parent_list[i].fd != -1; i++)
-      _gpgme_io_close (fd_parent_list[i].fd);
-
-    DEBUG4 ("CreateProcess ready\n"
-            "-   hProcess=%p  hThread=%p\n"
-            "-   dwProcessID=%d dwThreadId=%d\n",
-            pi.hProcess, pi.hThread, 
-            (int) pi.dwProcessId, (int) pi.dwThreadId);
-
-    if ( ResumeThread ( pi.hThread ) < 0 ) {
-        DEBUG1 ("ResumeThread failed: ec=%d\n", (int)GetLastError ());
+  
+  cr_flags |= CREATE_SUSPENDED; 
+  if (!CreateProcessA (path,
+		       arg_string,
+		       &sec_attr,     /* process security attributes */
+		       &sec_attr,     /* thread security attributes */
+		       TRUE,          /* inherit handles */
+		       cr_flags,      /* creation flags */
+		       envblock,      /* environment */
+		       NULL,          /* use current drive/directory */
+		       &si,           /* startup information */
+		       &pi))          /* returns process information */
+    {
+      TRACE_LOG1 ("CreateProcess failed: ec=%d", (int) GetLastError ());
+      free (arg_string);
+      /* FIXME: Should translate the error code.  */
+      errno = EIO;
+      return TRACE_SYSRES (-1);
     }
 
-    if ( !CloseHandle (pi.hThread) ) { 
-        DEBUG1 ("CloseHandle of thread failed: ec=%d\n",
-                 (int)GetLastError ());
+  /* Close the /dev/nul handle if used.  */
+  if (hnul != INVALID_HANDLE_VALUE)
+    {
+      if (!CloseHandle (hnul))
+	TRACE_LOG1 ("CloseHandle (hnul) failed: ec=%d (ignored)",
+		    (int) GetLastError ());
     }
+  
+  /* Close the other ends of the pipes.  */
+  for (i = 0; fd_parent_list[i].fd != -1; i++)
+    _gpgme_io_close (fd_parent_list[i].fd);
+  
+  TRACE_LOG4 ("CreateProcess ready: hProcess=%p, hThread=%p, "
+	      "dwProcessID=%d, dwThreadId=%d",
+	      pi.hProcess, pi.hThread, 
+	      (int) pi.dwProcessId, (int) pi.dwThreadId);
+  
+  if (ResumeThread (pi.hThread) < 0)
+    TRACE_LOG1 ("ResumeThread failed: ec=%d", (int) GetLastError ());
+  
+  if (!CloseHandle (pi.hThread))
+    TRACE_LOG1 ("CloseHandle of thread failed: ec=%d",
+		(int) GetLastError ());
 
-    return handle_to_pid (pi.hProcess);
+  TRACE_SUC1 ("process=%p", pi.hProcess);
+  return handle_to_pid (pi.hProcess);
 }
 
 
-/*
- * Select on the list of fds.
- * Returns: -1 = error
- *           0 = timeout or nothing to select
- *          >0 = number of signaled fds
- */
+/* Select on the list of fds.  Returns: -1 = error, 0 = timeout or
+   nothing to select, > 0 = number of signaled fds.  */
 int
-_gpgme_io_select ( struct io_select_fd_s *fds, size_t nfds, int nonblock )
+_gpgme_io_select (struct io_select_fd_s *fds, size_t nfds, int nonblock)
 {
-    HANDLE waitbuf[MAXIMUM_WAIT_OBJECTS];
-    int    waitidx[MAXIMUM_WAIT_OBJECTS];
-    int code, nwait;
-    int i, any;
-    int count;
-    void *dbg_help;
+  HANDLE waitbuf[MAXIMUM_WAIT_OBJECTS];
+  int waitidx[MAXIMUM_WAIT_OBJECTS];
+  int code;
+  int nwait;
+  int i;
+  int any;
+  int count;
+  void *dbg_help;
+  TRACE_BEG2 (DEBUG_SYSIO, "_gpgme_io_select", fds,
+	      "nfds=%u, nonblock=%u", nfds, nonblock);
 
  restart:
-    DEBUG_BEGIN (dbg_help, 3, "select on [ ");
-    any = 0;
-    nwait = 0;
-    count = 0;
-    for ( i=0; i < nfds; i++ ) {
-        if ( fds[i].fd == -1 ) 
-            continue;
-        fds[i].signaled = 0;
-        if ( fds[i].for_read || fds[i].for_write ) {
-            if ( fds[i].frozen ) {
-                DEBUG_ADD1 (dbg_help, "f%d ", fds[i].fd );
-            }
-            else if ( fds[i].for_read ) {
-                struct reader_context_s *c = find_reader (fds[i].fd,1);
-                
-                if (!c) { 
-                    DEBUG1 ("oops: no reader thread for fd %d", fds[i].fd);
-                }
-                else {
-                    if ( nwait >= DIM (waitbuf) ) {
-                        DEBUG_END (dbg_help, "oops ]");
-                        DEBUG0 ("Too many objects for WFMO!" );
-                        return -1;
+  TRACE_SEQ (dbg_help, "select on [ ");
+  any = 0;
+  nwait = 0;
+  count = 0;
+  for (i=0; i < nfds; i++)
+    {
+      if (fds[i].fd == -1)
+	continue;
+      fds[i].signaled = 0;
+      if (fds[i].for_read || fds[i].for_write)
+	{
+	  if (fds[i].frozen)
+	    TRACE_ADD1 (dbg_help, "f0x%x ", fds[i].fd);
+	  else if (fds[i].for_read)
+	    {
+	      struct reader_context_s *ctx = find_reader (fds[i].fd,1);
+	      
+	      if (!ctx)
+		TRACE_LOG1 ("error: no reader for FD 0x%x (ignored)",
+			    fds[i].fd);
+	      else
+		{
+		  if (nwait >= DIM (waitbuf))
+		    {
+		      TRACE_END (dbg_help, "oops ]");
+		      TRACE_LOG ("Too many objects for WFMO!");
+		      /* FIXME: Should translate the error code.  */
+		      errno = EIO;
+		      return TRACE_SYSRES (-1);
                     }
-                    waitidx[nwait]   = i;
-                    waitbuf[nwait++] = c->have_data_ev;
+		  waitidx[nwait] = i;
+		  waitbuf[nwait++] = ctx->have_data_ev;
                 }
-                DEBUG_ADD1 (dbg_help, "r%d ", fds[i].fd );
-                any = 1;
+	      TRACE_ADD1 (dbg_help, "r0x%x ", fds[i].fd);
+	      any = 1;
             }
-            else if ( fds[i].for_write ) {
-                struct writer_context_s *c = find_writer (fds[i].fd,1);
-                
-                if (!c) { 
-                    DEBUG1 ("oops: no writer thread for fd %d", fds[i].fd);
-                }
-                else {
-                    if ( nwait >= DIM (waitbuf) ) {
-                        DEBUG_END (dbg_help, "oops ]");
-                        DEBUG0 ("Too many objects for WFMO!" );
-                        return -1;
+	  else if (fds[i].for_write)
+	    {
+	      struct writer_context_s *ctx = find_writer (fds[i].fd,1);
+              
+	      if (!ctx)
+		TRACE_LOG1 ("error: no writer for FD 0x%x (ignored)",
+			    fds[i].fd);
+	      else
+		{
+		  if (nwait >= DIM (waitbuf))
+		    {
+		      TRACE_END (dbg_help, "oops ]");
+		      TRACE_LOG ("Too many objects for WFMO!");
+		      /* FIXME: Should translate the error code.  */
+		      errno = EIO;
+		      return TRACE_SYSRES (-1);
                     }
-		    waitidx[nwait]   = i;
-		    waitbuf[nwait++] = c->is_empty;
+		  waitidx[nwait] = i;
+		  waitbuf[nwait++] = ctx->is_empty;
                 }
-		DEBUG_ADD1 (dbg_help, "w%d ", fds[i].fd );
-		any = 1;
+	      TRACE_ADD1 (dbg_help, "w0x%x ", fds[i].fd);
+	      any = 1;
             }
         }
     }
-    DEBUG_END (dbg_help, "]");
-    if (!any) 
-        return 0;
-
-    code = WaitForMultipleObjects ( nwait, waitbuf, 0, nonblock ? 0 : 1000);
-    if ( code >= WAIT_OBJECT_0 && code < WAIT_OBJECT_0 + nwait ) {
-        /* This WFMO is a really silly function:  It does return either
-         * the index of the signaled object or if 2 objects have been
-         * signalled at the same time, the index of the object with the
-         * lowest object is returned - so and how do we find out
-         * how many objects have been signaled???.
-         * The only solution I can imagine is to test each object starting
-         * with the returned index individually - how dull.
-         */
-        any = 0;
-        for (i=code - WAIT_OBJECT_0; i < nwait; i++ ) {
-            if (WaitForSingleObject (waitbuf[i], 0) == WAIT_OBJECT_0) {
-                assert (waitidx[i] >=0 && waitidx[i] < nfds);
-                fds[waitidx[i]].signaled = 1;
-                any = 1;
-                count++;
-            }
-        }
-        if (!any) {
-            DEBUG0 ("Oops: No signaled objects found after WFMO");
-            count = -1;
-        }
+  TRACE_END (dbg_help, "]");
+  if (!any) 
+    return TRACE_SYSRES (0);
+
+  code = WaitForMultipleObjects (nwait, waitbuf, 0, nonblock ? 0 : 1000);
+  if (code >= WAIT_OBJECT_0 && code < WAIT_OBJECT_0 + nwait)
+    {
+      /* This WFMO is a really silly function: It does return either
+	 the index of the signaled object or if 2 objects have been
+	 signalled at the same time, the index of the object with the
+	 lowest object is returned - so and how do we find out how
+	 many objects have been signaled???.  The only solution I can
+	 imagine is to test each object starting with the returned
+	 index individually - how dull.  */
+      any = 0;
+      for (i = code - WAIT_OBJECT_0; i < nwait; i++)
+	{
+	  if (WaitForSingleObject (waitbuf[i], 0) == WAIT_OBJECT_0)
+	    {
+	      assert (waitidx[i] >=0 && waitidx[i] < nfds);
+	      fds[waitidx[i]].signaled = 1;
+	      any = 1;
+	      count++;
+	    }
+	}
+      if (!any)
+	{
+	  TRACE_LOG ("no signaled objects found after WFMO");
+	  count = -1;
+	}
     }
-    else if ( code == WAIT_TIMEOUT ) {
-        DEBUG0 ("WFMO timed out\n" );
-    }  
-    else if (code == WAIT_FAILED ) {
-        int le = (int)GetLastError ();
-        if ( le == ERROR_INVALID_HANDLE ) {
-            int k, j = handle_to_fd (waitbuf[i]);
-                    
-            DEBUG1 ("WFMO invalid handle %d removed\n", j);
-            for (k=0 ; k < nfds; k++ ) {
-                if ( fds[k].fd == j ) {
-                    fds[k].for_read = fds[k].for_write = 0;
-                    goto restart;
+  else if (code == WAIT_TIMEOUT)
+    TRACE_LOG ("WFMO timed out");
+  else if (code == WAIT_FAILED)
+    {
+      int le = (int) GetLastError ();
+      if (le == ERROR_INVALID_HANDLE)
+	{
+	  int k;
+	  int j = handle_to_fd (waitbuf[i]);
+          
+	  TRACE_LOG1 ("WFMO invalid handle %d removed", j);
+	  for (k = 0 ; k < nfds; k++)
+	    {
+	      if (fds[k].fd == j)
+		{
+		  fds[k].for_read = fds[k].for_write = 0;
+		  goto restart;
                 }
             }
-            DEBUG0 (" oops, or not???\n");
+	  TRACE_LOG (" oops, or not???");
         }
-        DEBUG1 ("WFMO failed: %d\n", le );
-        count = -1;
+      TRACE_LOG1 ("WFMO failed: %d", le);
+      count = -1;
     }
-    else {
-        DEBUG1 ("WFMO returned %d\n", code );
-        count = -1;
+  else
+    {
+      TRACE_LOG1 ("WFMO returned %d", code);
+      count = -1;
     }
-
-    if ( count ) {
-        DEBUG_BEGIN (dbg_help, 3, " signaled [ ");
-        for ( i=0; i < nfds; i++ ) {
-            if ( fds[i].fd == -1 ) 
-                continue;
-            if ( (fds[i].for_read || fds[i].for_write) && fds[i].signaled ) {
-                DEBUG_ADD2 (dbg_help, "%c%d ",
-                            fds[i].for_read? 'r':'w',fds[i].fd );
-            }
+  
+  if (count > 0)
+    {
+      TRACE_SEQ (dbg_help, "select OK [ ");
+      for (i = 0; i < nfds; i++)
+	{
+	  if (fds[i].fd == -1)
+	    continue;
+	  if ((fds[i].for_read || fds[i].for_write) && fds[i].signaled)
+	    TRACE_ADD2 (dbg_help, "%c0x%x ",
+			fds[i].for_read ? 'r' : 'w', fds[i].fd);
         }
-        DEBUG_END (dbg_help, "]");
+      TRACE_END (dbg_help, "]");
     }
-    
-    return count;
+
+  if (count < 0)
+    {
+      /* FIXME: Should determine a proper error code.  */
+      errno = EIO;
+    }
+  
+  return TRACE_SYSRES (count);
 }
 
+
 void
 _gpgme_io_subsystem_init (void)
 {
-  
+  /* Nothing to do.  */
 }
 
 
@@ -1189,14 +1340,16 @@ _gpgme_io_dup (int fd)
   struct reader_context_s *rd_ctx;
   struct writer_context_s *wt_ctx;
 
+  TRACE_BEG (DEBUG_SYSIO, "_gpgme_io_dup", fd);
+
   if (!DuplicateHandle (GetCurrentProcess(), handle,
 			GetCurrentProcess(), &new_handle,
 			0, FALSE, DUPLICATE_SAME_ACCESS))
     {
-      DEBUG1 ("DuplicateHandle failed: ec=%d\n", (int) GetLastError ());
+      TRACE_LOG1 ("DuplicateHandle failed: ec=%d\n", (int) GetLastError ());
       /* FIXME: Translate error code.  */
       errno = EIO;
-      return -1;
+      return TRACE_SYSRES (-1);
     }
 
   rd_ctx = find_reader (fd, 1);
@@ -1237,7 +1390,7 @@ _gpgme_io_dup (int fd)
       UNLOCK (writer_table_lock);
     }
 
-  return handle_to_fd (new_handle);
+  return TRACE_SYSRES (handle_to_fd (new_handle));
 }
 
 
@@ -1250,3 +1403,4 @@ gpgme_get_giochannel (int fd)
   return NULL;
 }
 
+
diff --git a/gpgme/w32-util.c b/gpgme/w32-util.c
index 889a6ec1..50a3c92d 100644
--- a/gpgme/w32-util.c
+++ b/gpgme/w32-util.c
@@ -1,7 +1,7 @@
 /* w32-util.c - Utility functions for the W32 API
    Copyright (C) 1999 Free Software Foundation, Inc
    Copyright (C) 2001 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2007 g10 Code GmbH
 
    This file is part of GPGME.
  
@@ -232,7 +232,8 @@ find_program_in_registry (const char *name)
     {
       int i;
 
-      DEBUG2 ("found %s in registry: `%s'", name, program);
+      TRACE2 (DEBUG_CTX, "gpgme:find_program_in_registry", 0,
+	      "found %s in registry: `%s'", name, program);
       for (i = 0; program[i]; i++)
 	{
 	  if (program[i] == '/')
diff --git a/gpgme/wait.c b/gpgme/wait.c
index 16a9f230..67956d37 100644
--- a/gpgme/wait.c
+++ b/gpgme/wait.c
@@ -1,6 +1,6 @@
 /* wait.c 
    Copyright (C) 2000 Werner Koch (dd9jn)
-   Copyright (C) 2001, 2002, 2003, 2004, 2005 g10 Code GmbH
+   Copyright (C) 2001, 2002, 2003, 2004, 2005, 2007 g10 Code GmbH
  
    This file is part of GPGME.
  
@@ -156,8 +156,10 @@ _gpgme_remove_io_cb (void *data)
   assert (fdt);
   idx = tag->idx;
 
-  DEBUG2 ("setting fd %d (item=%p) done", fdt->fds[idx].fd,
+  TRACE2 (DEBUG_CTX, "_gpgme_remove_io_cb", data,
+	  "setting fd 0x%x (item=%p) done", fdt->fds[idx].fd,
 	  fdt->fds[idx].opaque);
+
   free (fdt->fds[idx].opaque);
   free (tag);