Closed Bug 955430 Opened 10 years ago Closed 10 years ago

Account reconnects after using the /quit command

Categories

(Chat Core :: IRC, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: nhnt11, Assigned: aleth)

References

(Depends on 1 open bug)

Details

(Whiteboard: [1.5-wanted])

Attachments

(2 files, 7 obsolete files)

*** Original post on bio 1994 at 2013-06-07 16:57:00 UTC ***

When the /quit command is used, the account shows "Disconnecting..." and then "Lost connection with server" (in the accounts window) and then proceeds to reconnect.

The following error is displayed in the error console:

Error: Connection closed by server.
Source File: jar:file:///Applications/Instantbird.app/Contents/MacOS/omni.ja!/components/irc.js
Line: 666
Source Code:
prpl-irc
*** Original post on bio 1994 at 2013-06-08 10:38:17 UTC ***

Confirming.
OS: Other → All
Hardware: x86 → All
Whiteboard: [1.5-wanted]
Attached patch Patch (obsolete) — Splinter Review
*** Original post on bio 1994 as attmnt 2750 at 2013-08-22 16:04:00 UTC ***

This also moves some code from ircAccount.disconnect to ircAccount.quit which is otherwise never executed if only quit is called.
Attachment #8354519 - Flags: review?(clokep)
Assignee: nobody → aleth
Status: NEW → ASSIGNED
Comment on attachment 8354519 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2750 at 2013-08-23 13:07:58 UTC ***

>diff --git a/chat/protocols/irc/irc.js b/chat/protocols/irc/irc.js
>index 344b3a0..ed3e99d 100644
>--- a/chat/protocols/irc/irc.js
>+++ b/chat/protocols/irc/irc.js
>@@ -1202,40 +1202,40 @@ ircAccount.prototype = {
> 
>   // Used to wait for a response from the server.
>   _quitTimer: null,
>   // RFC 2812 Section 3.1.7.
>   quit: function(aMessage) {
>     this._reportDisconnecting(Ci.prplIAccount.NO_ERROR);
>     this.sendMessage("QUIT",
>                      aMessage || this.getString("quitmsg") || undefined);
>+
>+    // Reset original nickname for the next reconnect.
>+    this._requestedNickname = this._accountNickname;
>+
>+    // Give the server 2 seconds to respond, otherwise just forcefully
>+    // disconnect the socket. This will be cancelled if a response is heard from
>+    // the server.
>+    this._quitTimer = setTimeout(this.gotDisconnected.bind(this), 2 * 1000);
>   },
What does moving all this code here fix? Or is it just clean up?

>diff --git a/chat/protocols/irc/ircCommands.jsm b/chat/protocols/irc/ircCommands.jsm
>@@ -333,17 +333,20 @@ var commands = [
>   {
>     name: "quit",
>     get helpString() _("command.quit", "quit"),
>     run: function(aMsg, aConv) {
>-      getAccount(aConv).quit(aMsg);
>+      let account = getAccount(aConv);
>+      account.quit(aMsg);
>+      // Tell the imAccount as this is an intentional disconnection.
>+      account.imAccount.disconnect();
Why are we calling this? This seems very wrong. Can you provide more information about what's happening?

I'd think the real issue is around http://lxr.instantbird.org/instantbird/source/chat/protocols/irc/irc.js#1451
Attachment #8354519 - Flags: review?(clokep) → review-
*** Original post on bio 1994 at 2013-08-23 14:24:33 UTC ***

(In reply to comment #3)
> What does moving all this code here fix? Or is it just clean up?

This code should also be executed on /quit (which calls quit()), but is currently only executed on disconnect() (which also calls quit()).

> >+      // Tell the imAccount as this is an intentional disconnection.
> >+      account.imAccount.disconnect();
> Why are we calling this? This seems very wrong. Can you provide more
> information about what's happening?

What's happening is that we disconnect with Ci.prplIAccount.NO_ERROR. There is no bug on the IRC side. imAccount.js responds to such disconnections by reconnecting the account, as there is still a status observer around. The best way to remove the status observer seemed to me to be imAccount.disconnect(). which is called when users decide to disconnect an account. I guess protocols in general are not expected to have commands that disconnect them...
Attached patch Alternative patch (obsolete) — Splinter Review
*** Original post on bio 1994 as attmnt 2761 at 2013-08-23 15:07:00 UTC ***

Alternative "WTF do we need a /quit command for" patch. People can still set their fav quit message by changing the pref if they really care, but I guess this does break /quit for people used to using it. I am against adding a global command for this.
Attachment #8354530 - Flags: review?(clokep)
Comment on attachment 8354530 [details] [diff] [review]
Alternative patch

*** Original change on bio 1994 attmnt 2761 at 2013-08-23 15:21:14 UTC ***

r- because I don't want to remove the quit command, and even if we wanted, you would want to remove the localized string too ;).
Attachment #8354530 - Flags: review?(clokep) → review-
Attached patch Patch (obsolete) — Splinter Review
*** Original post on bio 1994 as attmnt 2762 at 2013-08-23 16:16:00 UTC ***

Retains /quit, improves comment, and calls disconnect() on /quit with the quit message being passed through.
Attachment #8354531 - Flags: review?(clokep)
Comment on attachment 8354519 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2750 at 2013-08-23 16:16:00 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354519 - Attachment is obsolete: true
Attached patch Patch (obsolete) — Splinter Review
*** Original post on bio 1994 as attmnt 2763 at 2013-08-23 16:27:00 UTC ***

Fix indent in existing code
Attachment #8354532 - Flags: review?(clokep)
Comment on attachment 8354531 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2762 at 2013-08-23 16:27:47 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354531 - Attachment is obsolete: true
Attachment #8354531 - Flags: review?(clokep)
*** Original post on bio 1994 at 2013-08-23 16:57:08 UTC ***

Btw I noticed in testing that the quit message is unreliably sent - on the receiving end, I sometimes see "Quit: aleth_dev" instead of "Quit: (default message)" or "Quit: (changed message)". I'm not sure why that is.
Comment on attachment 8354532 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2763 at 2013-08-23 17:02:52 UTC ***

(In reply to comment #9)
> Btw I noticed in testing that the quit message is unreliably sent - on the
> receiving end, I sometimes see "Quit: aleth_dev" instead of "Quit: (default
> message)" or "Quit: (changed message)". I'm not sure why that is.

It appears it is a regression, so I'll take another look at this.
Attachment #8354532 - Flags: review?(clokep)
Comment on attachment 8354532 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2763 at 2013-08-23 17:50:57 UTC ***

I don't think there's anything wrong with this patch. We send the correct QUIT message, and receive an ERROR response. The ERROR response sometimes includes the quit message we sent, and sometimes not, replacing it with the nickname. I don't know if this is some strange server behaviour if you QUIT too often in a short time or what.
Attachment #8354532 - Flags: review?(clokep)
*** Original post on bio 1994 at 2013-08-23 18:01:30 UTC ***

And indeed: unrealircd.conf contains

/* The minimum time a user must be connected before being allowed to use a QUIT message,
 * This will hopefully help stop spam */
anti-spam-quit-message-time
*** Original post on bio 1994 at 2013-08-23 18:17:29 UTC ***

Comment on attachment 8354532 [details] [diff] [review] (bio-attmnt 2763)
Patch

>diff --git a/chat/protocols/irc/irc.js b/chat/protocols/irc/irc.js
>     // If there's no socket, disconnect immediately to avoid waiting 2 seconds.
>     if (!this._socket || !this._socket.isConnected) {
>+      this._reportDisconnecting(Ci.prplIAccount.NO_ERROR);
Why add this? Won't that be handled at http://lxr.instantbird.org/instantbird/source/chat/protocols/irc/irc.js#1449?

Besides that, looks reasonable.
Attached patch Patch (obsolete) — Splinter Review
*** Original post on bio 1994 as attmnt 2768 at 2013-08-23 18:27:00 UTC ***

Removed the remaining _reportDisconnected as well.
Attachment #8354537 - Flags: review?(clokep)
Comment on attachment 8354532 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2763 at 2013-08-23 18:27:56 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354532 - Attachment is obsolete: true
Attachment #8354532 - Flags: review?(clokep)
*** Original post on bio 1994 at 2013-08-23 20:34:12 UTC ***

Thinking about the .imAccount.disconnect call again, and after seeing "Lost connection with server" in comment 0, I wonder if the problem isn't that we disconnect with an error code rather than 'OK'.
*** Original post on bio 1994 at 2013-08-24 09:50:31 UTC ***

(In reply to comment #15)
> Thinking about the .imAccount.disconnect call again, and after seeing "Lost
> connection with server" in comment 0, I wonder if the problem isn't that we
> disconnect with an error code rather than 'OK'.

No, in IRC we send QUIT and then the server closes the connection. The error message in comment 0 arises because the account at that point is already reconnecting, so the IRC code does not recognise this as an expected event during disconnection.
*** Original post on bio 1994 at 2013-08-24 09:53:51 UTC ***

(In reply to comment #16)
> No, in IRC we send QUIT and then the server closes the connection.

Or to be more precise, the server sends an ERROR message in response, as described in comment 11. http://lxr.instantbird.org/instantbird/source/chat/protocols/irc/ircBase.jsm#163
Comment on attachment 8354537 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2768 at 2013-08-24 13:27:31 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354537 - Flags: review?(clokep)
Comment on attachment 8354530 [details] [diff] [review]
Alternative patch

*** Original change on bio 1994 attmnt 2761 at 2013-08-24 13:27:53 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354530 - Attachment is obsolete: true
Attached patch Patch (obsolete) — Splinter Review
*** Original post on bio 1994 as attmnt 2776 at 2013-08-24 14:09:00 UTC ***

This includes the improvements to the ircSocket (delete this._account on disconnect) as discussed on IRC.

DEBUG logging of messages is now done before the handlers for the message are called, to prevent logging an ERROR message after reportDisconnected. The cost of this will be that we will always have DEBUG even when the message is not handled (which will produce an additional WARN or ERROR).
Attachment #8354545 - Flags: review?(clokep)
Comment on attachment 8354537 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2768 at 2013-08-24 14:09:39 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354537 - Attachment is obsolete: true
Comment on attachment 8354545 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2776 at 2013-08-24 14:10:01 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354545 - Flags: review?(florian)
Comment on attachment 8354545 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2776 at 2013-08-24 14:57:16 UTC ***

>+  onStopRequest: function(aRequest, aContext, aStatus) {
>+    if (!this._account)
>+      return;
>+    Socket.onStopRequest(aRequest, aContext, aStatus);
>+  },
>+  disconnect: function() {
>+    if (!this._account)
>+      return;
>+    Socket.disconnect();

This won't do what you expect. I think you want Socket.disconnect.call(this);

Can we simplify the rest of the code (avoid null checks) if we do here:
 this.onStopRequest = function() {};
?
Attachment #8354545 - Flags: review?(florian) → review-
Attached patch Patch (obsolete) — Splinter Review
*** Original post on bio 1994 as attmnt 2778 at 2013-08-24 15:17:00 UTC ***

It saves the onStopRequest override, but I kept the account check in the timeout handler to be safe as that is called by a timer.
Attachment #8354547 - Flags: review?(florian)
Comment on attachment 8354545 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2776 at 2013-08-24 15:17:32 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354545 - Attachment is obsolete: true
Attachment #8354545 - Flags: review?(clokep)
Comment on attachment 8354547 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2778 at 2013-08-24 15:18:13 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354547 - Flags: review?(clokep)
*** Original post on bio 1994 at 2013-08-24 15:26:55 UTC ***

(In reply to comment #20)
> I kept the account check in the
> timeout handler to be safe as that is called by a timer.

The timer is removed at the end of the disconnect method.
Comment on attachment 8354547 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2778 at 2013-08-24 15:33:10 UTC ***

r=fqueze with the null check in onConnectionTimedOut removed, and the comment above the disconnect method rephrased to indicate that there are 2 different cases in which this can be called, and the the parameter is only likely to exist for one of them.

I still want Patrick to have a look of course :).
Attachment #8354547 - Flags: review?(florian) → review+
Comment on attachment 8354547 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2778 at 2013-08-24 15:35:23 UTC ***

I didn't give this as in-depth of a look as I was hoping to (mostly to the changes in ircSocket), but I'm comfortable with this after the changes Florian suggested.
Attachment #8354547 - Flags: review?(clokep) → review+
Attached patch PatchSplinter Review
*** Original post on bio 1994 as attmnt 2779 at 2013-08-24 15:40:00 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354548 - Flags: review?(florian)
Comment on attachment 8354547 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2778 at 2013-08-24 15:40:14 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354547 - Attachment is obsolete: true
Comment on attachment 8354548 [details] [diff] [review]
Patch

*** Original change on bio 1994 attmnt 2779 at 2013-08-24 15:46:01 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354548 - Flags: review?(florian) → review+
Whiteboard: [1.5-wanted] → [1.5-wanted][checkin-needed]
*** Original post on bio 1994 at 2013-08-25 00:10:21 UTC ***

http://hg.instantbird.org/instantbird/rev/7991bfbc4d28
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Whiteboard: [1.5-wanted][checkin-needed] → [1.5-wanted]
Target Milestone: --- → 1.5
Attached patch Follow-up fixSplinter Review
*** Original post on bio 1994 as attmnt 2782 at 2013-08-25 11:03:00 UTC ***

Error during shutdown if an IRC account was connected:
[Exception... "'TypeError: this._account is undefined' when calling method: [nsITransportEventSink::onTransportStatus]"  nsresult: "0x8057001c (NS_ERROR_XPC_JS_THREW_JS_OBJECT)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"  data: no]

This is coming from:
450     this.DEBUG("onTransportStatus(" + (status || ("0x" + aStatus.toString(16))) +")");

in the onTransportStatus method of socket.jsm.

I tried calling this.transport.setEventSink(null, null); in the disconnect method, but unfortunately setEventSink calls are ignored after this.transport.open{Out,In}putStream.

So adding a null check seems the best remaining option...

For the curious, the status change that we are trying to log is STATUS_SENDING_TO because we send the string "QUIT :Instantbird 1.5a1pre -- http://www.instantbird.com" just before closing the transport, and this is in progress on the network thread.
Attachment #8354551 - Flags: review?(aleth)
Comment on attachment 8354551 [details] [diff] [review]
Follow-up fix

*** Original change on bio 1994 attmnt 2782 at 2013-08-25 12:59:37 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354551 - Flags: review?(aleth) → review+
*** Original post on bio 1994 at 2013-08-25 23:03:44 UTC ***

Comment on attachment 8354551 [details] [diff] [review] (bio-attmnt 2782)
Follow-up fix

http://hg.instantbird.org/instantbird/rev/3a003ed296a6
*** Original post on bio 1994 at 2013-08-26 10:20:25 UTC ***

(In reply to comment #26)
> For the curious, the status change that we are trying to log is
> STATUS_SENDING_TO because we send the string "QUIT :Instantbird 1.5a1pre --
> http://www.instantbird.com" just before closing the transport, and this is in
> progress on the network thread.

I wonder if something around this is the cause of bug 954748 (bio 1316) ?
Depends on: 955572
Depends on: 955623
You need to log in before you can comment on or make changes to this bug.