Bug 285172 - "Connection canceled on your request" error while no request made
Summary: "Connection canceled on your request" error while no request made
Status: RESOLVED FIXED
Alias: None
Product: telepathy
Classification: Frameworks and Libraries
Component: general (show other bugs)
Version: git-latest
Platform: Unlisted Binaries Linux
: NOR normal
Target Milestone: Future
Assignee: Telepathy Bugs
URL:
Keywords:
: 302819 (view as bug list)
Depends on:
Blocks:
 
Reported: 2011-10-28 13:34 UTC by Daniele E. Domenichelli
Modified: 2014-04-10 12:43 UTC (History)
10 users (show)

See Also:
Latest Commit:
Version Fixed In: 0.6.1


Attachments
kde-telepathy-debugger (294.80 KB, image/png)
2012-11-12 01:37 UTC, Myc
Details
Gabble log, anonymised (deleted)
2013-01-21 15:07 UTC, Dennis Schridde
Details
Gabble log, anonymised (deleted)
2013-01-21 15:18 UTC, Dennis Schridde
Details
Script I used to anonymise the log (611 bytes, application/x-shellscript)
2013-01-21 15:19 UTC, Dennis Schridde
Details
Gabble log, anonymised (205.48 KB, text/x-log)
2013-01-22 10:26 UTC, Dennis Schridde
Details
Output from dbus-monitor (144.78 KB, text/plain)
2014-03-26 10:53 UTC, Martin Kho
Details
Output from dbus-monitor manual connect. (516.20 KB, text/plain)
2014-03-26 11:30 UTC, Martin Kho
Details
xsession-errors_fail (301.39 KB, text/plain)
2014-03-29 22:39 UTC, Martin Kho
Details
xsession-errors_ok (354.63 KB, text/plain)
2014-03-29 22:39 UTC, Martin Kho
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Daniele E. Domenichelli 2011-10-28 13:34:29 UTC
I didn't cancel anything, but suddenly I got this notification [1]

    "The connection was canceled on your request"

I have no idea about which component displayed this error (therefore I'm setting it to common-internals) and for which reason, but for sure I didn't cancel anything.

[1] http://simplest-image-hosting.net/png-0-snapshot290


As a side bug I think that it is nice that all the components show errors as a single app, but at the same time it should be possible to know which component is showing that error or it will soon become impossible to debug. Perhaps we just need to add to the string the i18n'ed name of the component. Comments?
Comment 1 josuicida 2012-04-05 14:36:35 UTC
Same problem here. Can't connect to facebook, msn nor gtalk.

KDE 4.8.2 on ArchLinux
Comment 2 David Edmundson 2012-04-05 14:38:27 UTC
I'm afraid we need more information.

We need the logs from Gabble, the program that talks to Jabber networks.

http://martys.typepad.com/blog/2011/12/kde-telepathy-now-depends-on-telepathy-qt4-09-also-how-to-report-bugs.html
Comment 3 josuicida 2012-04-05 15:01:13 UTC
My mistake, previous packages from aur providing old telepathy-qt4
All ok after updating telepathy-qt4 package, sorry :)
Comment 4 Daniele E. Domenichelli 2012-04-05 16:08:38 UTC
Closing this, because I stopped having this kind of notification a lot of time ago, probably was fixed upstream
Comment 5 Martin Klapetek 2012-07-01 09:04:22 UTC
*** Bug 302819 has been marked as a duplicate of this bug. ***
Comment 6 Myc 2012-11-12 00:13:35 UTC
Needs to be reopened as it makes the IM client useless.
Comment 7 David Edmundson 2012-11-12 01:23:19 UTC
In order to fix this, we need to know why the backends are emitting this. 

I need a debug log from mission-control and gabble when this message is shown. 
(run ktp-debugger, copy and paste output)
Comment 8 Myc 2012-11-12 01:37:30 UTC
Created attachment 75188 [details]
kde-telepathy-debugger
Comment 9 Myc 2012-11-12 01:38:33 UTC
myc@Anonymau5:~$ ktp-debugger
Fontconfig warning: "/etc/fonts/conf.d/50-user.conf", line 9: reading configurations from ~/.fonts.conf is deprecated.
ktp-debugger(4693) KXMLGUIClient::setXMLFile: cannot find .rc file "ktp-debuggerui.rc" for component "ktp-debugger" 
tp-qt 0.9.3 DEBUG: Creating new DBusProxy  
tp-qt 0.9.3 DEBUG: ReadinessHelper: new supportedStatuses = QSet(0)  
tp-qt 0.9.3 DEBUG: ReadinessHelper: new supportedFeatures = QSet(QPair("Tp::DebugReceiver",0) )   
tp-qt 0.9.3 DEBUG: Creating new DBusProxy  
tp-qt 0.9.3 DEBUG: ReadinessHelper: new supportedStatuses = QSet(0)  
tp-qt 0.9.3 DEBUG: ReadinessHelper: new supportedFeatures = QSet(QPair("Tp::DebugReceiver",0) )   
tp-qt 0.9.3 DEBUG: Got reply to PendingVariantMap call  
tp-qt 0.9.3 DEBUG: Got reply to PendingVariantMap call  
tp-qt 0.9.3 DEBUG: ReadinessHelper::setIntrospectCompleted: feature: QPair("Tp::DebugReceiver",0) - success: true  
tp-qt 0.9.3 DEBUG: ReadinessHelper::setIntrospectCompleted: feature: QPair("Tp::DebugReceiver",0) - success: true  
I also included a screencap of kde-telepathy-debugger as I am not sure all of what you want.
Comment 10 Martin Klapetek 2012-11-12 10:57:47 UTC
David forgot to mention to use ktp-debugger from master or kde-telepathy-0.5 branch (of ktp-common-internals), which actually allows you to copy stuff from it. Then you should copy and paste the output you see inside the debugger. 

You can just get the code from git, compile and run in place, you don't need to install the library and mess your packaged install ;) You just need telepathy-qt-dev package installed.

In order to do so, follow these:

git clone git://anongit.kde.org/ktp-common-internals ktp-c-i
cd ktp-c-i
mkdir build && cd build
cmake ..

If you see "Build files were written to:...", you're good to go. If you see some missing dependencies, just install them using your package manager (and their -dev versions too) and run cmake .. again. Then continue:

make -j3
./tools/debugger/ktp-debugger

...and you should be running the "useful" debugger :)
Comment 11 Myc 2012-11-13 05:34:23 UTC
I am getting this so far as I don't see what dependencies are missing. 
myc@Anonymau5:~/ktp-c-i/build$ cmake ..
-- The CXX compiler identification is unknown
CMake Error: your CXX compiler: "CMAKE_CXX_COMPILER-NOTFOUND" was not found.   Please set CMAKE_CXX_COMPILER to a valid compiler path or name.
CMake Error at /usr/share/cmake-2.8/Modules/FindKDE4.cmake:98 (MESSAGE):
  ERROR: cmake/modules/FindKDE4Internal.cmake not found in
  /home/myc/.kde/share/apps;/usr/share/kubuntu-default-settings/kde4-profile/default/share/apps;/usr/share/kde4/apps
Call Stack (most recent call first):
  CMakeLists.txt:12 (find_package)


CMake Warning (dev) in CMakeLists.txt:
  No cmake_minimum_required command is present.  A line of code such as

    cmake_minimum_required(VERSION 2.8)

  should be added at the top of the file.  The version specified may be lower
  if you wish to support older CMake versions for this project.  For more
  information run "cmake --help-policy CMP0000".
This warning is for project developers.  Use -Wno-dev to suppress it.

-- Configuring incomplete, errors occurred!
Comment 12 Martin Klapetek 2012-11-13 12:04:37 UTC
Which distro are you using? If Ubuntu, then install build-essential package, in any other you'll need to install gcc and possibly some other packages.
Comment 13 Myc 2012-11-14 01:15:22 UTC
I am using kubuntu.  I installed build-essential.
This is the error I ran into.
/ktp-c-i/build$ cmake ..
-- The C compiler identification is GNU 4.7.2
-- The CXX compiler identification is GNU 4.7.2
-- Check for working C compiler: /usr/bin/gcc
-- Check for working C compiler: /usr/bin/gcc -- works
-- Detecting C compiler ABI info
-- Detecting C compiler ABI info - done
-- Check for working CXX compiler: /usr/bin/c++
-- Check for working CXX compiler: /usr/bin/c++ -- works
-- Detecting CXX compiler ABI info
-- Detecting CXX compiler ABI info - done
CMake Error at /usr/share/cmake-2.8/Modules/FindKDE4.cmake:98 (MESSAGE):
  ERROR: cmake/modules/FindKDE4Internal.cmake not found in
  /home/myc/.kde/share/apps;/usr/share/kubuntu-default-settings/kde4-profile/default/share/apps;/usr/share/kde4/apps
Call Stack (most recent call first):
  CMakeLists.txt:12 (find_package)


CMake Warning (dev) in CMakeLists.txt:
  No cmake_minimum_required command is present.  A line of code such as

    cmake_minimum_required(VERSION 2.8)

  should be added at the top of the file.  The version specified may be lower
  if you wish to support older CMake versions for this project.  For more
  information run "cmake --help-policy CMP0000".
This warning is for project developers.  Use -Wno-dev to suppress it.

-- Configuring incomplete, errors occurred!
Comment 14 Rohan Garg 2012-11-14 01:29:05 UTC
Nifty tip for anyone running debian/debian-based distros : sudo apt-get build-dep kde-telepathy-debugger

^ Installs all required build deps
Comment 15 Myc 2012-11-14 06:52:37 UTC
(In reply to comment #14)
> Nifty tip for anyone running debian/debian-based distros : sudo apt-get
> build-dep kde-telepathy-debugger
> 
> ^ Installs all required build deps

Fixed that issue.

Here is dump.
11/13/2012 22:49:58.224528 - [gabble/roster] _gabble_roster_item_maybe_remove (roster.c:488): contact#130 is still on the roster
11/13/2012 22:49:58.333997 - [gabble/media-channel] stun_server_resolved_cb (jingle-info.c:273): Resolved STUN server stun.telepathy.im:3478 to 93.93.128.223:3478
11/13/2012 22:49:58.370146 - [wocky] _end_element_ns: Received stanza
* iq xmlns='jabber:client' type='error' to='mycclark@gmail.com/kde-telepa85FE5991' id='7375673757' from='gmail.com'
    * query xmlns='http://jabber.org/protocol/disco#items'
    * error code='501' type='cancel'
        * feature-not-implemented xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'
11/13/2012 22:49:58.370204 - [gabble/disco] disco_items_cb (disco.c:726): Got error on items request: 
11/13/2012 22:49:58.370218 - [gabble/search] disco_done_cb (search-manager.c:137): Disco is done; complete pending requests
11/13/2012 22:49:58.372452 - [wocky] _end_element_ns: Received stanza
* iq xmlns='jabber:client' type='error' id='7425374284' to='mycclark@gmail.com/kde-telepa85FE5991'
    * pubsub xmlns='http://jabber.org/protocol/pubsub'
        * publish node='http://laptop.org/xmpp/activities'
            * item
                * activities xmlns='http://laptop.org/xmpp/activities'
    * error code='501' type='cancel'
        * feature-not-implemented xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'
11/13/2012 22:49:58.372832 - [wocky] _end_element_ns: Received stanza
* iq xmlns='jabber:client' type='error' id='7425274315' to='mycclark@gmail.com/kde-telepa85FE5991'
    * pubsub xmlns='http://jabber.org/protocol/pubsub'
        * publish node='http://laptop.org/xmpp/activity-properties'
            * item
                * activities xmlns='http://laptop.org/xmpp/activity-properties'
    * error code='501' type='cancel'
        * feature-not-implemented xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'
11/13/2012 22:49:58.373123 - [wocky] _error: wocky-xmpp-reader.c:633: Ignoring parser warning: xmlns: URI vcard-temp is not absolute

11/13/2012 22:49:58.374700 - [wocky] _end_element_ns: Received stanza
* iq xmlns='jabber:client' to='mycclark@gmail.com/kde-telepa85FE5991' id='7578775849' type='result'
    * vCard xmlns='vcard-temp'
        * FN
            "Myc Clark"
        * PHOTO
            * TYPE
                "image/jpeg"
            * BINVAL
                "/9j/4AAQSkZJRgABAQAAAQABAAD/2wCEAAUDBBAQDREQEBAPDQ8SDxIQEA4QDxAQDxAOEA8LDBAQEA0QDhAQDQ0RDQ0QDhYMEhERHxQTDw4WGRgTJBATFRUBBQUFCAcIDwkJDxcSEhQeFxQXGhcXHhYXFR4cHh4YFRgSFB4TFBQSFBYaFBgWFB0VHRcUFB4WEhcWFB4WFRUUFP/AABEIAGAAYAMBIgACEQEDEQH/xAAcAAACAgMBAQAAAAAAAAAAAAAGBwQFAQMIAgD/xAA4EAACAgEDAwMCBAMGBwEAAAABAgMREgAEIQUTMQYiQQdRFDJhcSOBkTNCUqGx8BUkU3KCwdEI/8QAGQEAAgMBAAAAAAAAAAAAAAAAAwQBAgUA/8QALBEAAQMCBAQHAAMBAAAAAAAAAQACEQMhEjFB8ARRYXETIoGRobHBFNHhBf/aAAwDAQACEQMRAD8A45O3assTiTQajRP2B8X+msjav5xbxfg+PF+PH666y9S7OJtls1gQtMHdVDRsEp1LMTmgV3VafIEHFSBQJ0tfrf0U7Vo4knknTtg+5BGY37gMqAqiFkOeQUg1RonRqtE0xKzqfH47Re2v+aJKvAw8gj9wdfRwMbpSa80CavxdeNFXqGUyShVJKDxj5xYZX+UkgEn281yOK4bv00gUwfhXWJCv8VJYwAJI2Kr3cqJdw47ZU2bKL4HAWebNMsrktkhc7mBrqjf2o3/TWHQg0QQft4P9NH/qzdK+4ZUQjtyFS5IXwQDRK2fvzVcGudY3MAlUiQcg0H4y4+cgefNUfnRPDvCt414IQAiEmgCT9vJ/pr0IzV0aHk/AJBIBPiyATXzR+2rF4zDIrKbo2L45+39NF/ph4mV4SwwlvAkC0lpyh880SvtNWA/m71XCVcvtKXhH+/8Af7asB0Sar7MtEWD23ojzYNeK5vWtJwQwI4x4AHgggg/oLsf+RGutvTHr9JeiO0amOWLbYuhjIQOQIlwasSsjU2KmwSw48atTZjMIdat4YkhckQ9OkYFhG7KotmCMQoq7JAoCubPxrWdk/t9r+4WvtPuH3HHuFfIvXRfprrKwdNaAMnf3E6xtGGXOOJqjt1skKVXyQOGA+CdTfqZtE3EoO2ZEl2SRpAuXExQoWwKgACwRZP5UA/vaY/idUof+hhMObCZnV8hvIFTIFY0VQyAxo25lECyM3mkERQICbLVxdql/X/oLfbv8RvBJlAr0GncZySK3bVI0RGCtbCMk9tQchyBZP/T2+7mxdwyyk9TkkBAoFUqWM80T7MG+aPPxq29ddIjE+ULiKPcAyTxxys0cswMDpIYiAsLqvtYqTkCAfyg6vxFFz3CMsoWbSqimSTp/dt9Uqvob6QZd3I0qrcmyyjK2UMUxePuqzAY2IpCrmhjR5DA6LH9NrtJoboUTIoYUpll7iEDI3Gu528VhSfbKtCsr1r6r6gZH2syQncSwxGKFFdY4vw8ZgQAEkSLKzkO0hUBSQi3jqo6/62n3ETwspg6j+IcHbOjSd3bNElh+CsjIwkoKA2QQqB3HBQiQCFq0ntqsscoS5fatLvd20a5oNxISzEIvudqXImgxogCvgHjXv0+rTF40Fe7kUD7hVgnmgTXJ8kH7i8fTNtxk+zVSgldHkBCB1ZAQpiMgpWbLkHg0viqL42HpQ7PatI6BIUXIs00bOAAfdIR7WcmyVW+eBfkla46ormdEmPVXRESNlKgsADeJ+/zZJ55/p8aXu2zgOYUMhOQBJ8KTi1iiCL/Xg0Qb1fetvWzTylgpWPFQimshTBixPItrK43wCD+86CESbcmvAU1R8N7SD8/B4/Q6tIfkrYXU89VWekemxOoJIXK1KnihTknK7+B8/wCGq029v1FBCyQqIYHcSNGa/iOoVQbPIiUBWBJ+AedJ/wBP9JB3DKSe0gycHxZql8cggZV8gEG/BvesdXeSRIowuRORyvBY18Fqri/dVmzxzdaZ4doaMZ7DqitaJk35Jk7XeRArNSMyC0duEBIONiwCqkhgCfI+dMT0N1fYTQRQ7aaOSZXQupI77ssqyyMaJyUsS3tJAFDiq0jekdKDtbs0z/8AUIVitij2lYGKAXRtg7EcVxWpG49PdOjlyZgkoIZQNwVZXBDAghkIa+RRFGvFaZqB7oIgeqpW4VlW+RRh0j0xC57SNLGyTbpwq5rEcsUjFAAKqiRGUL5W1Ng1qy9WI0Oy2Ty0ksSJFIA1cyCMG1XgL3E95A8MDzjWqzp3q6USsWdMNvso2fMAZ7ycosYZwjFVOSjEAeSSDxRZJ6zWOLYPuVDtNMkczqtqjivciFqKoacSAcKCRdahr4uFgvpkmDrvfosbrpCjapI0ZkUq6tIoLt2p5FZCVFnDONkyUGiEPAfjfvvS87tIkUwZlYTw7sKpm7kY/h2QQsmcZYE/31VxwTeiJx2xHtWV1R0eNJr99tJatZGIVyAQCoxcKaFkasPQfVY2327jRgJVWOVosSF9wZWeOwaByIIBPLeATelqlIR9fnt8KaHleC3pPtr8JUepvS/dO33iRxRtJEJZRKKXbyKF/FWCAwWJyrAcWr1wCDqp9XeuUl2kYdn3u4a+3FiUgiALKsx26ggGgHUMSVyILCmGnz649GxPt5IUcwLunxJAMg7koRDWbEJG4jjDRJQ9goC2tR9T6K+z2jCCOJp1cRSTWWXJnKmVVYK0oxBbFqwKqLf5TqYxkPXeS3qFSjcuN9Acu559AInW1jz36i2axri9mawWU/3FJAtj8MxyuMnxia5sEXpLcKsThj7ZI5EBJ5DU4QE8+7Jiv76k7z0jIkHenWSpMGCzf2ryMFRFINsFU0bIF+BQB1pl6TjtGY0UMjYsLA4bk/upGQ/T99TTPmgItVhdTxO5gd5z9oHuqaPZOjM+Yp+WQLfiwvNg2Lrgc3XzqPHsZVmIcMDIA2F4qEF13ZAOFWuYx5ah86mQdUC5SMMsfyi7GVA35qwPaP1vU31Tt5k2qbgS7aXuVl2pspYiQWCSQMiMhUfoRZuzp1/hsbcxv90VWyclI325KbdiOSqeKxDV4BUGxGo8ReAPN3ehn0vvow3demevDflRQwBxU3wUYsDRrFh86shucoiLJGNG+bsVfJ5sG/5/Ohv/AIeGgDKadbyH3AJBr+Qv/LVqpMgtvquDk0/TPp3c7ppdps4Wmlk3XcxZiETaQMyRySzSHH3OOLJLY8A2AW1tfoV1YwRosOxjMbLIt7yQgGpBeA27KC2ZJOR8EeKAifQ/bhOhR77aqX3a9UC70lnVRG7nbiOTD3PtY4Nyk2AyClnfjEkH/wBI+ndQTdMUUhtltdvtZY5O6qbyOCfqm2KwZvgvESSx7h8iR2waEjHSRrumyAOFpkXEpaevfWsqNtm3qwQmHcPt59vCWLxGIly2OVlXiTuran2vGQRdat+h7aV91LJs4Q8iTqy7iZgrJnHGzwsjENbxFW7QAWyr8FmItP8A9WMH3G22rQQ7WXfOW3MkTK080cMiwQJJMIlLIkTR7pozYBiCDIJmdHoHeSbVp42dNyzSr25ImB/iIkcLK/NJ+XPBvBku/LaYpVHOas+vQYx9p3lvst/UOvyuVDuUdd0TJHGjD8O0cG43JJLg5uRCWBoqSQOfmKN+8sSKkIcpFJJuAzFWQOcyAQHDOImibAhcg1+2q1bdf30LhN1OssTEmA4g9wM+cTR7iKPiTCNjTgDEWbo3om3Ue32u4ARspdwABDai1hjpmJFYrggBJuiKHng2PkEt4Uk4jvYCRfUekTboxdkrOsi2u7ncFdvGoU0qVk0jgqUclqLgEJizaFfrF/y+3j2qlWwVu6VAALsaQBcmpWGZqzWI+/LY9YesNhEsXZhTcxTxydnbxxmNBIe0isKUKFIEoLKT4bwC2PPX1XkCLHEOW8scixLDzbN7nq8cm88ni60myiGS4ZbgLefx9SvgY+LchA6mBqYvKG5puEH3YMf5e/8A1rVT1vcZSE/ah/TWdxJyP0X7/pqBeuqvmys0Io6bu7zUeAR/kqr/AKrqFs91hI48A/8Ay/8AMHUbpElWf1/0s/8AvWz8I8khEau7AZEIpYhV5LEKD7QKsnxq5qw0OKjDeE1PR3WZ9nuJDtd1Ls+5CJFDIrJJjcUivt51YO4kjkxLIPyE2oAOiB/rR1Rt92Nz1SSOMYjuxLto1txGVJeOAAqM7NDgAn40I/Vb1QZ5VZcWSNhTqrWEbEUWawffyDiOeB8kicfTQ7O3djUC8lZqlYUPCnIMKJGQrknXVgxufP7SXCirUyNoPpGZ9kcbL1MT1VJNzKZ3R2Mm6eR5O8qBkVFZUGK4kAUo5JJAyOi/6b+tw+7ewu2TcpahVUAyjMsrMFJRnUDGUEe6OrHACT2HVGgklMYDL28AGHgHA5UD+YBccgQQD5+NSd70WVIMmkV47/s2EqOobBu4VeMZJlIGyVnuif11IeWiI3uVDqLXmSd7hdQ+t+ktLvdsu1AnVSZJUaUiIuGUAM1M1KoYEqBWQ85e2F65aSQvu5cNtK2W1gWMSyOYxIDK4j7QtgIpArshyJQkENWon083UyQ05jiiwiXbcEqodEWzmbP8RgmBq6YgDOtMDeylI4SHHsiMNl1IVbjLkigwDNGrHIEexSpPnTA0WcTc73mgHoLRydKict2Yo4ZHjAKlUlHcOMuK+xCCwDAmlJNDka54+rrHvKrKUdcldbBAYFQaYeRYI5A5B02/UPrYLDJHtlyjdye+ECoKKMI4ENB2BS+8fYAzHngHn71D1BpZWdySWYnyTwSW4J+Dd/H7DQK9Ty4QtLhKTsWI2VeWOvGrrert/wAPEUM34i3EysF7QFkxmJlORtaDBh+a64rVLpKZWjC2JIRqV03qUkbZRyPE1EZI5RsW4ItSDRHBX51B19rjcQVAtdHI6myJOqMY1cRqYweHGasA7nkqpGXFX48EjWnpO7oSEgGPLKvHI4/MAWrhRjZ8g6Dix1i9GNaSCRklhw8NIxG9rW5W+EdbuKHtNIWAmnUf8t2XXtR0MZVlIWJ1YCqH3/QnVtt/WF7ZRIwZEj7CxmPJhEq+xgxxVspJGUqTaqpPPtGlo8zGrJNChZJoDwB9gPtrxkdQyoRM3z9J0sBYdb9VZ1AER23nn2XQPUt+iptdjJJLD23S5lieQtHGDIjCIMpdsljjwDLgcjzjqF03rPe3c5kZTtpVaZTIoDmBHESZqzNjDiGbE5CmJH5q0mt11mVggaR2EalY/cfYpJJCn4BJJ/nqJ+Jb/Efy4+T+W7x/7b5x1wrOmT7ad8pmM7x0VW8MAPmdfuP1dL+sPTsj7Z5kUdlXWJyGBZMiFvCwwQlsO6AbYsTWPCL3O8RO/C0MbtIUwmYsrw0cgVINUQwUgg8KND771zVu5q6tiavzXPF/OtLyEmybP3OuqPxiCjsbhMrbu4CrFT5B+DYP7H5BHN/bUbW+WUk2SSfuSSeBQ/oBrRoImLoj4k4cl9q02e0jMbs8pRwtxIEyDsGVWV3yBiOBLq2LhsSDjwdVevWWuIlQCv/Z"
11/13/2012 22:49:58.374738 - [gabble/pipeline] response_cb (request-pipeline.c:307): got reply for request 0x279bcc0
11/13/2012 22:49:58.374748 - [gabble/vcard] pipeline_reply_cb (vcard-manager.c:1380): called for entry 0x7f95e0001d40
11/13/2012 22:49:58.374820 - [gabble/vcard] manager_patch_vcard (vcard-manager.c:1316): patching vcard
11/13/2012 22:49:58.374841 - [gabble/pipeline] gabble_request_pipeline_enqueue (request-pipeline.c:431): enqueued new request as item 0x27d6a60
11/13/2012 22:49:58.374846 - [gabble/pipeline] gabble_request_pipeline_enqueue (request-pipeline.c:432): number of items in flight: 0
11/13/2012 22:49:58.375009 - [gabble/vcard] observe_vcard (vcard-manager.c:910): got vCard alias "Myc Clark" for handle 1 from <FN>
11/13/2012 22:49:58.375027 - [gabble/connection] gabble_conn_aliasing_nicknames_updated (conn-aliasing.c:857): ignoring boring alias change for handle 1, signal from 2 but source 6 has alias "Myc Clark"
11/13/2012 22:49:58.375036 - [gabble/vcard] vcard_get_avatar_sha1 (vcard-manager.c:662): Our vCard has a PHOTO 0x27734a0
11/13/2012 22:49:58.375181 - [gabble/vcard] vcard_get_avatar_sha1 (vcard-manager.c:679): Successfully decoded PHOTO.BINVAL, SHA-1 9c510cef3cd1120ab37b80e659163f5e8728b33c
11/13/2012 22:49:58.375343 - [wocky] _write_node_tree: Serializing tree:
* presence xmlns='jabber:client'
    * x xmlns='vcard-temp:x:update'
        * photo
            "9c510cef3cd1120ab37b80e659163f5e8728b33c"
    * c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://telepathy.freedesktop.org/caps' ver='WfdSbyWNauD/lPUjdP2++szTdW8=' ext='pmuc-v1 share-v1'
11/13/2012 22:49:58.375515 - [gabble/presence] self_vcard_request_cb (presence-cache.c:831): End of avatar conflict resolution
11/13/2012 22:49:58.375519 - [gabble/vcard] delete_request (vcard-manager.c:788): Discarding request 0x279aa30
11/13/2012 22:49:58.375520 - [gabble/vcard] cache_entry_attempt_to_free (vcard-manager.c:492): Not freeing vCard cache entry 0x7f95e0001d40: it has a cached vCard 0x2773590
11/13/2012 22:49:58.375521 - [gabble/vcard] delete_request (vcard-manager.c:788): Discarding request 0x2795130
11/13/2012 22:49:58.375524 - [gabble/vcard] cache_entry_attempt_to_free (vcard-manager.c:492): Not freeing vCard cache entry 0x7f95e0001d40: it has a cached vCard 0x2773590
11/13/2012 22:49:58.375525 - [gabble/vcard] vcard_get_avatar_sha1 (vcard-manager.c:662): Our vCard has a PHOTO 0x27734a0
11/13/2012 22:49:58.375571 - [gabble/vcard] vcard_get_avatar_sha1 (vcard-manager.c:679): Successfully decoded PHOTO.BINVAL, SHA-1 9c510cef3cd1120ab37b80e659163f5e8728b33c
11/13/2012 22:49:58.375648 - [gabble/vcard] delete_request (vcard-manager.c:788): Discarding request 0x279bc30
11/13/2012 22:49:58.375695 - [gabble/vcard] cache_entry_attempt_to_free (vcard-manager.c:492): Not freeing vCard cache entry 0x7f95e0001d40: it has a cached vCard 0x2773590
11/13/2012 22:49:58.375705 - [gabble/pipeline] delete_item (request-pipeline.c:178): deleting item 0x279bcc0
11/13/2012 22:49:58.375711 - [gabble/pipeline] gabble_request_pipeline_go (request-pipeline.c:388): called; 1 pending items, 0 items in flight
11/13/2012 22:49:58.375715 - [gabble/pipeline] send_next_request (request-pipeline.c:359): processing request 0x27d6a60
11/13/2012 22:49:58.375905 - [wocky] _write_node_tree: Serializing tree:
* iq xmlns='jabber:client' type='set' id='80660375724'
    * vCard xmlns='vcard-temp'
        * PHOTO
            * TYPE
                "image/jpeg"
            * BINVAL
                "/9j/4AAQSkZJRgABAQAAAQABAAD/2wCEAAUDBBAQDREQEBAPDQ8SDxIQEA4QDxAQDxAOEA8LDBAQEA0QDhAQDQ0RDQ0QDhYMEhERHxQTDw4WGRgTJBATFRUBBQUFCAcIDwkJDxcSEhQeFxQXGhcXHhYXFR4cHh4YFRgSFB4TFBQSFBYaFBgWFB0VHRcUFB4WEhcWFB4WFRUUFP/AABEIAGAAYAMBIgACEQEDEQH/xAAcAAACAgMBAQAAAAAAAAAAAAAGBwQFAQMIAgD/xAA4EAACAgEDAwMCBAMGBwEAAAABAgMREgAEIQUTMQYiQQdRFDJhcSOBkTNCUqGx8BUkU3KCwdEI/8QAGQEAAgMBAAAAAAAAAAAAAAAAAwQBAgUA/8QALBEAAQMCBAQHAAMBAAAAAAAAAQACEQMhEjFB8ARRYXETIoGRobHBFNHhBf/aAAwDAQACEQMRAD8A45O3assTiTQajRP2B8X+msjav5xbxfg+PF+PH666y9S7OJtls1gQtMHdVDRsEp1LMTmgV3VafIEHFSBQJ0tfrf0U7Vo4knknTtg+5BGY37gMqAqiFkOeQUg1RonRqtE0xKzqfH47Re2v+aJKvAw8gj9wdfRwMbpSa80CavxdeNFXqGUyShVJKDxj5xYZX+UkgEn281yOK4bv00gUwfhXWJCv8VJYwAJI2Kr3cqJdw47ZU2bKL4HAWebNMsrktkhc7mBrqjf2o3/TWHQg0QQft4P9NH/qzdK+4ZUQjtyFS5IXwQDRK2fvzVcGudY3MAlUiQcg0H4y4+cgefNUfnRPDvCt414IQAiEmgCT9vJ/pr0IzV0aHk/AJBIBPiyATXzR+2rF4zDIrKbo2L45+39NF/ph4mV4SwwlvAkC0lpyh880SvtNWA/m71XCVcvtKXhH+/8Af7asB0Sar7MtEWD23ojzYNeK5vWtJwQwI4x4AHgggg/oLsf+RGutvTHr9JeiO0amOWLbYuhjIQOQIlwasSsjU2KmwSw48atTZjMIdat4YkhckQ9OkYFhG7KotmCMQoq7JAoCubPxrWdk/t9r+4WvtPuH3HHuFfIvXRfprrKwdNaAMnf3E6xtGGXOOJqjt1skKVXyQOGA+CdTfqZtE3EoO2ZEl2SRpAuXExQoWwKgACwRZP5UA/vaY/idUof+hhMObCZnV8hvIFTIFY0VQyAxo25lECyM3mkERQICbLVxdql/X/oLfbv8RvBJlAr0GncZySK3bVI0RGCtbCMk9tQchyBZP/T2+7mxdwyyk9TkkBAoFUqWM80T7MG+aPPxq29ddIjE+ULiKPcAyTxxys0cswMDpIYiAsLqvtYqTkCAfyg6vxFFz3CMsoWbSqimSTp/dt9Uqvob6QZd3I0qrcmyyjK2UMUxePuqzAY2IpCrmhjR5DA6LH9NrtJoboUTIoYUpll7iEDI3Gu528VhSfbKtCsr1r6r6gZH2syQncSwxGKFFdY4vw8ZgQAEkSLKzkO0hUBSQi3jqo6/62n3ETwspg6j+IcHbOjSd3bNElh+CsjIwkoKA2QQqB3HBQiQCFq0ntqsscoS5fatLvd20a5oNxISzEIvudqXImgxogCvgHjXv0+rTF40Fe7kUD7hVgnmgTXJ8kH7i8fTNtxk+zVSgldHkBCB1ZAQpiMgpWbLkHg0viqL42HpQ7PatI6BIUXIs00bOAAfdIR7WcmyVW+eBfkla46ormdEmPVXRESNlKgsADeJ+/zZJ55/p8aXu2zgOYUMhOQBJ8KTi1iiCL/Xg0Qb1fetvWzTylgpWPFQimshTBixPItrK43wCD+86CESbcmvAU1R8N7SD8/B4/Q6tIfkrYXU89VWekemxOoJIXK1KnihTknK7+B8/wCGq029v1FBCyQqIYHcSNGa/iOoVQbPIiUBWBJ+AedJ/wBP9JB3DKSe0gycHxZql8cggZV8gEG/BvesdXeSRIowuRORyvBY18Fqri/dVmzxzdaZ4doaMZ7DqitaJk35Jk7XeRArNSMyC0duEBIONiwCqkhgCfI+dMT0N1fYTQRQ7aaOSZXQupI77ssqyyMaJyUsS3tJAFDiq0jekdKDtbs0z/8AUIVitij2lYGKAXRtg7EcVxWpG49PdOjlyZgkoIZQNwVZXBDAghkIa+RRFGvFaZqB7oIgeqpW4VlW+RRh0j0xC57SNLGyTbpwq5rEcsUjFAAKqiRGUL5W1Ng1qy9WI0Oy2Ty0ksSJFIA1cyCMG1XgL3E95A8MDzjWqzp3q6USsWdMNvso2fMAZ7ycosYZwjFVOSjEAeSSDxRZJ6zWOLYPuVDtNMkczqtqjivciFqKoacSAcKCRdahr4uFgvpkmDrvfosbrpCjapI0ZkUq6tIoLt2p5FZCVFnDONkyUGiEPAfjfvvS87tIkUwZlYTw7sKpm7kY/h2QQsmcZYE/31VxwTeiJx2xHtWV1R0eNJr99tJatZGIVyAQCoxcKaFkasPQfVY2327jRgJVWOVosSF9wZWeOwaByIIBPLeATelqlIR9fnt8KaHleC3pPtr8JUepvS/dO33iRxRtJEJZRKKXbyKF/FWCAwWJyrAcWr1wCDqp9XeuUl2kYdn3u4a+3FiUgiALKsx26ggGgHUMSVyILCmGnz649GxPt5IUcwLunxJAMg7koRDWbEJG4jjDRJQ9goC2tR9T6K+z2jCCOJp1cRSTWWXJnKmVVYK0oxBbFqwKqLf5TqYxkPXeS3qFSjcuN9Acu559AInW1jz36i2axri9mawWU/3FJAtj8MxyuMnxia5sEXpLcKsThj7ZI5EBJ5DU4QE8+7Jiv76k7z0jIkHenWSpMGCzf2ryMFRFINsFU0bIF+BQB1pl6TjtGY0UMjYsLA4bk/upGQ/T99TTPmgItVhdTxO5gd5z9oHuqaPZOjM+Yp+WQLfiwvNg2Lrgc3XzqPHsZVmIcMDIA2F4qEF13ZAOFWuYx5ah86mQdUC5SMMsfyi7GVA35qwPaP1vU31Tt5k2qbgS7aXuVl2pspYiQWCSQMiMhUfoRZuzp1/hsbcxv90VWyclI325KbdiOSqeKxDV4BUGxGo8ReAPN3ehn0vvow3demevDflRQwBxU3wUYsDRrFh86shucoiLJGNG+bsVfJ5sG/5/Ohv/AIeGgDKadbyH3AJBr+Qv/LVqpMgtvquDk0/TPp3c7ppdps4Wmlk3XcxZiETaQMyRySzSHH3OOLJLY8A2AW1tfoV1YwRosOxjMbLIt7yQgGpBeA27KC2ZJOR8EeKAifQ/bhOhR77aqX3a9UC70lnVRG7nbiOTD3PtY4Nyk2AyClnfjEkH/wBI+ndQTdMUUhtltdvtZY5O6qbyOCfqm2KwZvgvESSx7h8iR2waEjHSRrumyAOFpkXEpaevfWsqNtm3qwQmHcPt59vCWLxGIly2OVlXiTuran2vGQRdat+h7aV91LJs4Q8iTqy7iZgrJnHGzwsjENbxFW7QAWyr8FmItP8A9WMH3G22rQQ7WXfOW3MkTK080cMiwQJJMIlLIkTR7pozYBiCDIJmdHoHeSbVp42dNyzSr25ImB/iIkcLK/NJ+XPBvBku/LaYpVHOas+vQYx9p3lvst/UOvyuVDuUdd0TJHGjD8O0cG43JJLg5uRCWBoqSQOfmKN+8sSKkIcpFJJuAzFWQOcyAQHDOImibAhcg1+2q1bdf30LhN1OssTEmA4g9wM+cTR7iKPiTCNjTgDEWbo3om3Ue32u4ARspdwABDai1hjpmJFYrggBJuiKHng2PkEt4Uk4jvYCRfUekTboxdkrOsi2u7ncFdvGoU0qVk0jgqUclqLgEJizaFfrF/y+3j2qlWwVu6VAALsaQBcmpWGZqzWI+/LY9YesNhEsXZhTcxTxydnbxxmNBIe0isKUKFIEoLKT4bwC2PPX1XkCLHEOW8scixLDzbN7nq8cm88ni60myiGS4ZbgLefx9SvgY+LchA6mBqYvKG5puEH3YMf5e/8A1rVT1vcZSE/ah/TWdxJyP0X7/pqBeuqvmys0Io6bu7zUeAR/kqr/AKrqFs91hI48A/8Ay/8AMHUbpElWf1/0s/8AvWz8I8khEau7AZEIpYhV5LEKD7QKsnxq5qw0OKjDeE1PR3WZ9nuJDtd1Ls+5CJFDIrJJjcUivt51YO4kjkxLIPyE2oAOiB/rR1Rt92Nz1SSOMYjuxLto1txGVJeOAAqM7NDgAn40I/Vb1QZ5VZcWSNhTqrWEbEUWawffyDiOeB8kicfTQ7O3djUC8lZqlYUPCnIMKJGQrknXVgxufP7SXCirUyNoPpGZ9kcbL1MT1VJNzKZ3R2Mm6eR5O8qBkVFZUGK4kAUo5JJAyOi/6b+tw+7ewu2TcpahVUAyjMsrMFJRnUDGUEe6OrHACT2HVGgklMYDL28AGHgHA5UD+YBccgQQD5+NSd70WVIMmkV47/s2EqOobBu4VeMZJlIGyVnuif11IeWiI3uVDqLXmSd7hdQ+t+ktLvdsu1AnVSZJUaUiIuGUAM1M1KoYEqBWQ85e2F65aSQvu5cNtK2W1gWMSyOYxIDK4j7QtgIpArshyJQkENWon083UyQ05jiiwiXbcEqodEWzmbP8RgmBq6YgDOtMDeylI4SHHsiMNl1IVbjLkigwDNGrHIEexSpPnTA0WcTc73mgHoLRydKict2Yo4ZHjAKlUlHcOMuK+xCCwDAmlJNDka54+rrHvKrKUdcldbBAYFQaYeRYI5A5B02/UPrYLDJHtlyjdye+ECoKKMI4ENB2BS+8fYAzHngHn71D1BpZWdySWYnyTwSW4J+Dd/H7DQK9Ty4QtLhKTsWI2VeWOvGrrert/wAPEUM34i3EysF7QFkxmJlORtaDBh+a64rVLpKZWjC2JIRqV03qUkbZRyPE1EZI5RsW4ItSDRHBX51B19rjcQVAtdHI6myJOqMY1cRqYweHGasA7nkqpGXFX48EjWnpO7oSEgGPLKvHI4/MAWrhRjZ8g6Dix1i9GNaSCRklhw8NIxG9rW5W+EdbuKHtNIWAmnUf8t2XXtR0MZVlIWJ1YCqH3/QnVtt/WF7ZRIwZEj7CxmPJhEq+xgxxVspJGUqTaqpPPtGlo8zGrJNChZJoDwB9gPtrxkdQyoRM3z9J0sBYdb9VZ1AER23nn2XQPUt+iptdjJJLD23S5lieQtHGDIjCIMpdsljjwDLgcjzjqF03rPe3c5kZTtpVaZTIoDmBHESZqzNjDiGbE5CmJH5q0mt11mVggaR2EalY/cfYpJJCn4BJJ/nqJ+Jb/Efy4+T+W7x/7b5x1wrOmT7ad8pmM7x0VW8MAPmdfuP1dL+sPTsj7Z5kUdlXWJyGBZMiFvCwwQlsO6AbYsTWPCL3O8RO/C0MbtIUwmYsrw0cgVINUQwUgg8KND771zVu5q6tiavzXPF/OtLyEmybP3OuqPxiCjsbhMrbu4CrFT5B+DYP7H5BHN/bUbW+WUk2SSfuSSeBQ/oBrRoImLoj4k4cl9q02e0jMbs8pRwtxIEyDsGVWV3yBiOBLq2LhsSDjwdVevWWuIlQCv/Z"
        * FN
            "Myc Clark"
11/13/2012 22:49:58.376275 - [gabble/pipeline] gabble_request_pipeline_go (request-pipeline.c:388): called; 0 pending items, 1 items in flight
11/13/2012 22:49:58.437160 - [wocky] _end_element_ns: Received stanza
* iq xmlns='jabber:client' type='result' from='mycclark@gmail.com/android6982502203df' to='mycclark@gmail.com/kde-telepa85FE5991' id='204053220622'
    * query xmlns='http://jabber.org/protocol/disco#info'
        * identity category='account' type='registered' name='Google Talk User Account'
        * feature var='http://jabber.org/protocol/disco#info'
        * feature var='http://jabber.org/protocol/disco#items'
11/13/2012 22:49:58.437233 - [gabble/presence] set_caps_for (presence-cache.c:1201): setting caps for 1 (thanks to 1 mycclark@gmail.com/android6982502203df)
11/13/2012 22:49:58.437239 - [gabble/presence] gabble_presence_set_capabilities (presence.c:335): about to add caps to resource android6982502203df with serial 2
11/13/2012 22:49:58.437243 - [gabble/presence] gabble_presence_set_capabilities (presence.c:346): found resource android6982502203df
11/13/2012 22:49:58.437246 - [gabble/presence] gabble_presence_set_capabilities (presence.c:359): updating caps for resource android6982502203df
11/13/2012 22:49:58.437472 - [gabble/presence] disco_waiter_free (presence-cache.c:172): freeing waiter 0x279a900 for handle 1 with serial 2
11/13/2012 22:49:58.480590 - [wocky] _end_element_ns: Received stanza
* iq xmlns='jabber:client' to='mycclark@gmail.com/kde-telepa85FE5991' from='mycclark@gmail.com/TalkGadget33C62BC1' id='203551220082' type='result'
    * query xmlns='http://jabber.org/protocol/disco#info'
        * feature var='http://www.google.com/xmpp/protocol/pmuc/v1'
11/13/2012 22:49:58.480706 - [gabble/presence] set_caps_for (presence-cache.c:1201): setting caps for 1 (thanks to 1 mycclark@gmail.com/TalkGadget33C62BC1)
11/13/2012 22:49:58.480717 - [gabble/presence] gabble_presence_set_capabilities (presence.c:335): about to add caps to resource TalkGadget33C62BC1 with serial 1
11/13/2012 22:49:58.480722 - [gabble/presence] gabble_presence_set_capabilities (presence.c:346): found resource TalkGadget33C62BC1
11/13/2012 22:49:58.480726 - [gabble/presence] gabble_presence_set_capabilities (presence.c:351): new serial 1, old 0, clearing caps
11/13/2012 22:49:58.480731 - [gabble/presence] gabble_presence_set_capabilities (presence.c:359): updating caps for resource TalkGadget33C62BC1
11/13/2012 22:49:58.481302 - [gabble/presence] disco_waiter_free (presence-cache.c:172): freeing waiter 0x2776270 for handle 1 with serial 1
11/13/2012 22:49:58.481717 - [wocky] _end_element_ns: Received stanza
* iq xmlns='jabber:client' type='error' to='mycclark@gmail.com/kde-telepa85FE5991' id='203536220004' from='mycclark@gmail.com/TalkGadget33C62BC1'
    * query xmlns='http://jabber.org/protocol/disco#info' node='http://talkgadget.google.com/client/caps#vavinvite-v1'
    * error code='501' type='cancel'
        * feature-not-implemented xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'
11/13/2012 22:49:58.481776 - [gabble/presence] _caps_disco_cb (presence-cache.c:1344): disco query failed: 
11/13/2012 22:49:58.481782 - [gabble/presence] disco_failed (presence-cache.c:1125): failed to find a suitable candidate to retry disco request for URI http://talkgadget.google.com/client/caps#vavinvite-v1
11/13/2012 22:49:58.481790 - [gabble/presence] disco_waiter_list_free (presence-cache.c:187): list 0x243bf20
11/13/2012 22:49:58.481794 - [gabble/presence] disco_waiter_free (presence-cache.c:172): freeing waiter 0x279a8a0 for handle 1 with serial 1
11/13/2012 22:49:58.482121 - [wocky] _end_element_ns: Received stanza
* iq xmlns='jabber:client' to='mycclark@gmail.com/kde-telepa85FE5991' from='mycclark@gmail.com/TalkGadget33C62BC1' id='203790220161' type='result'
    * query xmlns='http://jabber.org/protocol/disco#info'
        * identity category='client' type='web'
11/13/2012 22:49:58.482209 - [gabble/presence] client_types_from_message (presence-cache.c:1260): Got type for 1: web (64)
11/13/2012 22:49:58.482230 - [gabble/presence] set_caps_for (presence-cache.c:1201): setting caps for 1 (thanks to 1 mycclark@gmail.com/TalkGadget33C62BC1)
11/13/2012 22:49:58.482239 - [gabble/presence] gabble_presence_set_capabilities (presence.c:335): about to add caps to resource TalkGadget33C62BC1 with serial 1
11/13/2012 22:49:58.482243 - [gabble/presence] gabble_presence_set_capabilities (presence.c:346): found resource TalkGadget33C62BC1
11/13/2012 22:49:58.482245 - [gabble/presence] gabble_presence_set_capabilities (presence.c:359): updating caps for resource TalkGadget33C62BC1
11/13/2012 22:49:58.482265 - [gabble/presence] emit_capabilities_update (presence-cache.c:1158): no change in caps for handle 1
11/13/2012 22:49:58.482287 - [gabble/presence] disco_waiter_free (presence-cache.c:172): freeing waiter 0x2405c00 for handle 1 with serial 1
11/13/2012 22:49:58.507982 - [wocky] _error: wocky-xmpp-reader.c:633: Ignoring parser warning: xmlns: URI vcard-temp is not absolute

11/13/2012 22:49:58.511140 - [wocky] _end_element_ns: Received stanza
* iq xmlns='jabber:client' type='error' id='80660375724' to='mycclark@gmail.com/kde-telepa85FE5991'
    * vCard xmlns='vcard-temp'
        * PHOTO
            * TYPE
                "image/jpeg"
            * BINVAL
                "/9j/4AAQSkZJRgABAQAAAQABAAD/2wCEAAUDBBAQDREQEBAPDQ8SDxIQEA4QDxAQDxAOEA8LDBAQEA0QDhAQDQ0RDQ0QDhYMEhERHxQTDw4WGRgTJBATFRUBBQUFCAcIDwkJDxcSEhQeFxQXGhcXHhYXFR4cHh4YFRgSFB4TFBQSFBYaFBgWFB0VHRcUFB4WEhcWFB4WFRUUFP/AABEIAGAAYAMBIgACEQEDEQH/xAAcAAACAgMBAQAAAAAAAAAAAAAGBwQFAQMIAgD/xAA4EAACAgEDAwMCBAMGBwEAAAABAgMREgAEIQUTMQYiQQdRFDJhcSOBkTNCUqGx8BUkU3KCwdEI/8QAGQEAAgMBAAAAAAAAAAAAAAAAAwQBAgUA/8QALBEAAQMCBAQHAAMBAAAAAAAAAQACEQMhEjFB8ARRYXETIoGRobHBFNHhBf/aAAwDAQACEQMRAD8A45O3assTiTQajRP2B8X+msjav5xbxfg+PF+PH666y9S7OJtls1gQtMHdVDRsEp1LMTmgV3VafIEHFSBQJ0tfrf0U7Vo4knknTtg+5BGY37gMqAqiFkOeQUg1RonRqtE0xKzqfH47Re2v+aJKvAw8gj9wdfRwMbpSa80CavxdeNFXqGUyShVJKDxj5xYZX+UkgEn281yOK4bv00gUwfhXWJCv8VJYwAJI2Kr3cqJdw47ZU2bKL4HAWebNMsrktkhc7mBrqjf2o3/TWHQg0QQft4P9NH/qzdK+4ZUQjtyFS5IXwQDRK2fvzVcGudY3MAlUiQcg0H4y4+cgefNUfnRPDvCt414IQAiEmgCT9vJ/pr0IzV0aHk/AJBIBPiyATXzR+2rF4zDIrKbo2L45+39NF/ph4mV4SwwlvAkC0lpyh880SvtNWA/m71XCVcvtKXhH+/8Af7asB0Sar7MtEWD23ojzYNeK5vWtJwQwI4x4AHgggg/oLsf+RGutvTHr9JeiO0amOWLbYuhjIQOQIlwasSsjU2KmwSw48atTZjMIdat4YkhckQ9OkYFhG7KotmCMQoq7JAoCubPxrWdk/t9r+4WvtPuH3HHuFfIvXRfprrKwdNaAMnf3E6xtGGXOOJqjt1skKVXyQOGA+CdTfqZtE3EoO2ZEl2SRpAuXExQoWwKgACwRZP5UA/vaY/idUof+hhMObCZnV8hvIFTIFY0VQyAxo25lECyM3mkERQICbLVxdql/X/oLfbv8RvBJlAr0GncZySK3bVI0RGCtbCMk9tQchyBZP/T2+7mxdwyyk9TkkBAoFUqWM80T7MG+aPPxq29ddIjE+ULiKPcAyTxxys0cswMDpIYiAsLqvtYqTkCAfyg6vxFFz3CMsoWbSqimSTp/dt9Uqvob6QZd3I0qrcmyyjK2UMUxePuqzAY2IpCrmhjR5DA6LH9NrtJoboUTIoYUpll7iEDI3Gu528VhSfbKtCsr1r6r6gZH2syQncSwxGKFFdY4vw8ZgQAEkSLKzkO0hUBSQi3jqo6/62n3ETwspg6j+IcHbOjSd3bNElh+CsjIwkoKA2QQqB3HBQiQCFq0ntqsscoS5fatLvd20a5oNxISzEIvudqXImgxogCvgHjXv0+rTF40Fe7kUD7hVgnmgTXJ8kH7i8fTNtxk+zVSgldHkBCB1ZAQpiMgpWbLkHg0viqL42HpQ7PatI6BIUXIs00bOAAfdIR7WcmyVW+eBfkla46ormdEmPVXRESNlKgsADeJ+/zZJ55/p8aXu2zgOYUMhOQBJ8KTi1iiCL/Xg0Qb1fetvWzTylgpWPFQimshTBixPItrK43wCD+86CESbcmvAU1R8N7SD8/B4/Q6tIfkrYXU89VWekemxOoJIXK1KnihTknK7+B8/wCGq029v1FBCyQqIYHcSNGa/iOoVQbPIiUBWBJ+AedJ/wBP9JB3DKSe0gycHxZql8cggZV8gEG/BvesdXeSRIowuRORyvBY18Fqri/dVmzxzdaZ4doaMZ7DqitaJk35Jk7XeRArNSMyC0duEBIONiwCqkhgCfI+dMT0N1fYTQRQ7aaOSZXQupI77ssqyyMaJyUsS3tJAFDiq0jekdKDtbs0z/8AUIVitij2lYGKAXRtg7EcVxWpG49PdOjlyZgkoIZQNwVZXBDAghkIa+RRFGvFaZqB7oIgeqpW4VlW+RRh0j0xC57SNLGyTbpwq5rEcsUjFAAKqiRGUL5W1Ng1qy9WI0Oy2Ty0ksSJFIA1cyCMG1XgL3E95A8MDzjWqzp3q6USsWdMNvso2fMAZ7ycosYZwjFVOSjEAeSSDxRZJ6zWOLYPuVDtNMkczqtqjivciFqKoacSAcKCRdahr4uFgvpkmDrvfosbrpCjapI0ZkUq6tIoLt2p5FZCVFnDONkyUGiEPAfjfvvS87tIkUwZlYTw7sKpm7kY/h2QQsmcZYE/31VxwTeiJx2xHtWV1R0eNJr99tJatZGIVyAQCoxcKaFkasPQfVY2327jRgJVWOVosSF9wZWeOwaByIIBPLeATelqlIR9fnt8KaHleC3pPtr8JUepvS/dO33iRxRtJEJZRKKXbyKF/FWCAwWJyrAcWr1wCDqp9XeuUl2kYdn3u4a+3FiUgiALKsx26ggGgHUMSVyILCmGnz649GxPt5IUcwLunxJAMg7koRDWbEJG4jjDRJQ9goC2tR9T6K+z2jCCOJp1cRSTWWXJnKmVVYK0oxBbFqwKqLf5TqYxkPXeS3qFSjcuN9Acu559AInW1jz36i2axri9mawWU/3FJAtj8MxyuMnxia5sEXpLcKsThj7ZI5EBJ5DU4QE8+7Jiv76k7z0jIkHenWSpMGCzf2ryMFRFINsFU0bIF+BQB1pl6TjtGY0UMjYsLA4bk/upGQ/T99TTPmgItVhdTxO5gd5z9oHuqaPZOjM+Yp+WQLfiwvNg2Lrgc3XzqPHsZVmIcMDIA2F4qEF13ZAOFWuYx5ah86mQdUC5SMMsfyi7GVA35qwPaP1vU31Tt5k2qbgS7aXuVl2pspYiQWCSQMiMhUfoRZuzp1/hsbcxv90VWyclI325KbdiOSqeKxDV4BUGxGo8ReAPN3ehn0vvow3demevDflRQwBxU3wUYsDRrFh86shucoiLJGNG+bsVfJ5sG/5/Ohv/AIeGgDKadbyH3AJBr+Qv/LVqpMgtvquDk0/TPp3c7ppdps4Wmlk3XcxZiETaQMyRySzSHH3OOLJLY8A2AW1tfoV1YwRosOxjMbLIt7yQgGpBeA27KC2ZJOR8EeKAifQ/bhOhR77aqX3a9UC70lnVRG7nbiOTD3PtY4Nyk2AyClnfjEkH/wBI+ndQTdMUUhtltdvtZY5O6qbyOCfqm2KwZvgvESSx7h8iR2waEjHSRrumyAOFpkXEpaevfWsqNtm3qwQmHcPt59vCWLxGIly2OVlXiTuran2vGQRdat+h7aV91LJs4Q8iTqy7iZgrJnHGzwsjENbxFW7QAWyr8FmItP8A9WMH3G22rQQ7WXfOW3MkTK080cMiwQJJMIlLIkTR7pozYBiCDIJmdHoHeSbVp42dNyzSr25ImB/iIkcLK/NJ+XPBvBku/LaYpVHOas+vQYx9p3lvst/UOvyuVDuUdd0TJHGjD8O0cG43JJLg5uRCWBoqSQOfmKN+8sSKkIcpFJJuAzFWQOcyAQHDOImibAhcg1+2q1bdf30LhN1OssTEmA4g9wM+cTR7iKPiTCNjTgDEWbo3om3Ue32u4ARspdwABDai1hjpmJFYrggBJuiKHng2PkEt4Uk4jvYCRfUekTboxdkrOsi2u7ncFdvGoU0qVk0jgqUclqLgEJizaFfrF/y+3j2qlWwVu6VAALsaQBcmpWGZqzWI+/LY9YesNhEsXZhTcxTxydnbxxmNBIe0isKUKFIEoLKT4bwC2PPX1XkCLHEOW8scixLDzbN7nq8cm88ni60myiGS4ZbgLefx9SvgY+LchA6mBqYvKG5puEH3YMf5e/8A1rVT1vcZSE/ah/TWdxJyP0X7/pqBeuqvmys0Io6bu7zUeAR/kqr/AKrqFs91hI48A/8Ay/8AMHUbpElWf1/0s/8AvWz8I8khEau7AZEIpYhV5LEKD7QKsnxq5qw0OKjDeE1PR3WZ9nuJDtd1Ls+5CJFDIrJJjcUivt51YO4kjkxLIPyE2oAOiB/rR1Rt92Nz1SSOMYjuxLto1txGVJeOAAqM7NDgAn40I/Vb1QZ5VZcWSNhTqrWEbEUWawffyDiOeB8kicfTQ7O3djUC8lZqlYUPCnIMKJGQrknXVgxufP7SXCirUyNoPpGZ9kcbL1MT1VJNzKZ3R2Mm6eR5O8qBkVFZUGK4kAUo5JJAyOi/6b+tw+7ewu2TcpahVUAyjMsrMFJRnUDGUEe6OrHACT2HVGgklMYDL28AGHgHA5UD+YBccgQQD5+NSd70WVIMmkV47/s2EqOobBu4VeMZJlIGyVnuif11IeWiI3uVDqLXmSd7hdQ+t+ktLvdsu1AnVSZJUaUiIuGUAM1M1KoYEqBWQ85e2F65aSQvu5cNtK2W1gWMSyOYxIDK4j7QtgIpArshyJQkENWon083UyQ05jiiwiXbcEqodEWzmbP8RgmBq6YgDOtMDeylI4SHHsiMNl1IVbjLkigwDNGrHIEexSpPnTA0WcTc73mgHoLRydKict2Yo4ZHjAKlUlHcOMuK+xCCwDAmlJNDka54+rrHvKrKUdcldbBAYFQaYeRYI5A5B02/UPrYLDJHtlyjdye+ECoKKMI4ENB2BS+8fYAzHngHn71D1BpZWdySWYnyTwSW4J+Dd/H7DQK9Ty4QtLhKTsWI2VeWOvGrrert/wAPEUM34i3EysF7QFkxmJlORtaDBh+a64rVLpKZWjC2JIRqV03qUkbZRyPE1EZI5RsW4ItSDRHBX51B19rjcQVAtdHI6myJOqMY1cRqYweHGasA7nkqpGXFX48EjWnpO7oSEgGPLKvHI4/MAWrhRjZ8g6Dix1i9GNaSCRklhw8NIxG9rW5W+EdbuKHtNIWAmnUf8t2XXtR0MZVlIWJ1YCqH3/QnVtt/WF7ZRIwZEj7CxmPJhEq+xgxxVspJGUqTaqpPPtGlo8zGrJNChZJoDwB9gPtrxkdQyoRM3z9J0sBYdb9VZ1AER23nn2XQPUt+iptdjJJLD23S5lieQtHGDIjCIMpdsljjwDLgcjzjqF03rPe3c5kZTtpVaZTIoDmBHESZqzNjDiGbE5CmJH5q0mt11mVggaR2EalY/cfYpJJCn4BJJ/nqJ+Jb/Efy4+T+W7x/7b5x1wrOmT7ad8pmM7x0VW8MAPmdfuP1dL+sPTsj7Z5kUdlXWJyGBZMiFvCwwQlsO6AbYsTWPCL3O8RO/C0MbtIUwmYsrw0cgVINUQwUgg8KND771zVu5q6tiavzXPF/OtLyEmybP3OuqPxiCjsbhMrbu4CrFT5B+DYP7H5BHN/bUbW+WUk2SSfuSSeBQ/oBrRoImLoj4k4cl9q02e0jMbs8pRwtxIEyDsGVWV3yBiOBLq2LhsSDjwdVevWWuIlQCv/Z"
        * FN
            "Myc Clark"
    * error code='500' type='wait'
        * internal-server-error xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'
11/13/2012 22:49:58.511194 - [gabble/pipeline] response_cb (request-pipeline.c:307): got reply for request 0x27d6a60
11/13/2012 22:49:58.511210 - [gabble/vcard] replace_reply_cb (vcard-manager.c:946): called: some error
11/13/2012 22:49:58.511219 - [gabble/vcard] gabble_vcard_manager_remove_edit_request (vcard-manager.c:1670): request == 0x2796670
11/13/2012 22:49:58.511229 - [gabble/pipeline] delete_item (request-pipeline.c:178): deleting item 0x27d6a60
11/13/2012 22:49:58.511236 - [gabble/pipeline] gabble_request_pipeline_go (request-pipeline.c:388): called; 0 pending items, 0 items in flight
11/13/2012 22:50:01.157119 - [gabble/presence] gabble_presence_cache_end_unsure_period (presence-cache.c:470): 0x23f1820
11/13/2012 22:50:03.156235 - [gabble/presence] gabble_presence_cache_end_unsure_period (presence-cache.c:470): 0x23f1b20
11/13/2012 22:51:27.244719 - [wocky] _end_element_ns: Received stanza
* presence xmlns='jabber:client' from='-1397724570@chat.facebook.com' to='myc.clark@chat.facebook.com/kde-telepathy_27a9a66e_4CE6EF132AF66' type='unavailable'
11/13/2012 22:51:27.244941 - [gabble/presence] emit_capabilities_update (presence-cache.c:1158): no change in caps for handle 2
11/13/2012 22:51:27.245251 - [gabble/presence] gabble_presence_cache_maybe_remove (presence-cache.c:2051): discarding cached presence for unavailable jid -1397724570@chat.facebook.com
Comment 16 Leo Tindle 2012-12-04 16:49:09 UTC
I had the same error message while trying to connect to facebook chat (Kubuntu 12.10 amd64). I recently found that if I check "Ignore SSL errors", the problem goes away and it connects just fine. HTH. -Leo
Comment 17 Dennis Schridde 2013-01-04 17:16:58 UTC
I also get loads of this. Usually right after login, before I could enter my KWallet password, or right thereafter.
Comment 18 Dennis Schridde 2013-01-11 15:47:04 UTC
Currently it happens especially for the my Facebook account.
1) I open the Contact List to change my status to online (the presence plasmoid is buggy in that regard - it does not reestablish connections).
2) As the Facebook account comes online and I see the "Facebook friends" group, I close the Contact List.
3) Soon thereafter I get the "cancelled on your request" error.
4) When I open the Contact List again, to make Telepathy reconnect, I often get a network error now. Maybe FB blocks too-frequent reconnects? I get no information what kind of network error occured...

If I leave the Contact List open in step (2), the "cancelled on your request" error does usually not occur.
Comment 19 Dennis Schridde 2013-01-11 15:49:59 UTC
(In reply to comment #18)
> If I leave the Contact List open in step (2), the "cancelled on your
> request" error does usually not occur.
P.S: This just seems to increase the chances that the connection will stay. But it is no guarantee. Sadly it is very hard to debug this, as I cannot attach the telepathy-gabble-xmpp-console to the Facebook connection right from the start. Once I try to connect it, it usually is already down again.
Comment 20 Martin Klapetek 2013-01-11 16:37:31 UTC
Thanks a lot for providing such detailed informations!

Btw., just out of curiosity, do you have auto-away enabled?
Comment 21 Dennis Schridde 2013-01-11 21:22:23 UTC
(In reply to comment #20)
> Thanks a lot for providing such detailed informations!
Any time.

> Btw., just out of curiosity, do you have auto-away enabled?
Yes.

But today the error appeared right after the connection was established. I was able to see the "Facebook friends" group for a split second in the Contact List (I have hide-offline enabled), and then I already got the message and the contacts were all offline again (or rather I was) .
Comment 22 Dennis Schridde 2013-01-12 12:06:55 UTC
Today Facebook works again without any apparent problems.

Random ideas:
1) Is it possible that the server does something that makes Telepathy(/KDE) cancel the connection as if the user had cancelled it himself?
2) Is it possible that Telepathy sends a cancel event to the connection when the Contact List or Presence plasmoid try to reconnect (as opposed to a plain connect)? And this cancel event arrives only after the connection was re-established?
Comment 23 Dennis Schridde 2013-01-15 21:52:17 UTC
Today Facebook stopped working entirely on another PC with the same symptoms. Telepathy establishes a connection, then immediately claims that I cancelled it, and reconnects - repeating this over and over again.

I tried the following to debug it, but then the issue vanished:
$ pkill telepathy-gabble
$ GABBLE_LOGFILE=/tmp/gabble.log GABBLE_PERSIST=1 GABBLE_DEBUG=all G_MESSAGES_DEBUG=all /usr/libexec/telepathy-gabble
$ tail -f /tmp/gabble.log
[...]
(telepathy-gabble:6109): tp-glib/params-WARNING **: tp_base_connection_manager_register: Couldn't claim bus name. If you are trying to debug this connection manager, disable all accounts and kill any running copies of this CM, then try again. Name 'org.freedesktop.Telepathy.ConnectionManager.gabble' already in use by another process
[...]

Afterwards Telepathy was able to establish a connection to Facebook and keep it. Could it be that Facebook does some kind of load-balancing? Randomly I connect to an overloaded server, it redirects me to another, Telepathy fails to understand that, interprets it as a cancel-request. After a while the DNS record vanished from the cache, I randomly connect to another server and the issue is gone? Just poking in the dark, really...
Comment 24 Martin Klapetek 2013-01-15 22:35:22 UTC
Before you actually kill gabble, make sure you are offline. Then start gabble and only after that connect. You can also use ktp-debugger if you're on 0.5.2, that gives you gabble log instantly as well as mission-control.

As for your guess - might be possible, but I'm sorry to say we're as much in dark as you are with this, as this is not our level of things we work on. You might get better assistance from the Telepathy folks though, either at #telepathy on freenode or bugs.freedesktop.org. Let us know if you learn anything new.
Comment 25 Dennis Schridde 2013-01-21 15:07:11 UTC
Created attachment 76604 [details]
Gabble log, anonymised

(In reply to comment #24)
> Before you actually kill gabble, make sure you are offline. Then start
> gabble and only after that connect. You can also use ktp-debugger if you're
> on 0.5.2, that gives you gabble log instantly as well as mission-control.
There seems to be no ktp-debugger in 0.5.2 for Ubuntu 12.04/Precise (Telepathy/KDE PPA).

However, I got a log now. First some network errors appeared, until it 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

I am not sure what lead to that, but maybe you can figure it out...?
Comment 26 Dennis Schridde 2013-01-21 15:18:52 UTC
Created attachment 76605 [details]
Gabble log, anonymised
Comment 27 Dennis Schridde 2013-01-21 15:19:30 UTC
Created attachment 76606 [details]
Script I used to anonymise the log
Comment 28 Dennis Schridde 2013-01-21 16:00:33 UTC
See also: https://bugs.freedesktop.org/show_bug.cgi?id=59668
Comment 29 Tom Albers 2013-01-21 16:19:36 UTC
The content of attachment 76605 [details] has been deleted by
    Tom Albers <toma@kde.org>
who provided the following reason:

Per request #313626

The token used to delete this attachment was generated at 2013-01-21 17:19:13 CET.
Comment 30 Tom Albers 2013-01-22 09:05:21 UTC
The content of attachment 76604 [details] has been deleted by
    Tom Albers <toma@kde.org>
who provided the following reason:

Per request author.

The token used to delete this attachment was generated at 2013-01-22 10:05:10 CET.
Comment 31 Dennis Schridde 2013-01-22 10:26:35 UTC
Created attachment 76625 [details]
Gabble log, anonymised
Comment 32 Martin Kho 2013-03-15 16:54:33 UTC
Hi,

Didn't see this issue any more with 0.6 alpha/beta (fedora, 0.5.80-1.fc19.x86_64) and google talk.

Thanks,

Martin Kho
Comment 33 David Edmundson 2013-04-16 10:18:19 UTC
Git commit 68e2e30e9820d0b6fe146e1dceb9313e7a3f968c by David Edmundson.
Committed on 16/04/2013 at 13:15.
Pushed by davidedmundson into branch 'kde-telepathy-0.6'.

Make sure to supress any remaining connection cancelled messages

If authentication fails becomes the user cancels or because the password is wrong
the connection still has the same ConnectionStatusReason

We want to supress user cancelled auth so we check the connectionError string which
is more detailed and gives the reason the auth failed

REVIEW: 110028
FIXED-IN: 0.6.1

M  +3    -0    error-handler.cpp

http://commits.kde.org/telepathy-kded-module/68e2e30e9820d0b6fe146e1dceb9313e7a3f968c
Comment 34 Martin Kho 2014-03-26 10:26:52 UTC
Hi,

For me, right after login ktp fails - again - to connect to google talk with this error (short message: Cancelled by User) in combination with telepathy-mission-control version 5.15.0 and higher. Detailed information can be found in [1].

Martin Kho

[1] https://bugzilla.redhat.com/show_bug.cgi?id=1055176
Comment 35 David Edmundson 2014-03-26 10:31:49 UTC
Martin, thanks for the debugging on that. 
I really don't understand what's going on.

The kded module doesn't get involved during login. It does try to change presence on bootup, but that's about it.

I can't reproduce it here, which isn't helpful :(

Would it be possible to get a log output from bustle or dbus-monitor? Note these logs may contain your passwords if authentication gets that far.
Comment 36 Martin Kho 2014-03-26 10:53:12 UTC
Created attachment 85758 [details]
Output from dbus-monitor

Hi David,

Thanks for your reply! See the attachment. I've recorded all messages till ktp gives up connecting.

HTH

Martin Kho
Comment 37 Martin Kho 2014-03-26 11:30:51 UTC
Created attachment 85761 [details]
Output from dbus-monitor manual connect.

Hi again,

I've created dbus output when I manually ask ktp to go online. May be this output can be helpful? What I see is that the SSL Negotiated: connection got disconnecten seems not to be fatal.

Martin Kho
Comment 38 Martin Kho 2014-03-26 12:07:57 UTC
Hi,

Comparing the 'good' and 'bad' dbus-monitor outputs I see the following:

'good'
signal sender=:1.88 -> dest=(null destination) serial=33 path=/org/freedesktop/Telepathy/Connection/gabble/jabber/mdlkho_40gmail_2ecom_2fkde_2dtelepathy_2d657662/ServerTLSChannel1/TLSCertificateObject; interface=org.freedesktop.Telepathy.Authentication.TLSCertificate; member=Accepted

'bad'
signal sender=:1.23 -> dest=(null destination) serial=34 path=/org/freedesktop/Telepathy/Connection/gabble/jabber/mdlkho_40gmail_2ecom_2fkde_2dtelepathy_2d657662/ServerTLSChannel1/TLSCertificateObject; interface=org.freedesktop.Telepathy.Authentication.TLSCertificate; member=Accepted
method return sender=:1.23 -> dest=:1.89 reply_serial=36

The difference here is the serial number (33 'good' vs 34 'bad').  After this line the outputs get completely different. Don't know if this is interesting.

Martin Kho
Comment 39 David Edmundson 2014-03-26 12:13:34 UTC
Another useful debug may be to turn on debug output for ktp-auth-handler in kdebugdialog.

killall ktp-auth-handler
then run /usr/lib/kde4/libexec/ktp-auth-handler --debug --persist

and then connect.

Sorry for making you do lots of work. It really is appreciated.
Comment 40 Martin Klapetek 2014-03-26 12:14:01 UTC
The serial number is just an identification number, basically each new request should get new serial. This is used when replying, so you know which request the reply belongs to (iirc). So those different serials should be ok.
Comment 41 Martin Kho 2014-03-26 12:33:11 UTC
Output from /usr/libexec/kde4/ktp-auth-handler --debug --persist:
Note: connection succeed. It only fails after log in

ktp-auth-handler(2241) KTp::TelepathyHandlerApplication::newJob: New job started. 1 jobs currently running                                                                                                                                   
Unknown signature value: 668
Unknown signature value:  668
Unknown signature value:  669
Unknown signature value:  795
Unknown signature value:  668
Unknown signature value:  668
Unknown signature value:  668
Unknown signature value:  668
Unknown signature value:  795
Unknown signature value:  668
Unknown signature value:  668
Unknown signature value:  668
Unknown signature value:  795
Unknown signature value:  668
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  668 
Unknown signature value:  795 
Unknown signature value:  668 
Unknown signature value:  795 
Unknown signature value:  668 
ktp-auth-handler(2241) KTp::TelepathyHandlerApplication::jobFinished: Job finished. 0 jobs currently running
ktp-auth-handler(2241) KTp::TelepathyHandlerApplication::newJob: New job started. 1 jobs currently running
ktp-auth-handler(2241) SaslAuthOp::gotProperties: ("X-OAUTH2", "X-GOOGLE-TOKEN", "PLAIN", "X-TELEPATHY-PASSWORD")
ktp-auth-handler(2241) XTelepathyPasswordAuthOperation::onSASLStatusChanged: Requesting password
ktp-auth-handler(2241) XTelepathyPasswordAuthOperation::onSASLStatusChanged: Authenticating...
ktp-auth-handler(2241) XTelepathyPasswordAuthOperation::onSASLStatusChanged: Authentication handshake
ktp-auth-handler(2241) XTelepathyPasswordAuthOperation::onSASLStatusChanged: Authentication succeeded
ktp-auth-handler(2241) KTp::TelepathyHandlerApplication::jobFinished: Job finished. 0 jobs currently running
Comment 42 Martin Klapetek 2014-03-26 12:51:18 UTC
Do you use KWallet and do you have different password for your KWallet than your login password?
Comment 43 Martin Kho 2014-03-26 12:59:27 UTC
@Comment 42
Yes I use KWallet and use a blanco password for the KWallet. So yes my login password and KWallet passwords are different. :-)

Martin Kho
Comment 44 Martin Kho 2014-03-26 12:59:56 UTC
Hi,

I'm trying it now in Fedora 21 because here I can turn on all sorts of debugging options in kdebugdialog. (ktp 0.8.0). I get different results:
a. ktp connects mostly fine when there is a system notification (eg new mail, updates available)
b. ktp fails (no notifications) to connect with in .xsession-errors the folling messages:
"tp-qt 0.9.3 WARN: Nested PendingReady for true failed with "org.freedesktop.Telepathy.Error.Cancelled" : "SSL Negotiated: Connection got disconnected: Connection got disconnected"  
tp-qt 0.9.3 WARN: Building connection "/org/freedesktop/Telepathy/Connection/gabble/jabber/mdlkho_40gmail_2ecom_2fkde_2dtelepathy_2d657662" failed with "org.freedesktop.Telepathy.Error.Cancelled" - "SSL Negotiated: Connection got disconnected: Connection got disconnected"  
tp-qt 0.9.3 WARN: StatefulDBusProxy::uniqueNameFrom(): Failed to get unique name of "org.freedesktop.Telepathy.Connection.gabble.jabber.mdlkho_40gmail_2ecom_2fkde_2dtelepathy_2d657662"  
tp-qt 0.9.3 WARN:   error: "org.freedesktop.DBus.Error.NameHasNoOwner" message: "Could not get owner of name 'org.freedesktop.Telepathy.Connection.gabble.jabber.mdlkho_40gmail_2ecom_2fkde_2dtelepathy_2d657662': no such name"  
QDBusConnection: name 'org.freedesktop.Telepathy.Connection.gabble.jabber.mdlkho_40gmail_2ecom_2fkde_2dtelepathy_2d657662' had owner ':1.22' but we thought it was ''
tp-qt 0.9.3 WARN: Nested PendingReady for true failed with "org.freedesktop.DBus.Error.NameHasNoOwner" : "Could not get owner of name 'org.freedesktop.Telepathy.Connection.gabble.jabber.mdlkho_40gmail_2ecom_2fkde_2dtelepathy_2d657662': no such name"  
tp-qt 0.9.3 WARN: Building connection "/org/freedesktop/Telepathy/Connection/gabble/jabber/mdlkho_40gmail_2ecom_2fkde_2dtelepathy_2d657662" failed with "org.freedesktop.DBus.Error.NameHasNoOwner" - "Could not get owner of name 'org.freedesktop.Telepathy.Connection.gabble.jabber.mdlkho_40gmail_2ecom_2fkde_2dtelepathy_2d657662': no such name"
Comment 45 Martin Kho 2014-03-26 13:10:20 UTC
Hi,

I've entered a password for Kwallet (same as my login password) Now, after KMail asked me for my KWallet password ktp connects, at least in Fedora 21. I'll try it in Fedora 20 and let you know what happens there.

Martin
Comment 46 Martin Kho 2014-03-26 13:16:29 UTC
Hi,

Sorry, no in Fedora 20 it makes no difference with or without a password. ktp keeps failing.
Comment 47 Martin Kho 2014-03-26 13:21:14 UTC
btw.

In fedora 20 I also see in .xsession-errors I see: 
"unnamed app(1719): Communication problem with  "kwalletmanager" , it probably crashed. 
Error message was:  "org.freedesktop.DBus.Error.UnknownObject" : " "No such object path '/MainApplication'" "

No idea who the unamed app is. ktp-auth-handler, telepathy-gabble?
Comment 48 David Edmundson 2014-03-26 13:24:40 UTC
it could be ktp-auth-handler. 
gabble doesn't know about any KDE things, which is why we have the tiny ktp-auth-handler to proxy between the connections and KDE things.

I'm not sure what we'd do on kwallet crashing. It'd probably come to us as the user deciding not to open kwallet; which would match the error messages.
Comment 49 Martin Kho 2014-03-26 13:38:12 UTC
Well just after I wrote my last comment I got an update for ktp (from v.0.7.1 to 0.8.0). This version and a kwallet password connects! I think I have to live with a password for KWallet. I hated KWallet from the beginning it entered KDE ;-)

Thanks for you very friendly and patient help.

Martin Kho
If you want me to test more, please let me know.
Comment 50 Martin Klapetek 2014-03-26 13:43:28 UTC
That's great to hear, thanks a lot for the huuuge digging you did (I was watching the RH bug), you've been probably the best bug triager ever :) Thanks for that. I'll totally buy you some beers if you ever show at any KDE event :D
Comment 51 Martin Kho 2014-03-26 13:50:02 UTC
Oh, I was a little to quick. ktp still crashes on kwallet. It connects because kmail opens the wallet.
Comment 52 Martin Kho 2014-03-26 17:58:46 UTC
Hi David and Martin,

Comment 51 was false alarm. I did try to set a password in a 'clean' (no kmail start up) openSuse and that had no effect. Ktp failed to connect. There seems to be something else wrong. KWallet didn't start at all at log in.

As a final test I disabled KMail/akonadi on Fedora 20, removed all entries in KWallet except Telepathy-kde. Then logged out and in, even rebooted. Everytime ktp connected fine after being asked for my password. Next I removed KWallet's password, logged out/in and rebooted. Ktp was happy. At last I enabled KMail and didn't have any negative effect on ktp.

Again thanks and sorry for the noise :-)

Martin Kho
Btw. I don't think that the crashing 'unnamed app' has anything to do with ktp.
Comment 53 Martin Kho 2014-03-29 22:37:27 UTC
Hi,

Hum, me again :-( I got failures again. This time I focused more on what happens with the ktp's KDED-module. I turned on all debugging in debugdialog. The following is what I found:
Ktp connects fine:
1. Modules kded_ktp_integration_module and ktp_approver loaded successful
<lot of other things are loaded/initialized>
2. Module kssld is loaded
3. ContactRequestHandler::onNewAccountAdded is called
Ktp fails to connect:
1. Modules kded_ktp_integration_module and ktp_approver loaded successful
2. ContactRequestHandler::onNewAccountAdded is called

So can it be that it's a timing issue?

Martin Kho
See for the complete successful and failing debugging output .xsession-errors_fail and .xsession-errors_ok
Comment 54 Martin Kho 2014-03-29 22:39:16 UTC
Created attachment 85831 [details]
xsession-errors_fail
Comment 55 Martin Kho 2014-03-29 22:39:49 UTC
Created attachment 85832 [details]
xsession-errors_ok
Comment 56 David Edmundson 2014-03-29 23:04:01 UTC
Could you try removing the chat plasmoid.
There's some stuff in the logs about that.
Comment 57 Martin Kho 2014-03-30 07:54:29 UTC
Hi David,

I had no ktp plasmoids on my desktop. Moving them away from "/usr/share/kde4/services/" made no difference. Connecting still fails.

Martin Kho
Comment 58 Martin Kho 2014-03-31 17:31:35 UTC
Hi,

Maybe a little unfair, but empathy under gnome 3.10 (fedora 20) connects just fine. It connects immediatly after log in and empathy-debugger shows no errors. So my issue seems solely related to ktp/kde (not even to telepathy).

What me keeps puzzling is that I can't believe that I'm the only one in this big globalized world, who has this issue. Does no one else uses the same version of ktp as I do?

My problem is that I'm getting out of ideas where to search any further.

Martin Kho
Comment 59 Martin Kho 2014-04-09 11:21:05 UTC
Hi,

My last question on this issue. What do I miss when I remove "org.freedesktop.Telepathy.Client.KTp.KdedIntegrationModule.service" from "/usr/share/dbus-1/services/"?
I'm not using a ScreenSaver, nor a mpris2 player and MissionControl can autoconnect (ConnectAutomatically=true) on it's own.

Thanks,
Martin Kho
Comment 60 David Edmundson 2014-04-09 11:25:35 UTC
That autoconnect flag in MC is for something entirely different.
That means auto connect if a channel request on that account is made.
Comment 61 Martin Kho 2014-04-09 11:35:12 UTC
Hi,
So AutoConnect in MC is not the same thing as AutoConnect in kded_integrationModule?

Martin Kho
Comment 62 Martin Kho 2014-04-09 11:38:00 UTC
... is it AutomaticPresence (0;;;) in MC  terms or/and HasBeenOnline(=true)?
Comment 63 David Edmundson 2014-04-09 11:47:23 UTC
Automatic presence is the presence to go to when autoconnecting for the reason above.
It's a bit weird and confusing.
Comment 64 Martin Klapetek 2014-04-09 13:33:21 UTC
You'd loose incoming contact requests and contact presence change notifications (eg. when contact comes online) and also error handling (showing a notification when there's an error).
Comment 65 Martin Kho 2014-04-09 13:43:16 UTC
(In reply to comment #64)
Thanks for your explanation!
> You'd loose incoming contact requests
Meaning that when a contact wants to chat with me, I'll miss him/her?

> and contact presence change
> notifications (eg. when contact comes online)
Well, this is no problem, because people using andriod hangout messenger have never showed their status to me.

> and also error handling
> (showing a notification when there's an error).
Like "Network Error" or "Cancelled Connection by User" ;-)
Comment 66 Martin Klapetek 2014-04-09 13:48:56 UTC
> Meaning that when a contact wants to chat with me, I'll miss him/her?

It's when a contact does not have you in his/her list yet and asks for your permission to add you, you get an icon in systray to approve or deny that request, that will in turn add him/her into your contact list too. Then you can see the contact's presence and chat freely.
Comment 67 Martin Kho 2014-04-09 14:07:21 UTC
Hi,
@comment 66: Like people who found my google+ profile on the internet and think lets try to contact him via chat?

As an alternative to slolely removing the module I've also tried the following 'workaround':
1. Removed "org.freedesktop.Telepathy.Client.KTp.KdedIntegrationModule.service" from "/usr/share/dbus-1/services"
2. Put the command "/usr/bin/dbus-send --session --type=method_call --dest=org.kde.kded /kded org.kde.kded.loadModule string:"kded_ktp_integration_module"" in a KDE startup script. (System Settings -> Startup and Shutdown -> Autostart)

ktp connects immediately (no 20 seconds delay), No temporary freezes/blocking of other systemtray icons (e.g. klipper). Does this work? implement the right features?

I hope this gives me the best of two worlds: kded integration module features and succesful connections/online presences.

Martin Kho
Comment 68 Martin Kho 2014-04-09 14:12:03 UTC
Output from "qdbus org.kde.kded /modules/kded_ktp_integration_module":

method QDBusVariant org.freedesktop.DBus.Properties.Get(QString interface_name, QString property_name)
method QVariantMap org.freedesktop.DBus.Properties.GetAll(QString interface_name)
method void org.freedesktop.DBus.Properties.Set(QString interface_name, QString property_name, QDBusVariant value)
method QString org.freedesktop.DBus.Introspectable.Introspect()
method QString org.freedesktop.DBus.Peer.GetMachineId()
method void org.freedesktop.DBus.Peer.Ping()

This is the same as I get when dbus-daemon loads the module.
Comment 69 Martin Klapetek 2014-04-10 09:59:13 UTC
> ktp connects immediately (no 20 seconds delay), No temporary freezes/blocking of other systemtray icons (e.g. klipper).

This is interesting. It looks like something is blocking your startup. Do you use "restore session on login" system setting? Also what applications do you start on login? And what services you have in system settings -> startup and shutdown -> service manager? Anything that does not look like it's part of KDE?

When something is blocking KDED (the whole process), everything freezes, including the systray icons.
Comment 70 Martin Kho 2014-04-10 10:25:51 UTC
I use nothing special. It is (now it was, after some fiddling with service files) a fresh Fedora 20 KDE live cd on bare metal. Setup google-talk account in ktp, no other accounts. See further below.

(In reply to comment #69)
> > ktp connects immediately (no 20 seconds delay), No temporary freezes/blocking of other systemtray icons (e.g. klipper).
> 
> This is interesting. It looks like something is blocking your startup. Do
> you use "restore session on login" system setting?

The default: yes

 Also what applications do
> you start on login?

No applications, only a folder plasmoid (default)

 And what services you have in system settings -> startup
> and shutdown -> service manager? 
All services are default. I've tried to temporary remove all, but the telepathy/ktp, services. (Load-on-Demand and Startup Services were empty, except for the ktp ones). Disabled SELinux, systemd-flushing service. And in all cases experienced the blockings/freezes. 

Anything that does not look like it's part
> of KDE?
No other stuff installed.
> 
> When something is blocking KDED (the whole process), everything freezes,
> including the systray icons.

I gonna try Kubuntu 14.04 nightly build to see wat happens. 13.10 didn't work for me. For a moment I thought about some hardware/network issue. Tried installing in a vm without succes. Tried another network connection, without luck.
Comment 71 Martin Kho 2014-04-10 12:43:07 UTC
Hi,

It took a while to get Kubuntu 14.04 running :-) But here is what I found:
1. kpt didn't connect immediatly after log in. After ~20 sec. it failed because kwallet wasn't available (something with ibus-deamon?)
2. in ~/.cache/upstart/dbus.log I see the following lines:
"Activating service name='org.freedesktop.Telepathy.Client.KTp.KdedIntegrationModule'"
[snip]
"Failed to activate service 'org.freedesktop.Telepathy.Client.KTp.KdedIntegrationModule': timed out.
g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 bytes on an async read (g-io-error-quark, 0). Exiting."

So the registering of  the Kded Integration Module is also problematic in Kubuntu 14.04, or it completely fails.

Sorry but, I couldn't find ktp-debugger on Kubuntu 14.04. All packages got new names :-(

Martin Kho
P.S. If you need dbus.log and/or startkde.log please let me know.