Bug 59668 - "Force closing of the connection" for no apparent reason
Summary: "Force closing of the connection" for no apparent reason
Status: NEW
Alias: None
Product: Telepathy
Classification: Unclassified
Component: gabble (show other bugs)
Version: unspecified
Hardware: x86 (IA32) All
: medium normal
Assignee: Telepathy bugs list
QA Contact: Telepathy bugs list
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2013-01-21 16:00 UTC by Dennis Schridde
Modified: 2013-01-22 20:14 UTC (History)
1 user (show)

See Also:
i915 platform:
i915 features:


Attachments
Gabble log, anonymised (205.48 KB, text/plain)
2013-01-21 16:00 UTC, Dennis Schridde
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Dennis Schridde 2013-01-21 16:00:12 UTC
Created attachment 73389 [details]
Gabble log, anonymised

Gabble seems to close connections for no apparent reason. In Telepathy/KDE the symptom is the message "The connection was cancelled on your request", without the user making any request.

For me, this often happens with my Facebook account, and when it happens, it goes like this: Telepathy establishes a connection, then immediately claims that I cancelled it, and reconnects - repeating this over and over again.

Sometimes the Facebook account works without issues, though. Today it happens all the time, while on other days it works fine. So it might have something to do with the Facebook servers sending something Gabble does not understand.

When it happened today, I was able to create a log. First some network errors appeared, until Telepathy was finally able to establish a connection - maybe that is another bug, but at least it is probably not related. However, then I made an interesting observation:
(telepathy-gabble:32573): gabble-DEBUG: remote_error_cb (connection.c:1718): Force closing of the connection 0x8309228

Could this be the reason for the connection being cancelled "on my request"?

See also: https://bugs.kde.org/show_bug.cgi?id=285172
Comment 1 Dennis Schridde 2013-01-21 16:10:38 UTC
This is on Ubuntu 12.04/Precise with telepathy-gabble-0.16.0-0ubuntu2 and kde-telepathy-0.5.2-0ubuntu1~ubuntu12.04.1~ppa1.
Comment 2 Simon McVittie 2013-01-21 20:16:22 UTC
Do you have more than one XMPP account? If you do, it would be helpful to disable all of them except the one with the problem while capturing the log.

> (telepathy-gabble:32573): gabble-DEBUG: connector_error_disconnect (connection.c:1772): connection failed: WOCKY_CONNECTOR_ERROR_TLS_SESSION_FAILED (#7): TLS handshake error: -9: GNUTLS_E_UNEXPECTED_PACKET_LENGTH

That might be something to do with it? If the server is getting TLS wrong somehow, I would expect strange error behaviour.

> (telepathy-gabble:32573): gabble-DEBUG: remote_error_cb (connection.c:1718): Force closing of the connection 0x8309228
> (telepathy-gabble:32573): tp-glib/connection-DEBUG: tp_base_connection_change_status: was 0, now 2, for reason 0

Reason 0 is None_Specified, which is ... unhelpful. remote_error_cb ought to log a debug message with the error it received, before it translates it into Telepathy terminology. The next step for anyone who wants to pick this up (probably not me, I'm afraid) would be to add that debug message.

"Force closing" just means the connection has basically already died, and now we're cleaning up the mess.

> In Telepathy/KDE the symptom is the message "The connection was cancelled on your request", without the user making any request.

I would expect this to mean TP_CONNECTION_STATUS_REASON_REQUESTED, which is 1, but I don't see any changes to status 2 (DISCONNECTED) for reason 1 (REQUESTED) in your log: the only changes to status 2 that I can see are for reasons 0 (NONE_SPECIFIED) or 2 (NETWORK_ERROR).
Comment 3 Dennis Schridde 2013-01-22 20:14:39 UTC
(In reply to comment #2)
> Do you have more than one XMPP account? If you do, it would be helpful to
> disable all of them except the one with the problem while capturing the log.
I already disabled all of them but the Facebook account.

> > (telepathy-gabble:32573): gabble-DEBUG: connector_error_disconnect (connection.c:1772): connection failed: WOCKY_CONNECTOR_ERROR_TLS_SESSION_FAILED (#7): TLS handshake error: -9: GNUTLS_E_UNEXPECTED_PACKET_LENGTH
> 
> That might be something to do with it? If the server is getting TLS wrong
> somehow, I would expect strange error behaviour.
I assume this is one of the network errors that Telepathy reported, before it was able to connect the first time.

That is this part of my original report:
> First some network errors appeared, until Telepathy was finally able to
> establish a connection - maybe that is another bug, but at least it is 
> probably not related.

If you already kept that in mind while reading the log, of course this might be the actual reason.

> > In Telepathy/KDE the symptom is the message "The connection was cancelled on your request", without the user making any request.
> 
> I would expect this to mean TP_CONNECTION_STATUS_REASON_REQUESTED, which is
> 1, but I don't see any changes to status 2 (DISCONNECTED) for reason 1
> (REQUESTED) in your log: the only changes to status 2 that I can see are for
> reasons 0 (NONE_SPECIFIED) or 2 (NETWORK_ERROR).
So there are two bugs? For one Telepathy disconnects for unknown reasons, and then Telepathy/KDE also displays a wrong and misleading message about it?


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.