2007-07-17 Marcus Brinkmann <marcus@g10code.de>
[gpgme.git] / gpgme / w32-io.c
index 9ae22f5..4a76d75 100644 (file)
@@ -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));
 }
 
 \f
@@ -1250,3 +1403,4 @@ gpgme_get_giochannel (int fd)
   return NULL;
 }
 
+