Improve debugging; fix c522de11.

* include/mailutils/types.hin (mu_debug_handle_t)
(mu_debug_level_t): New data types.
* include/mailutils/debug.h (mu_debug_level_p)
(mu_debug_category_level)
(mu_debug_set_category_level): Change argument types to
mu_debug_handle_t/mu_debug_level_t.
* libmailutils/diag/debug.c: Likewise.

* libmailutils/server/acl.c (_run_entry): Call mu_debug_log_nl
instead of mu_debug_log_end with an empty format string.

* include/mailutils/sieve.h
* libmailutils/filter/base64.c
* libmailutils/stream/stream.c
* libmu_sieve/conf.c
* libmu_sieve/extensions/spamd.c
* libmu_sieve/sieve.y
* sieve/sieve.c: Commit the changes c522de11 failed to commit.

@@ -58,14 +58,17 @@ char *mu_sockaddr_to_astr (const struct sockaddr *sa, int salen);
 
 size_t mu_debug_register_category (char *name);
 size_t mu_debug_next_handle (void);
-int mu_debug_level_p (int catn, int level);
-void mu_debug_enable_category (const char *catname, size_t catlen, int level);
+int mu_debug_level_p (mu_debug_handle_t catn, mu_debug_level_t level);
+void mu_debug_enable_category (const char *catname, size_t catlen,
+			       mu_debug_level_t level);
 void mu_debug_disable_category (const char *catname, size_t catlen);
-int mu_debug_category_level (const char *catname, size_t catlen, int *plev);
+int mu_debug_category_level (const char *catname, size_t catlen,
+			     mu_debug_level_t *plev);
 void mu_debug_parse_spec (const char *spec);  
 int mu_debug_format_spec(mu_stream_t str, const char *names, int showunset);
 
-void mu_debug_set_category_level (int catn, int level);
+void mu_debug_set_category_level (mu_debug_handle_t catn,
+				  mu_debug_level_t level);
 void mu_debug_clear_all (void);
   
 void mu_debug_log (const char *fmt, ...) MU_PRINTFLIKE(1,2);

@@ -120,10 +120,13 @@ typedef struct
 #define MU_SIEVE_DRY_RUN      0x0008
 
 extern int mu_sieve_yydebug;
+extern mu_debug_handle_t mu_sieve_debug_handle;
 extern mu_list_t mu_sieve_include_path;
 extern mu_list_t mu_sieve_library_path;
 extern mu_list_t mu_sieve_library_path_prefix;
 
+void mu_sieve_debug_init (void);
+  
 /* Memory allocation functions */
 void *mu_sieve_alloc (size_t size);
 void *mu_sieve_palloc (mu_list_t * pool, size_t size);

@@ -120,6 +120,8 @@ typedef struct _mu_secret *mu_secret_t;
 typedef struct _mu_mime_io_buffer *mu_mime_io_buffer_t;
 
 typedef void (*mu_onexit_t) (void*);
+typedef unsigned int mu_debug_handle_t;
+typedef unsigned int mu_debug_level_t;
 
 #define MU_FOLDER_ATTRIBUTE_DIRECTORY  0x001
 #define MU_FOLDER_ATTRIBUTE_FILE       0x002

@@ -38,7 +38,7 @@ int mu_debug_line_info;          /* Debug messages include source locations */
 struct debug_category
 {
   char *name;
-  size_t level;
+  mu_debug_level_t level;
   int isset;
 };
 
@@ -103,7 +103,7 @@ mu_debug_next_handle ()
 }
 
 int
-mu_debug_level_p (int catn, int level)
+mu_debug_level_p (mu_debug_handle_t catn, mu_debug_level_t level)
 {
   return catn < catcnt
     && ((cattab[catn].isset ? cattab[catn].level : cattab[0].level) &
@@ -111,16 +111,16 @@ mu_debug_level_p (int catn, int level)
 }
 
 int
-mu_debug_category_match (int catn, int mask)
+mu_debug_category_match (mu_debug_handle_t catn, mu_debug_level_t mask)
 {
   return catn < catcnt
     && ((cattab[catn].isset ? cattab[catn].level : cattab[0].level) & mask);
 }
 
-static size_t
+static mu_debug_handle_t
 find_category (const char *name, size_t len)
 {
-  size_t i;
+  mu_debug_handle_t i;
 
   for (i = 0; i < catcnt; i++)
     {
@@ -128,14 +128,15 @@ find_category (const char *name, size_t len)
 	  memcmp (cattab[i].name, name, len) == 0)
 	return i;
     }
-  return -1;
+  return (mu_debug_handle_t)-1;
 }
 
 void
-mu_debug_enable_category (const char *catname, size_t catlen, int level)
+mu_debug_enable_category (const char *catname, size_t catlen,
+			  mu_debug_level_t level)
 {
-  size_t catn = find_category (catname, catlen);
-  if (catn == (size_t)-1)
+  mu_debug_handle_t catn = find_category (catname, catlen);
+  if (catn == (mu_debug_handle_t)-1)
     {
       mu_error (_("unknown category: %.*s"), (int) catlen, catname);
       return;
@@ -148,7 +149,7 @@ void
 mu_debug_disable_category (const char *catname, size_t catlen)
 {
   size_t catn = find_category (catname, catlen);
-  if (catn == (size_t)-1)
+  if (catn == (mu_debug_handle_t)-1)
     {
       mu_error (_("unknown category: %.*s"), (int) catlen, catname);
       return;
@@ -157,14 +158,15 @@ mu_debug_disable_category (const char *catname, size_t catlen)
 }
 
 int
-mu_debug_category_level (const char *catname, size_t catlen, int *plev)
+mu_debug_category_level (const char *catname, size_t catlen,
+			 mu_debug_level_t *plev)
 {
-  size_t catn;
+  mu_debug_handle_t catn;
 
   if (catname)
     {
       catn = find_category (catname, catlen);
-      if (catn == (size_t)-1) 
+      if (catn == (mu_debug_handle_t)-1) 
 	return MU_ERR_NOENT;
     }
   else
@@ -174,7 +176,7 @@ mu_debug_category_level (const char *catname, size_t catlen, int *plev)
 }
 
 void
-mu_debug_set_category_level (int catn, int level)
+mu_debug_set_category_level (mu_debug_handle_t catn, mu_debug_level_t level)
 {
   if (catn < catcnt)
     {
@@ -189,7 +191,7 @@ static void
 parse_spec (const char *spec)
 {
   char *q;
-  int level;
+  mu_debug_level_t level;
 
   if (mu_isdigit (*spec))
     {

@@ -110,6 +110,7 @@ _base64_decoder (void *xd MU_ARG_UNUSED,
 		 enum mu_filter_command cmd,
 		 struct mu_filter_io *iobuf)
 {
+  enum mu_filter_result result = mu_filter_ok;
   int i = 0, tmp = 0, pad = 0;
   size_t consumed = 0;
   unsigned char data[4];
@@ -165,14 +166,18 @@ _base64_decoder (void *xd MU_ARG_UNUSED,
       else
 	{
 	  /* I did not get all the data.  */
-	  consumed -= i;
+	  if (cmd != mu_filter_lastbuf)
+	    {
+	      consumed -= i;
+	      result = mu_filter_again;
+	    }
 	  break;
 	}
       i = 0;
     }
   iobuf->isize = consumed;
   iobuf->osize = nbytes;
-  return mu_filter_ok;
+  return result;
 }
 
 enum base64_state

@@ -688,7 +688,7 @@ _run_entry (void *item, void *data)
 		if (mu_debug_level_p (MU_DEBCAT_ACL, MU_DEBUG_TRACE9))
 		  {
 		    debug_sockaddr (rp->sa, rp->salen);
-		    mu_debug_log_end ("");
+		    mu_debug_log_nl ();
 		  }
 	      }
 	  }

@@ -1202,16 +1202,21 @@ mu_stream_truncate (mu_stream_t stream, mu_off_t size)
 int
 mu_stream_shutdown (mu_stream_t stream, int how)
 {
+  int rc;
+  
   if (!(stream->flags & _MU_STR_OPEN))
     {
       if (stream->open)
 	return MU_ERR_NOT_OPEN;
       _stream_init (stream);
     }
-  
+
+  rc = mu_stream_flush (stream);
+  if (rc)
+    return rc;
   if (stream->shutdown)
     return stream->shutdown (stream, how);
-  return ENOSYS;
+  return 0;
 }
 
 int

@@ -26,6 +26,15 @@ mu_list_t mu_sieve_include_path = NULL;
 mu_list_t mu_sieve_library_path = NULL;
 mu_list_t mu_sieve_library_path_prefix = NULL;
 
+mu_debug_handle_t mu_sieve_debug_handle;
+
+void
+mu_sieve_debug_init ()
+{
+  if (!mu_sieve_debug_handle)
+    mu_sieve_debug_handle = mu_debug_register_category ("sieve");
+}
+
 static int
 _path_append (void *item, void *data)
 {
@@ -65,5 +74,6 @@ mu_sieve_module_init (enum mu_gocs_op op, void *data)
   mu_list_destroy (&p->library_path);
   mu_list_destroy (&p->library_path_prefix);
   mu_list_destroy (&p->include_path);
+  mu_sieve_debug_init ();
   return 0;
 }

@@ -45,7 +45,7 @@ static int
 spamd_connect_tcp (mu_sieve_machine_t mach, mu_stream_t *stream,
 		   char *host, int port)
 {
-  int rc = mu_tcp_stream_create (stream, host, port, 0);
+  int rc = mu_tcp_stream_create (stream, host, port, MU_STREAM_RDWR);
   if (rc)
     {
       mu_sieve_error (mach, "mu_tcp_stream_create: %s", mu_strerror (rc));
@@ -57,7 +57,7 @@ spamd_connect_tcp (mu_sieve_machine_t mach, mu_stream_t *stream,
 static int
 spamd_connect_socket (mu_sieve_machine_t mach, mu_stream_t *stream, char *path)
 {
-  int rc = mu_socket_stream_create (stream, path, 0);
+  int rc = mu_socket_stream_create (stream, path, MU_STREAM_RDWR);
   if (rc)
     {
       mu_sieve_error (mach, "mu_socket_stream_create: %s", mu_strerror (rc));
@@ -91,7 +91,12 @@ spamd_send_message (mu_stream_t stream, mu_message_t msg)
 {
   int rc;
   mu_stream_t mstr, flt;
-
+  struct mu_buffer_query newbuf, oldbuf;
+  int bufchg = 0;
+  mu_debug_handle_t dlev;
+  int xlev;
+  int xlevchg = 0;
+  
   rc = mu_message_get_streamref (msg, &mstr);
   if (rc)
     return rc;
@@ -103,47 +108,60 @@ spamd_send_message (mu_stream_t stream, mu_message_t msg)
       return rc;
     }
 
+  /* Ensure effective transport buffering */
+  if (mu_stream_ioctl (stream, MU_IOCTL_TRANSPORT_BUFFER,
+		       MU_IOCTL_OP_GET, &oldbuf) == 0)
+    {
+      newbuf.type = MU_TRANSPORT_OUTPUT;
+      newbuf.buftype = mu_buffer_full;
+      newbuf.bufsize = 64*1024;
+      mu_stream_ioctl (stream, MU_IOCTL_TRANSPORT_BUFFER, MU_IOCTL_OP_SET, 
+		       &newbuf);
+      bufchg = 1;
+    }
+
+  if (mu_debug_category_level ("sieve", 5, &dlev) == 0 &&
+      !(dlev & MU_DEBUG_LEVEL_MASK (MU_DEBUG_TRACE9)))
+    {
+      /* Mark out the following data as payload */
+      xlev = MU_XSCRIPT_PAYLOAD;
+      if (mu_stream_ioctl (stream, MU_IOCTL_XSCRIPTSTREAM,
+			   MU_IOCTL_XSCRIPTSTREAM_LEVEL, &xlev) == 0)
+	xlevchg = 1;
+    }
+  
   rc = mu_stream_copy (stream, flt, 0, NULL);
 
+  /* Restore prior transport buffering and xscript level */
+  if (bufchg)
+    mu_stream_ioctl (stream, MU_IOCTL_TRANSPORT_BUFFER, MU_IOCTL_OP_SET, 
+		     &oldbuf);
+  if (xlevchg)
+    mu_stream_ioctl (stream, MU_IOCTL_XSCRIPTSTREAM,
+		     MU_IOCTL_XSCRIPTSTREAM_LEVEL, &xlev);
+  
   mu_stream_destroy (&mstr);
   mu_stream_destroy (&flt);
   return rc;
 }
 
-static size_t
-spamd_read_line (mu_sieve_machine_t mach, mu_stream_t stream,
-		 char *buffer, size_t size, size_t *pn)
-{
-  size_t n = 0;
-  int rc = mu_stream_readline (stream, buffer, size, &n);
-  if (rc == 0)
-    {
-      if (pn)
-	*pn = n;
-      while (n > 0 && (buffer[n-1] == '\r' || buffer[n-1] == '\n'))
-	n--;
-      buffer[n] = 0;
-      if (mu_sieve_get_debug_level (mach) & MU_SIEVE_DEBUG_TRACE)
-	mu_sieve_debug (mach, ">> %s\n", buffer);
-    }
-  return rc;
-}
-
 #define char_to_num(c) (c-'0')
 
 static void
-decode_float (long *vn, char *str, int digits)
+decode_float (long *vn, const char *str, int digits, char **endp)
 {
   long v;
   size_t frac = 0;
   size_t base = 1;
   int i;
   int negative = 0;
+  char *end;
   
   for (i = 0; i < digits; i++)
     base *= 10;
   
-  v = strtol (str, &str, 10);
+  v = strtol (str, &end, 10);
+  str = end;
   if (v < 0)
     {
       negative = 1;
@@ -153,12 +171,16 @@ decode_float (long *vn, char *str, int digits)
   v *= base;
   if (*str == '.')
     {
-      for (str++, i = 0; *str && i < digits; i++, str++)
+      for (str++, i = 0; *str && mu_isdigit (*str) && i < digits;
+	   i++, str++)
 	frac = frac * 10 + char_to_num (*str);
-      if (*str)
+      if (*str && mu_isdigit (*str))
 	{
 	  if (char_to_num (*str) >= 5)
 	    frac++;
+	  if (endp)
+	    while (*str && mu_isdigit (*str))
+	      str++;
 	}
       else
 	for (; i < digits; i++)
@@ -167,6 +189,8 @@ decode_float (long *vn, char *str, int digits)
   *vn = v + frac;
   if (negative)
     *vn = - *vn;
+  if (endp)
+    *endp = (char*) str;
 }
 
 static int
@@ -209,6 +233,7 @@ spamd_abort (mu_sieve_machine_t mach, mu_stream_t *stream, signal_handler handle
 }
 
 static int got_sigpipe;
+static signal_handler handler;
 
 static RETSIGTYPE
 sigpipe_handler (int sig MU_ARG_UNUSED)
@@ -216,6 +241,60 @@ sigpipe_handler (int sig MU_ARG_UNUSED)
   got_sigpipe = 1;
 }
 
+static void
+spamd_read_line (mu_sieve_machine_t mach, mu_stream_t stream,
+		 char **pbuffer, size_t *psize)
+{
+  size_t n;
+  int rc = mu_stream_getline (stream, pbuffer, psize, &n);
+  if (rc == 0)
+    mu_rtrim_cset (*pbuffer, "\r\n");
+  else
+    {
+      /* FIXME: Need an 'onabort' mechanism in Sieve machine, which
+	 would restore the things to their prior state.  This will
+	 also allow to make handler local again. */
+      free (pbuffer);
+      mu_sieve_error (mach, "read error: %s", mu_strerror (rc));
+      spamd_abort (mach, &stream, handler);
+    }
+}
+
+static int
+parse_response_line (mu_sieve_machine_t mach, const char *buffer)
+{
+  const char *str;
+  char *end;
+  long version;
+  unsigned long resp;
+  
+  str = buffer;
+  if (strncmp (str, "SPAMD/", 6))
+    return MU_ERR_BADREPLY;
+  str += 6;
+
+  decode_float (&version, str, 1, &end);
+  if (version < 10)
+    {
+      mu_sieve_error (mach, _("unsupported SPAMD version: %s"), str);
+      return MU_ERR_BADREPLY;
+    }
+
+  str = mu_str_skip_class (end, MU_CTYPE_SPACE);
+  if (!*str || !mu_isdigit (*str))
+    {
+      mu_sieve_error (mach, _("malformed spamd response: %s"), buffer);
+      return MU_ERR_BADREPLY;
+    }
+
+  resp = strtoul (str, &end, 10);
+  if (resp != 0)
+    {
+      mu_sieve_error (mach, _("spamd failure: %lu %s"), resp, end);
+      return MU_ERR_REPLY;
+    }
+  return 0;
+}
 
 /* The test proper */
 
@@ -246,20 +325,19 @@ sigpipe_handler (int sig MU_ARG_UNUSED)
 static int
 spamd_test (mu_sieve_machine_t mach, mu_list_t args, mu_list_t tags)
 {
-  char buffer[512];
-  char version_str[19];
+  char *buffer = NULL;
+  size_t size = 0;
   char spam_str[6], score_str[21], threshold_str[21];
-  int response, rc;
-  long version;
+  int rc;
   int result;
   long score, threshold, limit;
-  mu_stream_t stream = NULL;
+  mu_stream_t stream = NULL, null;
   mu_sieve_value_t *arg;
   mu_message_t msg;
-  size_t m_size, m_lines, size;
-  signal_handler handler;
+  size_t m_size, m_lines;
   char *host;
   mu_header_t hdr;
+  mu_debug_handle_t lev = 0;
   
   if (mu_sieve_get_debug_level (mach) & MU_SIEVE_DEBUG_TRACE)
     {
@@ -284,11 +362,37 @@ spamd_test (mu_sieve_machine_t mach, mu_list_t args, mu_list_t tags)
   if (result) /* spamd_connect_ already reported error */
     mu_sieve_abort (mach);
 
+  mu_stream_set_buffer (stream, mu_buffer_line, 0);
+  if (mu_debug_category_level ("sieve", 5, &lev) == 0 &&
+      (lev & MU_DEBUG_LEVEL_MASK (MU_DEBUG_PROT)))
+    {
+      int rc;
+      mu_stream_t dstr, xstr;
+      
+      rc = mu_dbgstream_create (&dstr, MU_DIAG_DEBUG);
+      if (rc)
+	mu_error (_("cannot create debug stream; transcript disabled: %s"),
+		  mu_strerror (rc));
+      else
+	{
+	  rc = mu_xscript_stream_create (&xstr, stream, dstr, NULL);
+	  if (rc)
+	    mu_error (_("cannot create transcript stream: %s"),
+		      mu_strerror (rc));
+	  else
+	    {
+	      mu_stream_unref (stream);
+	      stream = xstr;
+	    }
+	}
+    }
+
   msg = mu_sieve_get_message (mach);
   mu_message_size (msg, &m_size);
   mu_message_lines (msg, &m_lines);
 
   spamd_send_command (stream, "SYMBOLS SPAMC/1.2");
+  
   spamd_send_command (stream, "Content-length: %lu",
 		      (u_long) (m_size + m_lines));
   if (mu_sieve_tag_lookup (tags, "user", &arg))
@@ -307,7 +411,7 @@ spamd_test (mu_sieve_machine_t mach, mu_list_t args, mu_list_t tags)
   spamd_send_message (stream, msg);
   mu_stream_shutdown (stream, MU_STREAM_WRITE);
 
-  spamd_read_line (mach, stream, buffer, sizeof buffer, NULL);
+  spamd_read_line (mach, stream, &buffer, &size);
 
   if (got_sigpipe)
     {
@@ -315,25 +419,10 @@ spamd_test (mu_sieve_machine_t mach, mu_list_t args, mu_list_t tags)
       spamd_abort (mach, &stream, handler);
     }
 
-  if (sscanf (buffer, "SPAMD/%18s %d %*s", version_str, &response) != 2)
-    {
-      mu_sieve_error (mach, _("spamd responded with bad string '%s'"), buffer);
-      spamd_abort (mach, &stream, handler);
-    }
+  if (parse_response_line (mach, buffer))
+    spamd_abort (mach, &stream, handler);
   
-  decode_float (&version, version_str, 1);
-  if (version < 10)
-    {
-      mu_sieve_error (mach, _("unsupported SPAMD version: %s"), version_str);
-      spamd_abort (mach, &stream, handler);
-    }
-
-  /*
-  if (response)
-    ...
-  */
-  
-  spamd_read_line (mach, stream, buffer, sizeof buffer, NULL);
+  spamd_read_line (mach, stream, &buffer, &size);
   if (sscanf (buffer, "Spam: %5s ; %20s / %20s",
 	      spam_str, score_str, threshold_str) != 3)
     {
@@ -344,27 +433,27 @@ spamd_test (mu_sieve_machine_t mach, mu_list_t args, mu_list_t tags)
 
   result = decode_boolean (spam_str);
   score = strtoul (score_str, NULL, 10);
-  decode_float (&score, score_str, 3);
-  decode_float (&threshold, threshold_str, 3);
+  decode_float (&score, score_str, 3, NULL);
+  decode_float (&threshold, threshold_str, 3, NULL);
 
   if (!result)
     {
       if (mu_sieve_tag_lookup (tags, "over", &arg))
 	{
-	  decode_float (&limit, arg->v.string, 3);
+	  decode_float (&limit, arg->v.string, 3, NULL);
 	  result = score >= limit;
 	}
       else if (mu_sieve_tag_lookup (tags, "under", &arg))
 	{
-	  decode_float (&limit, arg->v.string, 3);
+	  decode_float (&limit, arg->v.string, 3, NULL);
 	  result = score <= limit;	  
 	}
     }
   
   /* Skip newline */
-  spamd_read_line (mach, stream, buffer, sizeof buffer, NULL);
+  spamd_read_line (mach, stream, &buffer, &size);
   /* Read symbol list */
-  spamd_read_line (mach, stream, buffer, sizeof buffer, &size);
+  spamd_read_line (mach, stream, &buffer, &size);
 
   rc = mu_message_get_header (msg, &hdr);
   if (rc)
@@ -379,11 +468,22 @@ spamd_test (mu_sieve_machine_t mach, mu_list_t args, mu_list_t tags)
   mu_header_append (hdr, "X-Spamd-Threshold", threshold_str);
   mu_header_append (hdr, "X-Spamd-Keywords", buffer);
 
-  while (spamd_read_line (mach, stream, buffer, sizeof buffer, &size) == 0
-	 && size > 0)
-    /* Drain input */;
-  
-  spamd_destroy (&stream);
+  free (buffer);
+
+  /* Create a data sink */
+  mu_nullstream_create (&null, MU_STREAM_WRITE);
+
+  /* Mark out the following data as payload */
+  if (!(lev & MU_DEBUG_LEVEL_MASK (MU_DEBUG_TRACE9)))
+    {
+      int xlev = MU_XSCRIPT_PAYLOAD;
+      mu_stream_ioctl (stream, MU_IOCTL_XSCRIPTSTREAM,
+		       MU_IOCTL_XSCRIPTSTREAM_LEVEL, &xlev);
+    }
+  mu_stream_copy (null, stream, 0, NULL);
+  mu_stream_destroy (&null);
+  mu_stream_destroy (&stream);
+
   set_signal_handler (SIGPIPE, handler);
 
   return result;

@@ -349,7 +349,8 @@ mu_sieve_machine_init_ex (mu_sieve_machine_t *pmach,
 {
   int rc;
   mu_sieve_machine_t mach;
-  
+
+  mu_sieve_debug_init ();
   mach = malloc (sizeof (*mach));
   if (!mach)
     return ENOMEM;

@@ -181,6 +181,7 @@ parser (int key, char *arg, struct argp_state *state)
       
     case 'n':
       sieve_debug |= MU_SIEVE_DRY_RUN;
+      mu_argp_node_list_new (lst, "verbose", "yes");
       break;
 
     case 'k':
@@ -451,7 +452,8 @@ main (int argc, char *argv[])
   mu_gocs_register ("tls", mu_tls_module_init);
 #endif
   mu_gocs_register ("sieve", mu_sieve_module_init);
-
+  mu_sieve_debug_init ();
+  
   mu_register_all_formats ();
 
   debug_level = MU_DEBUG_LEVEL_MASK (MU_DEBUG_ERROR);