From 3ff35bcb679748d8c739fb38eba33a54ff9e128d Mon Sep 17 00:00:00 2001 From: Michael Gratton Date: Sat, 10 Aug 2019 11:26:47 +1000 Subject: [PATCH 1/5] Remove some duplicate debug logging Only log from FSM event handlers, not from connection signal handlers. --- .../imap/transport/imap-client-session.vala | 37 +++++++++++-------- 1 file changed, 21 insertions(+), 16 deletions(-) diff --git a/src/engine/imap/transport/imap-client-session.vala b/src/engine/imap/transport/imap-client-session.vala index c944f3ea..93ef9f33 100644 --- a/src/engine/imap/transport/imap-client-session.vala +++ b/src/engine/imap/transport/imap-client-session.vala @@ -1,7 +1,9 @@ -/* Copyright 2016 Software Freedom Conservancy Inc. +/* + * Copyright 2016 Software Freedom Conservancy Inc. + * Copyright 2019 Michael Gratton * * This software is licensed under the GNU Lesser General Public License - * (version 2.1 or later). See the COPYING file in this distribution. + * (version 2.1 or later). See the COPYING file in this distribution. */ /** @@ -472,7 +474,7 @@ public class Geary.Imap.ClientSession : BaseObject { new Geary.State.Mapping(State.BROKEN, Event.CLOSE_MAILBOX, on_late_command), new Geary.State.Mapping(State.BROKEN, Event.LOGOUT, on_late_command), new Geary.State.Mapping(State.BROKEN, Event.DISCONNECT, Geary.State.nop), - new Geary.State.Mapping(State.BROKEN, Event.DISCONNECTED, Geary.State.nop), + new Geary.State.Mapping(State.BROKEN, Event.DISCONNECTED, on_disconnected), new Geary.State.Mapping(State.BROKEN, Event.RECV_STATUS, on_dropped_response), new Geary.State.Mapping(State.BROKEN, Event.RECV_COMPLETION, on_dropped_response), new Geary.State.Mapping(State.BROKEN, Event.SEND_ERROR, Geary.State.nop), @@ -784,9 +786,23 @@ public class Geary.Imap.ClientSession : BaseObject { } private uint on_connected(uint state, uint event) { - debug("[%s] Connected", to_string()); + debug("[%s] Connected to %s", + to_string(), + imap_endpoint.to_string()); - // stay in current state -- wait for initial status response to move into NOAUTH or LOGGED OUT + // stay in current state -- wait for initial status response + // to move into NOAUTH or LOGGED OUT + return state; + } + + private uint on_disconnected(uint state, + uint event, + void *user = null, + GLib.Object? obj = null, + GLib.Error? err = null) { + debug("[%s] Disconnected from %s", + to_string(), + this.imap_endpoint.to_string()); return state; } @@ -1736,28 +1752,19 @@ public class Geary.Imap.ClientSession : BaseObject { // private void on_network_connected() { - debug("[%s] Connected to %s", to_string(), imap_endpoint.to_string()); - fsm.issue(Event.CONNECTED); } private void on_network_disconnected() { - debug("[%s] Disconnected from %s", to_string(), imap_endpoint.to_string()); - fsm.issue(Event.DISCONNECTED); } private void on_network_sent_command(Command cmd) { -#if VERBOSE_SESSION - debug("[%s] Sent command %s", to_string(), cmd.to_string()); -#endif // resechedule keepalive schedule_keepalive(); } private void on_network_send_error(Error err) { - debug("[%s] Send error: %s", to_string(), err.message); - fsm.issue(Event.SEND_ERROR, null, null, err); } @@ -1908,8 +1915,6 @@ public class Geary.Imap.ClientSession : BaseObject { } private void on_network_receive_failure(Error err) { - debug("[%s] Receive failed: %s", to_string(), err.message); - fsm.issue(Event.RECV_ERROR, null, null, err); } From 5a9944a9df228d3d187e8efebd6f3208c94c3c79 Mon Sep 17 00:00:00 2001 From: Michael Gratton Date: Sat, 10 Aug 2019 11:29:13 +1000 Subject: [PATCH 2/5] Handle Imap.Deserialiser EOS better Ensure that the client connection is disconnected when the deserialiser receives an EOS from its underlying stream. Rename the signal used by Imap.ClientConnection to notify the Imap.ClientSession of EOS to make it more clear what is going on. Resolves the issue in #481 where an EOS was recevied but the connection was not pulled down until after a NOOP was sent and timed out. --- .../transport/imap-client-connection.vala | 10 ++-- .../imap/transport/imap-client-session.vala | 48 ++++++++++--------- 2 files changed, 31 insertions(+), 27 deletions(-) diff --git a/src/engine/imap/transport/imap-client-connection.vala b/src/engine/imap/transport/imap-client-connection.vala index 960d12aa..fd9e2f1b 100644 --- a/src/engine/imap/transport/imap-client-connection.vala +++ b/src/engine/imap/transport/imap-client-connection.vala @@ -1,9 +1,9 @@ /* * Copyright 2016 Software Freedom Conservancy Inc. - * Copyright 2018 Michael Gratton + * Copyright 2018-2019 Michael Gratton * * This software is licensed under the GNU Lesser General Public License - * (version 2.1 or later). See the COPYING file in this distribution. + * (version 2.1 or later). See the COPYING file in this distribution. */ public class Geary.Imap.ClientConnection : BaseObject { @@ -114,8 +114,8 @@ public class Geary.Imap.ClientConnection : BaseObject { root.to_string(), err.message); } - public virtual signal void recv_closed() { - Logging.debug(Logging.Flag.NETWORK, "[%s] recv closed", to_string()); + public virtual signal void received_eos() { + Logging.debug(Logging.Flag.NETWORK, "[%s] recv eos", to_string()); } public virtual signal void send_failure(Error err) { @@ -596,7 +596,7 @@ public class Geary.Imap.ClientConnection : BaseObject { } private void on_eos() { - recv_closed(); + received_eos(); } private void on_command_timeout(Command command) { diff --git a/src/engine/imap/transport/imap-client-session.vala b/src/engine/imap/transport/imap-client-session.vala index 93ef9f33..07ed573f 100644 --- a/src/engine/imap/transport/imap-client-session.vala +++ b/src/engine/imap/transport/imap-client-session.vala @@ -750,7 +750,7 @@ public class Geary.Imap.ClientSession : BaseObject { cx.received_continuation_response.connect(on_received_continuation_response); cx.received_bytes.connect(on_received_bytes); cx.received_bad_response.connect(on_received_bad_response); - cx.recv_closed.connect(on_received_closed); + cx.received_eos.connect(on_received_eos); cx.receive_failure.connect(on_network_receive_failure); cx.deserialize_failure.connect(on_network_receive_failure); @@ -777,7 +777,7 @@ public class Geary.Imap.ClientSession : BaseObject { cx.received_continuation_response.disconnect(on_received_continuation_response); cx.received_bytes.disconnect(on_received_bytes); cx.received_bad_response.disconnect(on_received_bad_response); - cx.recv_closed.disconnect(on_received_closed); + cx.received_eos.connect(on_received_eos); cx.receive_failure.disconnect(on_network_receive_failure); cx.deserialize_failure.disconnect(on_network_receive_failure); @@ -1606,16 +1606,20 @@ public class Geary.Imap.ClientSession : BaseObject { // error handling // - // use different error handler when connecting because, if connect_async() fails, there's no - // requirement for the user to call disconnect_async() and clean up... this prevents leaving the - // FSM in the CONNECTING state, causing an assertion when this object is destroyed - private uint on_connecting_send_recv_error(uint state, uint event, void *user, Object? object, Error? err) { - assert(err != null); - - debug("[%s] Connecting send/recv error, dropping client connection: %s", to_string(), err.message); - + // use different error handler when connecting because, if + // connect_async() fails, there's no requirement for the user to + // call disconnect_async() and clean up... this prevents leaving + // the FSM in the CONNECTING state, causing an assertion when this + // object is destroyed + private uint on_connecting_send_recv_error(uint state, + uint event, + void *user, + GLib.Object? object, + GLib.Error? err) { + debug("[%s] Connecting send/recv error, dropping client connection: %s", + to_string(), + err != null ? err.message : "EOS"); fsm.do_post_transition(() => { drop_connection(); }); - return State.BROKEN; } @@ -1636,12 +1640,16 @@ public class Geary.Imap.ClientSession : BaseObject { dispatch_disconnect_results(DisconnectReason.LOCAL_ERROR, result); } - private uint on_recv_error(uint state, uint event, void *user, Object? object, Error? err) { - assert(err != null); - debug("[%s] Receive error, disconnecting: %s", to_string(), err.message); - + private uint on_recv_error(uint state, + uint event, + void *user, + GLib.Object? object, + GLib.Error? err) { + debug("[%s] Receive error, disconnecting: %s", + to_string(), + (err != null) ? err.message : "EOS" + ); cx.disconnect_async.begin(null, on_fire_recv_error_signal); - return State.BROKEN; } @@ -1906,12 +1914,8 @@ public class Geary.Imap.ClientSession : BaseObject { debug("[%s] Received bad response %s: %s", to_string(), root.to_string(), err.message); } - private void on_received_closed(ClientConnection cx) { -#if VERBOSE_SESSION - // This currently doesn't generate any Events, but it does mean the connection has closed - // due to EOS - debug("[%s] Received closed", to_string()); -#endif + private void on_received_eos(ClientConnection cx) { + fsm.issue(Event.RECV_ERROR, null, null, null); } private void on_network_receive_failure(Error err) { From 0b923a29ead913184d5886a72402326197012b60 Mon Sep 17 00:00:00 2001 From: Michael Gratton Date: Sat, 10 Aug 2019 11:31:33 +1000 Subject: [PATCH 3/5] Ensure bad IMAP response are treated as other errors Send a receive error event to the FSM when a bad response is received so that the connection is closed, in the same way as for other receive errors. --- src/engine/imap/transport/imap-client-session.vala | 1 + 1 file changed, 1 insertion(+) diff --git a/src/engine/imap/transport/imap-client-session.vala b/src/engine/imap/transport/imap-client-session.vala index 07ed573f..62955e32 100644 --- a/src/engine/imap/transport/imap-client-session.vala +++ b/src/engine/imap/transport/imap-client-session.vala @@ -1912,6 +1912,7 @@ public class Geary.Imap.ClientSession : BaseObject { private void on_received_bad_response(RootParameters root, ImapError err) { debug("[%s] Received bad response %s: %s", to_string(), root.to_string(), err.message); + fsm.issue(Event.RECV_ERROR, null, null, err); } private void on_received_eos(ClientConnection cx) { From 63210247dd6bea98d32c2f5d0e11b3c050473b1b Mon Sep 17 00:00:00 2001 From: Michael Gratton Date: Sat, 10 Aug 2019 11:43:22 +1000 Subject: [PATCH 4/5] Rename the BROKEN FSM state to CLOSED BROKEN sounds bad, whereas it's actually a normal state. --- .../imap/transport/imap-client-session.vala | 40 +++++++++---------- 1 file changed, 20 insertions(+), 20 deletions(-) diff --git a/src/engine/imap/transport/imap-client-session.vala b/src/engine/imap/transport/imap-client-session.vala index 62955e32..581da0cc 100644 --- a/src/engine/imap/transport/imap-client-session.vala +++ b/src/engine/imap/transport/imap-client-session.vala @@ -180,7 +180,7 @@ public class Geary.Imap.ClientSession : BaseObject { LOGGING_OUT, // terminal state - BROKEN, + CLOSED, COUNT } @@ -467,18 +467,18 @@ public class Geary.Imap.ClientSession : BaseObject { new Geary.State.Mapping(State.LOGGED_OUT, Event.RECV_ERROR, on_recv_error), new Geary.State.Mapping(State.LOGGED_OUT, Event.SEND_ERROR, on_send_error), - new Geary.State.Mapping(State.BROKEN, Event.CONNECT, on_late_command), - new Geary.State.Mapping(State.BROKEN, Event.LOGIN, on_late_command), - new Geary.State.Mapping(State.BROKEN, Event.SEND_CMD, on_late_command), - new Geary.State.Mapping(State.BROKEN, Event.SELECT, on_late_command), - new Geary.State.Mapping(State.BROKEN, Event.CLOSE_MAILBOX, on_late_command), - new Geary.State.Mapping(State.BROKEN, Event.LOGOUT, on_late_command), - new Geary.State.Mapping(State.BROKEN, Event.DISCONNECT, Geary.State.nop), - new Geary.State.Mapping(State.BROKEN, Event.DISCONNECTED, on_disconnected), - new Geary.State.Mapping(State.BROKEN, Event.RECV_STATUS, on_dropped_response), - new Geary.State.Mapping(State.BROKEN, Event.RECV_COMPLETION, on_dropped_response), - new Geary.State.Mapping(State.BROKEN, Event.SEND_ERROR, Geary.State.nop), - new Geary.State.Mapping(State.BROKEN, Event.RECV_ERROR, Geary.State.nop), + new Geary.State.Mapping(State.CLOSED, Event.CONNECT, on_late_command), + new Geary.State.Mapping(State.CLOSED, Event.LOGIN, on_late_command), + new Geary.State.Mapping(State.CLOSED, Event.SEND_CMD, on_late_command), + new Geary.State.Mapping(State.CLOSED, Event.SELECT, on_late_command), + new Geary.State.Mapping(State.CLOSED, Event.CLOSE_MAILBOX, on_late_command), + new Geary.State.Mapping(State.CLOSED, Event.LOGOUT, on_late_command), + new Geary.State.Mapping(State.CLOSED, Event.DISCONNECT, Geary.State.nop), + new Geary.State.Mapping(State.CLOSED, Event.DISCONNECTED, on_disconnected), + new Geary.State.Mapping(State.CLOSED, Event.RECV_STATUS, on_dropped_response), + new Geary.State.Mapping(State.CLOSED, Event.RECV_COMPLETION, on_dropped_response), + new Geary.State.Mapping(State.CLOSED, Event.SEND_ERROR, Geary.State.nop), + new Geary.State.Mapping(State.CLOSED, Event.RECV_ERROR, Geary.State.nop), }; fsm = new Geary.State.Machine(machine_desc, mappings, on_ignored_transition); @@ -488,7 +488,7 @@ public class Geary.Imap.ClientSession : BaseObject { ~ClientSession() { switch (fsm.get_state()) { case State.UNCONNECTED: - case State.BROKEN: + case State.CLOSED: // no problem-o break; @@ -595,7 +595,7 @@ public class Geary.Imap.ClientSession : BaseObject { case State.UNCONNECTED: case State.LOGGED_OUT: case State.LOGGING_OUT: - case State.BROKEN: + case State.CLOSED: return ProtocolState.UNCONNECTED; case State.NOAUTH: @@ -1355,7 +1355,7 @@ public class Geary.Imap.ClientSession : BaseObject { // nothing more we can do; drop connection and report disconnect to user cx.disconnect_async.begin(null, on_bye_disconnect_completed); - state = State.BROKEN; + state = State.CLOSED; break; default: @@ -1599,7 +1599,7 @@ public class Geary.Imap.ClientSession : BaseObject { params.proceed = true; - return State.BROKEN; + return State.CLOSED; } // @@ -1620,7 +1620,7 @@ public class Geary.Imap.ClientSession : BaseObject { to_string(), err != null ? err.message : "EOS"); fsm.do_post_transition(() => { drop_connection(); }); - return State.BROKEN; + return State.CLOSED; } private uint on_send_error(uint state, uint event, void *user, Object? object, Error? err) { @@ -1633,7 +1633,7 @@ public class Geary.Imap.ClientSession : BaseObject { cx.disconnect_async.begin(null, on_fire_send_error_signal); - return State.BROKEN; + return State.CLOSED; } private void on_fire_send_error_signal(Object? object, AsyncResult result) { @@ -1650,7 +1650,7 @@ public class Geary.Imap.ClientSession : BaseObject { (err != null) ? err.message : "EOS" ); cx.disconnect_async.begin(null, on_fire_recv_error_signal); - return State.BROKEN; + return State.CLOSED; } private void on_fire_recv_error_signal(Object? object, AsyncResult result) { From eb6afae35820404c44a350c81cf54f9d2764e8c0 Mon Sep 17 00:00:00 2001 From: Michael Gratton Date: Sat, 10 Aug 2019 11:46:35 +1000 Subject: [PATCH 5/5] Rename UNCONNECTED FSM and protocol state to NOT_CONNECTED The former is ambiguous, the latter is not. --- src/engine/imap/api/imap-client-service.vala | 4 +-- .../imap/transport/imap-client-session.vala | 32 ++++++++++--------- test/integration/imap/client-session.vala | 2 +- 3 files changed, 20 insertions(+), 18 deletions(-) diff --git a/src/engine/imap/api/imap-client-service.vala b/src/engine/imap/api/imap-client-service.vala index f07a2379..6613c44d 100644 --- a/src/engine/imap/api/imap-client-service.vala +++ b/src/engine/imap/api/imap-client-service.vala @@ -1,6 +1,6 @@ /* * Copyright 2016 Software Freedom Conservancy Inc. - * Copyright 2017-2018 Michael Gratton + * Copyright 2017-2019 Michael Gratton * * This software is licensed under the GNU Lesser General Public License * (version 2.1 or later). See the COPYING file in this distribution. @@ -355,7 +355,7 @@ internal class Geary.Imap.ClientService : Geary.ClientService { } break; - case ClientSession.ProtocolState.UNCONNECTED: + case ClientSession.ProtocolState.NOT_CONNECTED: // Already disconnected, so drop it on the floor try { yield remove_session_async(target); diff --git a/src/engine/imap/transport/imap-client-session.vala b/src/engine/imap/transport/imap-client-session.vala index 581da0cc..d3ff645a 100644 --- a/src/engine/imap/transport/imap-client-session.vala +++ b/src/engine/imap/transport/imap-client-session.vala @@ -83,7 +83,7 @@ public class Geary.Imap.ClientSession : BaseObject { * These don't exactly match the states in the IMAP specification. For one, they count * transitions as states unto themselves (due to network latency and the asynchronous nature * of ClientSession's interface). Also, the LOGOUT (and logging out) state has been melded - * into {@link ProtocolState.UNCONNECTED} on the presumption that the nuances of a disconnected or + * into {@link ProtocolState.NOT_CONNECTED} on the presumption that the nuances of a disconnected or * disconnecting session is uninteresting to the caller. * * See [[http://tools.ietf.org/html/rfc3501#section-3]] @@ -91,7 +91,7 @@ public class Geary.Imap.ClientSession : BaseObject { * @see get_protocol_state */ public enum ProtocolState { - UNCONNECTED, + NOT_CONNECTED, CONNECTING, UNAUTHORIZED, AUTHORIZING, @@ -165,8 +165,10 @@ public class Geary.Imap.ClientSession : BaseObject { } private enum State { + // initial state + NOT_CONNECTED, + // canonical IMAP session states - UNCONNECTED, NOAUTH, AUTHORIZED, SELECTED, @@ -219,7 +221,7 @@ public class Geary.Imap.ClientSession : BaseObject { } private static Geary.State.MachineDescriptor machine_desc = new Geary.State.MachineDescriptor( - "Geary.Imap.ClientSession", State.UNCONNECTED, State.COUNT, Event.COUNT, + "Geary.Imap.ClientSession", State.NOT_CONNECTED, State.COUNT, Event.COUNT, state_to_string, event_to_string); /** @@ -348,13 +350,13 @@ public class Geary.Imap.ClientSession : BaseObject { this.imap_endpoint = imap_endpoint; Geary.State.Mapping[] mappings = { - new Geary.State.Mapping(State.UNCONNECTED, Event.CONNECT, on_connect), - new Geary.State.Mapping(State.UNCONNECTED, Event.LOGIN, on_early_command), - new Geary.State.Mapping(State.UNCONNECTED, Event.SEND_CMD, on_early_command), - new Geary.State.Mapping(State.UNCONNECTED, Event.SELECT, on_early_command), - new Geary.State.Mapping(State.UNCONNECTED, Event.CLOSE_MAILBOX, on_early_command), - new Geary.State.Mapping(State.UNCONNECTED, Event.LOGOUT, on_early_command), - new Geary.State.Mapping(State.UNCONNECTED, Event.DISCONNECT, Geary.State.nop), + new Geary.State.Mapping(State.NOT_CONNECTED, Event.CONNECT, on_connect), + new Geary.State.Mapping(State.NOT_CONNECTED, Event.LOGIN, on_early_command), + new Geary.State.Mapping(State.NOT_CONNECTED, Event.SEND_CMD, on_early_command), + new Geary.State.Mapping(State.NOT_CONNECTED, Event.SELECT, on_early_command), + new Geary.State.Mapping(State.NOT_CONNECTED, Event.CLOSE_MAILBOX, on_early_command), + new Geary.State.Mapping(State.NOT_CONNECTED, Event.LOGOUT, on_early_command), + new Geary.State.Mapping(State.NOT_CONNECTED, Event.DISCONNECT, Geary.State.nop), new Geary.State.Mapping(State.CONNECTING, Event.CONNECT, on_already_connected), new Geary.State.Mapping(State.CONNECTING, Event.LOGIN, on_early_command), @@ -487,7 +489,7 @@ public class Geary.Imap.ClientSession : BaseObject { ~ClientSession() { switch (fsm.get_state()) { - case State.UNCONNECTED: + case State.NOT_CONNECTED: case State.CLOSED: // no problem-o break; @@ -592,11 +594,11 @@ public class Geary.Imap.ClientSession : BaseObject { current_mailbox = null; switch (fsm.get_state()) { - case State.UNCONNECTED: + case State.NOT_CONNECTED: case State.LOGGED_OUT: case State.LOGGING_OUT: case State.CLOSED: - return ProtocolState.UNCONNECTED; + return ProtocolState.NOT_CONNECTED; case State.NOAUTH: return ProtocolState.UNAUTHORIZED; @@ -1197,7 +1199,7 @@ public class Geary.Imap.ClientSession : BaseObject { uint seconds; switch (get_protocol_state(null)) { - case ProtocolState.UNCONNECTED: + case ProtocolState.NOT_CONNECTED: case ProtocolState.CONNECTING: return; diff --git a/test/integration/imap/client-session.vala b/test/integration/imap/client-session.vala index 957cbde6..e2d38a63 100644 --- a/test/integration/imap/client-session.vala +++ b/test/integration/imap/client-session.vala @@ -33,7 +33,7 @@ class Integration.Imap.ClientSession : TestCase { } public override void tear_down() throws GLib.Error { - if (this.session.get_protocol_state(null) != UNCONNECTED) { + if (this.session.get_protocol_state(null) != NOT_CONNECTED) { this.session.disconnect_async.begin(null, async_complete_full); this.session.disconnect_async.end(async_result()); }