Bug 1055176 - ktp: "got error: SSL Negotiated: Connection got disconnected"
Summary: ktp: "got error: SSL Negotiated: Connection got disconnected"
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Fedora
Classification: Fedora
Component: ktp-auth-handler
Version: 20
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Jaroslav Reznik
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-01-19 11:54 UTC by Martin Kho
Modified: 2014-03-25 12:28 UTC (History)
6 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2014-03-18 13:53:20 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
Output of tab Mission Control (ktp-debugger) (71.29 KB, text/plain)
2014-01-19 11:54 UTC, Martin Kho
no flags Details
mc_good.debug (92.93 KB, text/plain)
2014-03-17 18:33 UTC, Martin Kho
no flags Details
mc_bad.debug (31.97 KB, text/plain)
2014-03-17 18:33 UTC, Martin Kho
no flags Details

Description Martin Kho 2014-01-19 11:54:35 UTC
Created attachment 852347 [details]
Output of tab Mission Control (ktp-debugger)

Description of problem:
After log in ktp does not reconnect (status "available"). Sometimes it reconnects after a long time (see attached output of mission conrol), most of the time it doesn't. The output shows the following errro: "on_connection_ready: got error: SSL Negotiated: Connection got disconnected: Connection got disconnected"

Version-Release number of selected component (if applicable):
ktp-auth-handler-0.7.0-1.fc20.x86_64

How reproducible:
always

Steps to Reproduce:
1. log in (ktp tries to connect, cycling icon)
2. 
3.

Actual results:
reconnection fails

Expected results:
ktp reconnects

Additional info:
The same version in Fedora 19 connects just fine. It only is an issue in Fedora 20 and higher. If I can remember it right, it started after the transition of kde-plasma-networkmanagement to kde-plasma-nm.

Comment 1 Martin Kho 2014-03-14 20:42:42 UTC
Hi,

The issue has to do with telepathy-mission-control. I downgraded this package to version 5.14.1-2 (was 5.16.1-1.fc20) and ktp connects as expected. I'll try to find out which commit made it stop working.

Martin Kho

P.S. Does this report need to be redirected to package 'telepathy-mission-control'?

Comment 2 Martin Kho 2014-03-14 21:18:14 UTC
Hi,

It looks like the culprit is somewhere in commit:

McdSlacker: Use org.gnome.SessionManager DBus service:
1d3403089ab01ff5b5056cd360d5469099d0ff08

or

McdSlacker: don't crash if SessionManager is absent or StatusChanged has no parameters
7877d99ed2f9ff2cd0888e8f762ebad932852767

The other commits between version 5.14.1-2 and 5.15.0 didn't contain any 'code'. Versions 5,15.0 and higher all fail.

HTH

Martin Kho

Comment 3 Martin Kho 2014-03-16 11:20:35 UTC
Hi,

Hum... I'm afraid this issue is not a bug, but by design. Telepathy-mission-control has been made a 'Gnome-ish' component, because it now depence on Gnome's SessionManager.

I'm not sure if it would be better to drop ktp and use kopete as the default IM-client - for the time being. Now ktp gives - at least for me - a rather annoying experience.

Martin Kho

Comment 4 Martin Kho 2014-03-17 15:31:22 UTC
Closing, using Kopete now.

Thanks,

Martin Kho

Comment 5 Rex Dieter 2014-03-17 15:34:34 UTC
Do you have any references to support the claim:
Telepathy-mission-control has been made a 'Gnome-ish' component, because it now depends on Gnome's SessionManager.
??

Do you know if kde telepathy upstream aware of this?  If not, I'll bring it to their attention.

Comment 6 Rex Dieter 2014-03-17 15:40:09 UTC
Also, any hints on how to reproduce this?  I'm currently using ktp via jabber for facebook and google accounts, and I don't recall ever seeing this.

Comment 7 Rex Dieter 2014-03-17 17:45:04 UTC
Fwiw, I am seeing just now:

Could not connect rdieter. There was a network error, check your connection

may or may not be related to this bug (the connection error is different)

Comment 8 Martin Kho 2014-03-17 17:58:25 UTC
Hi Rex,

I based my 'assumptions' on the source code [1] and a bugreport [2].

#comment6: I'm using a google account too with 2-way authentication. Ktp's default Account settings, Away After 15 minutes, Not available After 30 minutes. disabled Go offline when closing the contact list and enabled Restore last presence on login. Further is everything default. So concrete hints are difficult to give. I only found that downgrading telepathy-mission-control 'solved' this issue. Btw. in the system log (journalctl) I see "gnome-keyring-daemon[1059]: couldn't set environment variable in session: The name org.gnome.SessionManager was not provided by any .service files" 

#comment7: I see that one too. Seems to me a Google issue and not (?) related to this problem.

HTH


Martin Kho



[1] http://cgit.freedesktop.org/telepathy/telepathy-mission-control/commit/?id=1d3403089ab01ff5b5056cd360d5469099d0ff08

[2] https://bugs.freedesktop.org/show_bug.cgi?id=62530

Comment 9 Martin Kho 2014-03-17 18:32:15 UTC
Hi,

I found some more info by running:

qdbus --literal org.freedesktop.Telepathy.MissionControl5 /org/freedesktop/Telepathy/debug org.freedesktop.Telepathy.Debug.GetMessages |sed -e "s/\[Argument:/\r\n\[Argument:/g" > mc_[good]/[bad].debug (see attachments)

In mc_good.debug I also see: "mcd_connection_invalidated_cb: Proxy destroyed (SSL Negotiated: Connection got disconnected: Connection got disconnected)!"]
but somewhat further below:
"mcd_connection_invalidated_cb: Preparing for reconnection in 3 seconds"],

In mc_bad.debug I see: "mcd_connection_invalidated_cb: Proxy destroyed (SSL Negotiated: Connection got disconnected: Connection got disconnected)!"],
and
"connection_should_reconnect: error code org.freedesktop.Telepathy.Error.Cancelled, not reconnecting"],

So it seems that it's not the SSL Negotiation causes the problem, but the fact that Connection is not reconnecting.

Martin Kho

Comment 10 Martin Kho 2014-03-17 18:33:07 UTC
Created attachment 875618 [details]
mc_good.debug

Comment 11 Martin Kho 2014-03-17 18:33:40 UTC
Created attachment 875619 [details]
mc_bad.debug

Comment 12 Martin Kho 2014-03-17 18:51:22 UTC
Hi,

Some more info:

In the window "Accounts - KDE Control Module I get the message "Cancelled by user". That's a nice message, I just logged in and didn't do anything else :-)

Martin Kho

Comment 13 Martin Klapetek 2014-03-17 20:27:18 UTC
Running KTp on Kubuntu with MC 5.16.1 works just fine, there is no Gnome SessionManager installed, so maybe that is unrelated.

Comment 14 Martin Kho 2014-03-18 10:28:03 UTC
Hi,

Okay, it seems that I'm the only one with this issue. As I said I'm using Kopete now and that's fine.

Can you please close this report.

Thanks,


Martin Kho

Comment 15 Rex Dieter 2014-03-18 13:53:20 UTC
ok

Comment 16 Martin Kho 2014-03-23 11:34:11 UTC
Hi,

I did some more work and like to reopen this report. 

1. I compared working code (from v5.15.0) vs non working code (v5.14.1). This brought me to the file mcd-connection.c.
2. After some bisecting I came to commit [1]: "Check for the specific error codes when reconnecting"

In the working version the decision to reconnect was based on a disconnect reason. In the failing version this was changed to 'some specific error code'. Don't know where this code is comming from (DBus?).

The error "SSL Negotiated: Connection was closed" looks to me not in line with connection was Cancel by user, resulting on not reconnecting (TP_ERROR_CANCELLED). In the working version the error was seen as a Network-error (TP_CONNECTION_STATUS_REASON_NETWORK_ERROR).

Btw. Of course the error still stands. I get it in the working version too. It started happening somewhere in the 0.6 series.

HTH

Martin Kho

[1] http://cgit.freedesktop.org/telepathy/telepathy-mission-control/commit/?id=9b04e1ba0a4cfe74345cb6eaa0496b3348e9a24a

Comment 17 Martin Kho 2014-03-25 11:00:18 UTC
Hi,

Did some test with other distro's:

1. Kubuntu 13.10
* telepathy-gabber: 0.18.1-1
* telepathy-mission-control: 5.14.1-1ubuntu6
a. ktp: 0.6.3-0ubuntu1: automatically connects immediatly after login. no errors
b. ktp: 0.7.0-0ubuntu1~-0ubuntu13.10.1~ppa1: automatically connects after ca. 20sec. with "SSL Negotiated: connection got disconnected" error

* telepathy-mission-control: 5.16.1-1ubuntu1 [1]
automatic connect fails after login. ps aux shows: Z [debus-deamon] <defunct>

[1] https://launchpad.net/ubuntu/+source/telepathy-mission-control-5

2. openSUSE 13.1
* telepathy-gabble-0.18.1-2.1.3.x86_64
* telepathy-mission-control-5.16.0-1.1.x86_64
* ktp: 0.8.0-13.1.x86_64: automatic connect fails after login. ps aux shows: Z [debus-deamon] <defunct>

So the basic problem lies IMHO somewhere in the update from ktp 0.6.3 to 0.7.0. The updated telepathy-mission-control only triggers and fails on this bug. I've no idee where to search. Maybe ktp-auth-handler? Is this easily to debug?

#comment 16: My memmory wasn't to good. The errors started happening after the 0.6 series like I've found in Kubuntu.

Martin Kho

Comment 18 Martin Kho 2014-03-25 12:28:41 UTC
Hi,

Got it! The culprit is in the Kded Integration Module. I moved /usr/share/dbus-1/services/org.freedesktop.Telepathy.Client.KTp.KdedIntegrationModule.service out off the way. Now ktp connect immediately without any errors.

Now I'll try to find out what's going wrong.

I'll keep you informed.

Martin Kho


Note You need to log in before you can comment on or make changes to this bug.