[FTP] improve debugging

- print LIST replies again
- make connections have a debug id and use it for debugging prints

6 files changed, 39 insertions, 32 deletions

diff --git a/daemon/gvfsbackendftp.c b/daemon/gvfsbackendftp.c
index 847266e1..4b7f8b97 100644
--- a/daemon/gvfsbackendftp.c
+++ b/daemon/gvfsbackendftp.c
@@ -108,7 +108,7 @@ gvfs_backend_ftp_determine_features (GVfsFtpTask *task)
 	{
 	  if (g_ascii_strcasecmp (feature, features[j].name) == 0)
 	    {
-	      DEBUG ("feature %s supported\n", features[j].name);
+	      g_debug ("# feature %s supported\n", features[j].name);
 	      task->backend->features |= 1 << features[j].enable;
 	    }
 	}
@@ -125,10 +125,11 @@ gvfs_backend_ftp_determine_system (GVfsFtpTask *task)
   static const struct {
     const char *  id;
     GVfsFtpSystem system;
+    const char *  debug_name;
   } known_systems[] = {
     /* NB: the first entry that matches is taken, so order matters */
-    { "UNIX ", G_VFS_FTP_SYSTEM_UNIX },
-    { "WINDOWS_NT ", G_VFS_FTP_SYSTEM_WINDOWS }
+    { "UNIX ", G_VFS_FTP_SYSTEM_UNIX, "Unix"},
+    { "WINDOWS_NT ", G_VFS_FTP_SYSTEM_WINDOWS, "Windows NT" }
   };
   guint i;
   char *system_name;
@@ -151,7 +152,7 @@ gvfs_backend_ftp_determine_system (GVfsFtpTask *task)
 			       strlen (known_systems[i].id)) == 0)
 	{
 	  task->backend->system = known_systems[i].system;
-	  DEBUG ("system is %u\n", task->backend->system);
+	  g_debug ("# system is %s\n", known_systems[i].debug_name);
 	  break;
 	}
     }
@@ -427,7 +428,7 @@ try_login:
       ftp->addr = G_SOCKET_CONNECTABLE (g_vfs_ftp_connection_get_address (task.conn, &task.error));
       if (ftp->addr == NULL)
         {
-          DEBUG ("error querying remote address: %s\nUsing original address instead.", task.error->message);
+          g_debug ("# error querying remote address: %s\nUsing original address instead.", task.error->message);
           g_vfs_ftp_task_clear_error (&task);
           ftp->addr = g_object_ref (addr);
         }
diff --git a/daemon/gvfsftpconnection.c b/daemon/gvfsftpconnection.c
index d6b1274a..9756e37f 100644
--- a/daemon/gvfsftpconnection.c
+++ b/daemon/gvfsftpconnection.c
@@ -27,6 +27,9 @@
 
 #include "gvfsftpconnection.h"
 
+/* used for identifying the connection during debugging */
+static volatile int debug_id = 0;
+
 struct _GVfsFtpConnection
 {
   GSocketClient *       client;                 /* socket client used for opening connections */
@@ -35,6 +38,8 @@ struct _GVfsFtpConnection
   GDataInputStream *    commands_in;            /* wrapper around in stream to allow line-wise reading */
 
   GIOStream *		data;                   /* ftp data stream or NULL if not in use */
+
+  int                   debug_id;               /* unique id for debugging purposes */
 };
 
 GVfsFtpConnection *
@@ -48,6 +53,7 @@ g_vfs_ftp_connection_new (GSocketConnectable *addr,
 
   conn = g_slice_new0 (GVfsFtpConnection);
   conn->client = g_socket_client_new ();
+  conn->debug_id = g_atomic_int_exchange_and_add (&debug_id, 1);
   conn->commands = G_IO_STREAM (g_socket_client_connect (conn->client,
                                                          addr,
                                                          cancellable,
@@ -93,6 +99,11 @@ g_vfs_ftp_connection_send (GVfsFtpConnection *conn,
     len = strlen (command);
   g_return_val_if_fail (command[len-2] == '\r' && command[len-1] == '\n', FALSE);
 
+  if (g_str_has_prefix (command, "PASS"))
+    g_debug ("--%2d ->  PASS ***\r\n", conn->debug_id);
+  else
+    g_debug ("--%2d ->  %s", conn->debug_id, command);
+
   return g_output_stream_write_all (g_io_stream_get_output_stream (conn->commands),
                                     command,
                                     len,
@@ -135,7 +146,7 @@ g_vfs_ftp_connection_receive (GVfsFtpConnection *conn,
           goto fail;
         }
 
-      DEBUG ("<-- %s\n", line);
+      g_debug ("<-%2d --  %s\r\n", conn->debug_id, line);
       if (lines)
         g_ptr_array_add (lines, line);
 
@@ -230,6 +241,7 @@ g_vfs_ftp_connection_close_data_connection (GVfsFtpConnection *conn)
 /**
  * g_vfs_ftp_connection_get_data_stream:
  * @conn: a connection
+ * @debug_id: %NULL or pointer taking id to use for debugging purposes
  *
  * Gets the data stream in use by @conn. It is an error to call this function
  * when no data stream exists. Be sure to check the return value of
@@ -238,11 +250,13 @@ g_vfs_ftp_connection_close_data_connection (GVfsFtpConnection *conn)
  * Returns: the data stream of @conn
  **/
 GIOStream *
-g_vfs_ftp_connection_get_data_stream (GVfsFtpConnection *conn)
+g_vfs_ftp_connection_get_data_stream (GVfsFtpConnection *conn, int *debug_id)
 {
   g_return_val_if_fail (conn != NULL, NULL);
   g_return_val_if_fail (conn->data != NULL, NULL);
 
+  if (debug_id)
+    *debug_id = conn->debug_id;
   return conn->data;
 }
 
diff --git a/daemon/gvfsftpconnection.h b/daemon/gvfsftpconnection.h
index 4fbc91be..7fd33870 100644
--- a/daemon/gvfsftpconnection.h
+++ b/daemon/gvfsftpconnection.h
@@ -27,14 +27,6 @@
 
 G_BEGIN_DECLS
 
-#define PRINT_DEBUG
-
-#ifdef PRINT_DEBUG
-#define DEBUG g_print
-#else
-#define DEBUG(...)
-#endif
-
 
 typedef struct _GVfsFtpConnection GVfsFtpConnection;
 
@@ -64,7 +56,8 @@ gboolean                g_vfs_ftp_connection_open_data_connection
                                                                GError **                error);
 void                    g_vfs_ftp_connection_close_data_connection
                                                               (GVfsFtpConnection *      conn);
-GIOStream *             g_vfs_ftp_connection_get_data_stream  (GVfsFtpConnection *      conn);
+GIOStream *             g_vfs_ftp_connection_get_data_stream  (GVfsFtpConnection *      conn,
+                                                               int *                    debug_id);
 gssize                  g_vfs_ftp_connection_write_data       (GVfsFtpConnection *      conn,
                                                                const char *             data,
                                                                gsize                    len,
diff --git a/daemon/gvfsftpdircache.c b/daemon/gvfsftpdircache.c
index d5082780..f77635e4 100644
--- a/daemon/gvfsftpdircache.c
+++ b/daemon/gvfsftpdircache.c
@@ -138,6 +138,8 @@ g_vfs_ftp_dir_cache_lookup_entry (GVfsFtpDirCache *  cache,
                                   guint              stamp)
 {
   GVfsFtpDirCacheEntry *entry;
+  GIOStream *stream;
+  int debug_id;
 
   g_mutex_lock (cache->lock);
   entry = g_hash_table_lookup (cache->directories, dir);
@@ -166,7 +168,9 @@ g_vfs_ftp_dir_cache_lookup_entry (GVfsFtpDirCache *  cache,
     return NULL;
 
   entry = g_vfs_ftp_dir_cache_entry_new (stamp);
-  cache->funcs->process (g_io_stream_get_input_stream (g_vfs_ftp_connection_get_data_stream (task->conn)),
+  stream = g_vfs_ftp_connection_get_data_stream (task->conn, &debug_id);
+  cache->funcs->process (g_io_stream_get_input_stream (stream),
+                         debug_id,
                          dir,
                          entry,
                          task->cancellable,
@@ -407,6 +411,7 @@ g_vfs_ftp_dir_cache_purge_file (GVfsFtpDirCache *  cache,
 
 static gboolean
 g_vfs_ftp_dir_cache_funcs_process (GInputStream *        stream,
+                                   int                   debug_id,
                                    const GVfsFtpFile *   dir,
                                    GVfsFtpDirCacheEntry *entry,
                                    gboolean              is_unix,
@@ -432,6 +437,7 @@ g_vfs_ftp_dir_cache_funcs_process (GInputStream *        stream,
       struct list_result result = { 0, };
       GTimeVal tv = { 0, 0 };
 
+      g_debug ("<<%2d <<  %s\n", debug_id, line);
       type = ParseFTPList (line, &state, &result);
       if (type != 'd' && type != 'f' && type != 'l')
         {
@@ -565,22 +571,24 @@ g_vfs_ftp_dir_cache_funcs_resolve_default (GVfsFtpTask *      task,
 
 static gboolean
 g_vfs_ftp_dir_cache_funcs_process_unix (GInputStream *        stream,
+                                        int                   debug_id,
                                         const GVfsFtpFile *   dir,
                                         GVfsFtpDirCacheEntry *entry,
                                         GCancellable *        cancellable,
                                         GError **             error)
 {
-  return g_vfs_ftp_dir_cache_funcs_process (stream, dir, entry, TRUE, cancellable, error);
+  return g_vfs_ftp_dir_cache_funcs_process (stream, debug_id, dir, entry, TRUE, cancellable, error);
 }
 
 static gboolean
 g_vfs_ftp_dir_cache_funcs_process_default (GInputStream *        stream,
+                                           int                   debug_id,
                                            const GVfsFtpFile *   dir,
                                            GVfsFtpDirCacheEntry *entry,
                                            GCancellable *        cancellable,
                                            GError **             error)
 {
-  return g_vfs_ftp_dir_cache_funcs_process (stream, dir, entry, FALSE, cancellable, error);
+  return g_vfs_ftp_dir_cache_funcs_process (stream, debug_id, dir, entry, FALSE, cancellable, error);
 }
 
 const GVfsFtpDirFuncs g_vfs_ftp_dir_cache_funcs_unix = {
diff --git a/daemon/gvfsftpdircache.h b/daemon/gvfsftpdircache.h
index 5a1237a8..efebec25 100644
--- a/daemon/gvfsftpdircache.h
+++ b/daemon/gvfsftpdircache.h
@@ -36,6 +36,7 @@ typedef struct _GVfsFtpDirCacheEntry GVfsFtpDirCacheEntry;
 struct _GVfsFtpDirFuncs {
   const char *          command;
   gboolean              (* process)                             (GInputStream *         stream,
+                                                                 int                    debug_id,
                                                                  const GVfsFtpFile *    dir,
                                                                  GVfsFtpDirCacheEntry * entry,
                                                                  GCancellable *         cancellable,
diff --git a/daemon/gvfsftptask.c b/daemon/gvfsftptask.c
index c2368174..0a6d4c20 100644
--- a/daemon/gvfsftptask.c
+++ b/daemon/gvfsftptask.c
@@ -235,7 +235,7 @@ g_vfs_ftp_task_acquire_connection (GVfsFtpTask *task)
 	  ftp->max_connections = MIN (ftp->max_connections, maybe_max_connections);
 	  if (ftp->max_connections == 0)
 	    {
-	      DEBUG ("no more connections left, exiting...");
+	      g_debug ("no more connections left, exiting...");
 	      /* FIXME: shut down properly */
 	      exit (0);
 	    }
@@ -600,16 +600,6 @@ retry:
       retry_on_timeout = TRUE;
     }
 
-#ifdef PRINT_DEBUG
-  if (g_str_has_prefix (command->str, "PASS"))
-    DEBUG ("--> PASS ***\n");
-  else
-    {
-      command->str[command->len - 2] = 0;
-      DEBUG ("--> %s\n", command->str);
-      command->str[command->len - 2] = '\r';
-    }
-#endif
   g_vfs_ftp_connection_send (task->conn,
                              command->str,
                              command->len,
@@ -758,7 +748,7 @@ g_vfs_ftp_task_open_data_connection_epsv (GVfsFtpTask *task)
                                                   &task->error))
     {
       g_object_unref (addr);
-      DEBUG ("Successful EPSV response code, but data connection failed. Enabling FTP_WORKAROUND_BROKEN_EPSV.\n");
+      g_debug ("# Successful EPSV response code, but data connection failed. Enabling FTP_WORKAROUND_BROKEN_EPSV.\n");
       g_vfs_backend_ftp_use_workaround (task->backend, G_VFS_FTP_WORKAROUND_BROKEN_EPSV);
       g_vfs_ftp_task_clear_error (task);
       return FALSE;
@@ -828,7 +818,7 @@ g_vfs_ftp_task_open_data_connection_pasv (GVfsFtpTask *task)
          
       g_object_unref (addr);
       /* set workaround flag (see below), so we don't try this again */
-      DEBUG ("Successfull PASV response but data connection failed. Enabling FTP_WORKAROUND_PASV_ADDR.\n");
+      g_debug ("# Successfull PASV response but data connection failed. Enabling FTP_WORKAROUND_PASV_ADDR.\n");
       g_vfs_backend_ftp_use_workaround (task->backend, G_VFS_FTP_WORKAROUND_PASV_ADDR);
       g_vfs_ftp_task_clear_error (task);
     }