[geary] Additional debug logging at app shutdown for bug #745561

[Jim Nelson <jnelson src gnome org>]

commit 7494fa57d2307379842334042b312f406632277c
Author: Jim Nelson <jim yorba org>
Date:   Thu Mar 5 15:55:05 2015 -0800

    Additional debug logging at app shutdown for bug #745561
    
    Hopefully these messages will give us some idea where in the shutdown
    code the application sometimes hangs.

 src/client/application/geary-controller.vala       |   24 +++++++++++++++++--
 src/engine/api/geary-abstract-local-folder.vala    |    6 +++-
 src/engine/api/geary-folder.vala                   |    9 +++++--
 src/engine/app/app-conversation-monitor.vala       |   12 +++++++--
 .../imap-engine/imap-engine-minimal-folder.vala    |   12 ++++++---
 .../replay-ops/imap-engine-user-close.vala         |    4 ++-
 6 files changed, 51 insertions(+), 16 deletions(-)
---
diff --git a/src/client/application/geary-controller.vala b/src/client/application/geary-controller.vala
index c60574c..740ee78 100644
--- a/src/client/application/geary-controller.vala
+++ b/src/client/application/geary-controller.vala
@@ -269,14 +269,21 @@ public class GearyController : Geary.BaseObject {
         // close the ConversationMonitor
         try {
             if (current_conversations != null) {
-                yield current_conversations.stop_monitoring_async(null);
+                debug("Stopping conversation monitor for %s...", current_conversations.folder.to_string());
+                
+                bool closing = yield current_conversations.stop_monitoring_async(null);
                 
                 // If not an Inbox, wait for it to close so all pending operations are flushed
-                if (!inboxes.values.contains(current_conversations.folder))
+                if (closing) {
+                    debug("Waiting for %s to close...", current_conversations.folder.to_string());
                     yield current_conversations.folder.wait_for_close_async(null);
+                }
+                
+                debug("Stopped conversation monitor for %s", current_conversations.folder.to_string());
             }
         } catch (Error err) {
-            message("Error closing conversation at shutdown: %s", err.message);
+            message("Error closing conversation monitor %s at shutdown: %s",
+                current_conversations.folder.to_string(), err.message);
         } finally {
             current_conversations = null;
         }
@@ -284,9 +291,16 @@ public class GearyController : Geary.BaseObject {
         // close all Inboxes
         foreach (Geary.Folder inbox in inboxes.values) {
             try {
+                debug("Closing %s...", inbox.to_string());
+                
                 // close and wait for all pending operations to be flushed
                 yield inbox.close_async(null);
+                
+                debug("Waiting for %s to close completely...", inbox.to_string());
+                
                 yield inbox.wait_for_close_async(null);
+                
+                debug("Closed %s", inbox.to_string());
             } catch (Error err) {
                 message("Error closing Inbox %s at shutdown: %s", inbox.to_string(), err.message);
             }
@@ -295,7 +309,9 @@ public class GearyController : Geary.BaseObject {
         // close all Accounts
         foreach (Geary.Account account in email_stores.keys) {
             try {
+                debug("Closing account %s", account.to_string());
                 yield account.close_async(null);
+                debug("Closed account %s", account.to_string());
             } catch (Error err) {
                 message("Error closing account %s at shutdown: %s", account.to_string(), err.message);
             }
@@ -305,7 +321,9 @@ public class GearyController : Geary.BaseObject {
         
         // Turn off the lights and lock the door behind you
         try {
+            debug("Closing Engine...");
             yield Geary.Engine.instance.close_async(null);
+            debug("Closed Engine");
         } catch (Error err) {
             message("Error closing Geary Engine instance: %s", err.message);
         }
diff --git a/src/engine/api/geary-abstract-local-folder.vala b/src/engine/api/geary-abstract-local-folder.vala
index 05a062f..74f1add 100644
--- a/src/engine/api/geary-abstract-local-folder.vala
+++ b/src/engine/api/geary-abstract-local-folder.vala
@@ -47,14 +47,16 @@ public abstract class Geary.AbstractLocalFolder : Geary.Folder {
         return true;
     }
     
-    public override async void close_async(Cancellable? cancellable = null) throws Error {
+    public override async bool close_async(Cancellable? cancellable = null) throws Error {
         if (open_count == 0 || --open_count > 0)
-            return;
+            return false;
         
         closed_semaphore.blind_notify();
         
         notify_closed(Geary.Folder.CloseReason.LOCAL_CLOSE);
         notify_closed(Geary.Folder.CloseReason.FOLDER_CLOSED);
+        
+        return false;
     }
     
     public override async void wait_for_close_async(Cancellable? cancellable = null) throws Error {
diff --git a/src/engine/api/geary-folder.vala b/src/engine/api/geary-folder.vala
index 7b213c3..bb8abe8 100644
--- a/src/engine/api/geary-folder.vala
+++ b/src/engine/api/geary-folder.vala
@@ -452,12 +452,15 @@ public abstract class Geary.Folder : BaseObject {
      * tearing down network connections, closing files, and so forth.  See "closed" for signals
      * indicating the closing states.
      *
-     * If the Folder is already closed, the method silently returns.
+     * Returns true if the open count decrements to zero and the folder is ''closing''.  Use
+     * { link wait_for_close_async} to block until the folder is completely closed.  Otherwise,
+     * returns false.  Note that this semantic is slightly different than the result code for
+     * { link open_async}.
      */
-    public abstract async void close_async(Cancellable? cancellable = null) throws Error;
+    public abstract async bool close_async(Cancellable? cancellable = null) throws Error;
     
     /**
-     * Wait for the Folder to fully close.
+     * Wait for the { link Folder} to fully close.
      *
      * Unlike { link wait_for_open_async}, this will ''always'' block until a { link Folder} is
      * closed, even if it's not open.
diff --git a/src/engine/app/app-conversation-monitor.vala b/src/engine/app/app-conversation-monitor.vala
index 5baac5c..12ca9d8 100644
--- a/src/engine/app/app-conversation-monitor.vala
+++ b/src/engine/app/app-conversation-monitor.vala
@@ -320,10 +320,13 @@ public class Geary.App.ConversationMonitor : BaseObject {
      * supplied to start_monitoring_async() is used during monitoring but *not* for this method.
      * If null is supplied as the Cancellable, no cancellable is used; pass the original Cancellable
      * here to use that.
+     *
+     * Returns a result code that is semantically identical to the result of
+     * { link Geary.Folder.close_async}.
      */
-    public async void stop_monitoring_async(Cancellable? cancellable) throws Error {
+    public async bool stop_monitoring_async(Cancellable? cancellable) throws Error {
         if (!is_monitoring)
-            return;
+            return false;
         
         yield operation_queue.stop_processing_async(cancellable);
         
@@ -337,9 +340,10 @@ public class Geary.App.ConversationMonitor : BaseObject {
         folder.account.email_flags_changed.disconnect(on_account_email_flags_changed);
         folder.account.email_locally_complete.disconnect(on_account_email_locally_complete);
         
+        bool closing = false;
         Error? close_err = null;
         try {
-            yield folder.close_async(cancellable);
+            closing = yield folder.close_async(cancellable);
         } catch (Error err) {
             // throw, but only after cleaning up (which is to say, if close_async() fails,
             // then the Folder is still treated as closed, which is the best that can be
@@ -353,6 +357,8 @@ public class Geary.App.ConversationMonitor : BaseObject {
         
         if (close_err != null)
             throw close_err;
+        
+        return closing;
     }
     
     /**
diff --git a/src/engine/imap-engine/imap-engine-minimal-folder.vala 
b/src/engine/imap-engine/imap-engine-minimal-folder.vala
index c8e460e..9759d9c 100644
--- a/src/engine/imap-engine/imap-engine-minimal-folder.vala
+++ b/src/engine/imap-engine/imap-engine-minimal-folder.vala
@@ -774,25 +774,27 @@ private class Geary.ImapEngine.MinimalFolder : Geary.Folder, Geary.FolderSupport
         notify_opened(Geary.Folder.OpenState.BOTH, remote_count);
     }
     
-    public override async void close_async(Cancellable? cancellable = null) throws Error {
+    public override async bool close_async(Cancellable? cancellable = null) throws Error {
         // Check open_count but only decrement inside of replay queue
         if (open_count <= 0)
-            return;
+            return false;
         
         UserClose user_close = new UserClose(this, cancellable);
         replay_queue.schedule(user_close);
         
         yield user_close.wait_for_ready_async(cancellable);
+        
+        return user_close.closing;
     }
     
     public override async void wait_for_close_async(Cancellable? cancellable = null) throws Error {
         yield closed_semaphore.wait_async(cancellable);
     }
     
-    internal async void user_close_async(Cancellable? cancellable) {
+    internal async bool user_close_async(Cancellable? cancellable) {
         // decrement open_count and, if zero, continue closing Folder
         if (open_count == 0 || --open_count > 0)
-            return;
+            return false;
         
         if (remote_folder != null)
             _properties.remove(remote_folder.properties);
@@ -803,6 +805,8 @@ private class Geary.ImapEngine.MinimalFolder : Geary.Folder, Geary.FolderSupport
         // don't yield here, close_internal_async() needs to be called outside of the replay queue
         // the open_count protects against this path scheduling it more than once
         close_internal_async.begin(CloseReason.LOCAL_CLOSE, CloseReason.REMOTE_CLOSE, true, cancellable);
+        
+        return true;
     }
     
     // Close the remote connection and, if open_count is zero, the Folder itself.  A Mutex is used
diff --git a/src/engine/imap-engine/replay-ops/imap-engine-user-close.vala 
b/src/engine/imap-engine/replay-ops/imap-engine-user-close.vala
index 96474cb..00a53b8 100644
--- a/src/engine/imap-engine/replay-ops/imap-engine-user-close.vala
+++ b/src/engine/imap-engine/replay-ops/imap-engine-user-close.vala
@@ -5,6 +5,8 @@
  */
 
 private class Geary.ImapEngine.UserClose : Geary.ImapEngine.ReplayOperation {
+    public bool closing = false;
+    
     private MinimalFolder owner;
     private Cancellable? cancellable;
     
@@ -25,7 +27,7 @@ private class Geary.ImapEngine.UserClose : Geary.ImapEngine.ReplayOperation {
     }
     
     public override async ReplayOperation.Status replay_local_async() throws Error {
-        yield owner.user_close_async(cancellable);
+        closing = yield owner.user_close_async(cancellable);
         
         return ReplayOperation.Status.COMPLETED;
     }