Bug 19762

From what I can tell, the gimpnet IRC server is particularly sluggish and if you enable that account and wait a few seconds until after idle has sent the NICK and USER accounts, and then disable the account, we will hit an assert.  

What seems to be happening is: when the account is disabled, idle will send a QUIT command to the server, but the server seems to be blocking waiting for an ident response, so it doesn't see the QUIT command.  telepathy-idle seems to be waiting for a response to the QUIT command before it actually terminates its connection to the server.  At some point (perhaps up to 30 seconds later), the server will decide to stop waiting for an ident response and will send the following messages:
 NOTICE AUTH :*** No Ident response
 :irc.acc.umu.se 001 idletest :Welcome to the Internet Relay Network

telepathy-idle will see this welcome message (001) and attempt to change our status to CONNECTED.  However, the act of sending the QUIT command apparently had already changed our internal status from CONNECTING to DISCONNECTED, so when we try to change our status to CONNECTED, we violate an assertion that we can only transition to CONNECTED if we're currently in CONNECTING state.

===========================================

Here is the debugger stack trace:

#0  g_logv (log_domain=0xb7d92007 \"tp-glib\", log_level=G_LOG_LEVEL_CRITICAL, format=0xb7c05171 \"%s: assertion `%s' failed\", args1=0xbfc7619c \"`4\?\?H5\?\?\?\?\?\?\?a\?\?\?\?\?\?\\a \?\?`4\?\?H5\?\?\\") at gmessages.c:493
#1  g_log (log_domain=0xb7d92007 \"tp-glib\", log_level=G_LOG_LEVEL_CRITICAL, format=0xb7c05171 \"%s: assertion `%s' failed\") at gmessages.c:517
#2  g_return_if_fail_warning (log_domain=0xb7d92007 \"tp-glib\", pretty_function=0xb7d93460 \"tp_base_connection_change_status\", expression=0xb7d93548 \"prev_status == TP_CONNECTION_STATUS_CONNECTING\") at gmessages.c:532
#3  tp_base_connection_change_status (self=0x95bd230, status=TP_CONNECTION_STATUS_CONNECTED, reason=TP_CONNECTION_STATUS_REASON_REQUESTED) at base-connection.c:2632
#4  connection_connect_cb (conn=0x95bd230, success=1, fail_reason=TP_CONNECTION_STATUS_REASON_NONE_SPECIFIED) at idle-connection.c:887
#5  _welcome_handler (parser=0x95c07f8, code=IDLE_PARSER_NUMERIC_WELCOME, args=0x95c41d0, user_data=0x95bd230) at idle-connection.c:848
#6  _parse_and_forward_one (parser=0x95c07f8, tokens=0x95c6950, code=IDLE_PARSER_NUMERIC_WELCOME, format=0x806423a \"\") at idle-parser.c:399
#7  _parse_message (parser=0x95c07f8, split_msg=0x95b47c0 \":irc.acc.umu.se 001 idletest :Welcome to the Internet Relay Network idletest\") at idle-parser.c:321
#8  idle_parser_receive (parser=0x95c07f8, msg=0x95c2e08 \":irc.acc.umu.se 001 idletest :Welcome to the Internet Relay Network idletest\\r\\n:irc.acc.umu.se 002 idletest :Your host is irc.acc.umu.se[130.239.18.157/6667], running version 2.8/gimpnet-0.1beta3\\r\\nNOTI\"...) at idle-parser.c:214
#9  sconn_received_cb (sconn=0x95c33b0, raw_msg=0x95bf970 \":irc.acc.umu.se 001 idletest :Welcome to the Internet Relay Network idletest\\r\\n:irc.acc.umu.se 002 idletest :Your host is irc.acc.umu.se[130.239.18.157/6667], running version 2.8/gimpnet-0.1beta3\\r\\nNOTI\"..., conn=0x95bd230) at idle-connection.c:661
#10  g_cclosure_marshal_VOID__STRING (closure=0x95b6aa8, return_value=0x0, n_param_values=2, param_values=0x95b8590, invocation_hint=0xbfc76968, marshal_data=0x0) at gmarshal.c:496
#11  g_closure_invoke (closure=0x95b6aa8, return_value=0x0, n_param_values=2, param_values=0x95b8590, invocation_hint=0xbfc76968) at gclosure.c:767
#12  signal_emit_unlocked_R (node=0x95bd800, detail=0, instance=0x95c33b0, emission_return=0x0, instance_and_params=0x95b8590) at gsignal.c:3244
#13  g_signal_emit_valist (instance=0x95c33b0, signal_id=22, detail=0, var_args=0xbfc76bfc \"0l\?\?,l\?\?\?5\\\b\?5\\\b\?u[\\t\\") at gsignal.c:2977
#14  g_signal_emit_by_name (instance=0x95c33b0, detailed_signal=0x80647b0 \"received\") at gsignal.c:3071
#15  io_func (src=0x95c8530, cond=G_IO_IN, data=0x95c33b0) at idle-server-connection.c:301
#16  g_io_unix_dispatch (source=0x95c6268, callback=0x8056ecc <io_func>, user_data=0x95c33b0) at giounix.c:162
#17  g_main_dispatch (context=0x95b37e8) at gmain.c:1814
#18  g_main_context_dispatch (context=0x95b37e8) at gmain.c:2367
#19  g_main_context_iterate (context=0x95b37e8, block=1, dispatch=1, self=0x95b8ca0) at gmain.c:2448
#20  g_main_loop_run (loop=0x95b2840) at gmain.c:2656
#21  tp_run_connection_manager (prog_name=0x8062df0 \"telepathy-idle\", version=0x8062de8 \"0.1.2.1\", construct_cm=0x804d3f4 <_construct_cm>, argc=1, argv=0xbfc77144) at run.c:264
#22  main (argc=1, argv=0xbfc77144) at idle.c:38

===========================================

Here is the relevant portion of the telepathy-idle log:

(telepathy-idle:5928): tp-glib-DEBUG: tp_cm_param_setter_offset: account = "idletest"
(telepathy-idle:5928): tp-glib-DEBUG: tp_cm_param_setter_offset: server = "irc.gimp.org"
(telepathy-idle:5928): tp-glib-DEBUG: tp_cm_param_setter_offset: port = 6667 = 0x1a0b
(telepathy-idle:5928): tp-glib-DEBUG: parse_parameters: password not given, using default behaviour
(telepathy-idle:5928): tp-glib-DEBUG: tp_cm_param_setter_offset: fullname = "test user"
(telepathy-idle:5928): tp-glib-DEBUG: tp_cm_param_setter_offset: charset = "UTF-8"
(telepathy-idle:5928): tp-glib-DEBUG: tp_cm_param_setter_offset: quit-message = "So long and thanks for all the IRC - telepathy-idle IRC Connection Manager for Telepathy - http://telepathy.freedesktop.org"
(telepathy-idle:5928): tp-glib-DEBUG: tp_cm_param_setter_offset: use-ssl = FALSE
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_init: Initializing (TpBaseConnection *)0x95bd230
(telepathy-idle:5928): tp-glib-DEBUG: tp_presence_mixin_init: called.
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_constructor: Post-construction: (TpBaseConnection *)0x95bd230
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_constructor: Handle repo for type #0 at (nil)
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_constructor: Handle repo for type #1 at 0x95c3230
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_constructor: Handle repo for type #2 at 0x95c3460
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_constructor: Handle repo for type #3 at (nil)
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_constructor: Handle repo for type #4 at (nil)
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_constructor: Channel factory #0 at 0x95b5c60
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_constructor: Channel factory #1 at 0x95b5c40
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_register: bus name org.freedesktop.Telepathy.Connection.idle.irc.idletest_40irc_2egimp_2eorg
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_register: object path /org/freedesktop/Telepathy/Connection/idle/irc/idletest_40irc_2egimp_2eorg
** (telepathy-idle:5928): DEBUG: change_state: emitting status-changed, state 1, reason 1
** (telepathy-idle:5928): DEBUG: sconn_status_changed_cb: called with state 1
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_change_status: was 4294967295, now 1, for reason 1
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_change_status: emitting status-changed to 1, for reason 1
** (telepathy-idle:5928): DEBUG: connect_io_func: connected!
** (telepathy-idle:5928): DEBUG: change_state: emitting status-changed, state 2, reason 1
** (telepathy-idle:5928): DEBUG: sconn_status_changed_cb: called with state 2
** (telepathy-idle:5928): DEBUG: _parse_message: parsing "NOTICE AUTH :*** Looking up your hostname..."
** (telepathy-idle:5928): DEBUG: _parse_message: parsing "NOTICE AUTH :*** Checking Ident"
** (telepathy-idle:5928): DEBUG: _parse_message: parsing "NOTICE AUTH :*** Found your hostname"
** (telepathy-idle:5928): DEBUG: msg_queue_timeout_cb: called
** (telepathy-idle:5928): DEBUG: iface_send_impl: sent "NICK idletest
"
** (telepathy-idle:5928): DEBUG: msg_queue_timeout_cb: called
** (telepathy-idle:5928): DEBUG: iface_send_impl: sent "USER idletest 8 * :test user
"
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_change_status: was 1, now 2, for reason 1
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_change_status: emitting status-changed to 2, for reason 1
** (telepathy-idle:5928): DEBUG: iface_send_impl: sent "QUIT :So long and thanks for all the IRC - telepathy-idle IRC Connection Manager for Telepathy - http://telepathy.freedesktop.org
"
** (telepathy-idle:5928): DEBUG: msg_queue_timeout_cb: called
** (telepathy-idle:5928): DEBUG: _parse_message: parsing "NOTICE AUTH :*** No Ident response"
** (telepathy-idle:5928): DEBUG: _parse_message: parsing ":irc.acc.umu.se 001 idletest :Welcome to the Internet Relay Network idletest"
** (telepathy-idle:5928): DEBUG: _parse_and_forward_one: message code 31
** (telepathy-idle:5928): DEBUG: _parse_atom: parsing atom "irc.acc.umu.se" as I
** (telepathy-idle:5928): DEBUG: _parse_atom: ignored token
** (telepathy-idle:5928): DEBUG: _parse_atom: parsing atom "001" as I
** (telepathy-idle:5928): DEBUG: _parse_atom: ignored token
** (telepathy-idle:5928): DEBUG: _parse_atom: parsing atom "idletest" as c
** (telepathy-idle:5928): DEBUG: _parse_atom: set handle 1
** (telepathy-idle:5928): DEBUG: _parse_and_forward_one: succesfully parsed
(telepathy-idle:5928): tp-glib-DEBUG: tp_base_connection_change_status: was 2, now 0, for reason 1

tp-glib-CRITICAL **: tp_base_connection_change_status: assertion `prev_status == TP_CONNECTION_STATUS_CONNECTING' failed
aborting...