[Telepathy] Can't open chat window from Empathy for specific contact (with workaround)

Pedro Francisco pedrogfrancisco at gmail.com
Wed Jul 18 03:56:35 PDT 2012


Hi again!
I can't open chat windows; clicking one specific contact will spawn
the Gnome-Shell notification icon but no window. Clicking the
Gnome-shell notification icon for the contact will do nothing.

Though no Empathy chat window is running,
$ ps ax |grep empathy-chat
15237 ?        Sl     0:33 /usr/libexec/empathy-chat

Killing that process usually solves the problem (using kill 15237 ,
since on this case killall /usr/libexec/empathy-chat wouldn't work)

---------------------------------------------
When the Gnome-Shell notification is spawned but I am unable to open a
Chat Window by clicking Open on it:
---------------------------------------------
empathy-debugger window for mission control:
mcd-DEBUG: 07/18/2012 11:24:05.973683: dispatcher_delegate_channels: called
mcd-DEBUG: 07/18/2012 11:24:05.974142: try_delegating:
/org/freedesktop/Telepathy/Connection/gabble/jabber/me_40gmail_2ecom_2fe162dc12/ImChannel42
mcd-DEBUG: 07/18/2012 11:24:05.974536: try_delegating: ...trying client :1.425
mcd-DEBUG: 07/18/2012 11:24:05.974904:
_mcd_client_proxy_handle_channels: calling HandleChannels on
org.freedesktop.Telepathy.Client.Empathy.Chat
mcd-DEBUG: 07/18/2012 11:24:05.975414: _mcd_channel_set_status: 0x974b858, 4


---------------------------------------------
When after a few tries (e.g., clicking 'remove' from Gnome-Shell
notification) not even Gnome-Shell notification is spawned after
clicking the contact on Empathy:
---------------------------------------------
empathy-debugger window for mission control:
mcd-DEBUG: 18-07-2012 11:30:00.295790:
dispatcher_channel_request_acl_start: start
/org/freedesktop/Telepathy/Account/gabble/jabber/goa_google_account_1337788239.org.freedesktop.Telepathy.Connection.Interface.Requests.EnsureChannel
acl (0x972ec00)
mcd-DEBUG: 18-07-2012 11:30:00.296391:
dispatcher_channel_request_acl_success: complete acl (0x972ec00)
mcd-DEBUG: 18-07-2012 11:30:00.297035: _mcd_request_init: 0x975caa8
mcd-DEBUG: 18-07-2012 11:30:00.297787: _mcd_request_new: 0x975caa8
(for 0x965c450)
mcd-DEBUG: 18-07-2012 11:30:00.298571: _mcd_channel_set_status: 0x965d9d8, 1
mcd-DEBUG: 18-07-2012 11:30:00.299083: _mcd_request_predict_handler:
Default handler org.freedesktop.Telepathy.Client.Empathy.Chat for
request /org/freedesktop/Telepathy/ChannelDispatcher/Request42 doesn't
want AddRequest
mcd-DEBUG: 18-07-2012 11:30:00.299470:
dispatcher_channel_request_acl_cleanup: cleanup acl (0x972ec00)
mcd-DEBUG: 18-07-2012 11:30:00.304351: ready_to_request_cb: Starting
online request
mcd-DEBUG: 18-07-2012 11:30:00.304737: _mcd_account_online_request:
connection status for gabble/jabber/goa_google_account_1337788239 is 0
mcd-DEBUG: 18-07-2012 11:30:00.305115: _mcd_account_online_request:
gabble/jabber/goa_google_account_1337788239 is already connected
mcd-DEBUG: 18-07-2012 11:30:00.305510: online_request_cb: called
mcd-DEBUG: 18-07-2012 11:30:00.305891: _mcd_mission_set_parent: child
= 0x965d9d8, parent = 0x965ac88
mcd-DEBUG: 18-07-2012 11:30:00.306565: _mcd_channel_set_status: 0x965d9d8, 2
mcd-DEBUG: 18-07-2012 11:30:00.312288: common_request_channel_cb:
0x965d9d8, object
/org/freedesktop/Telepathy/Connection/gabble/jabber/me_40gmail_2ecom_2fe162dc12/ImChannel42
mcd-DEBUG: 18-07-2012 11:30:00.312694:
_mcd_dispatcher_add_channel_request: non-reinvoked handling of channel
0x965d9d8
mcd-DEBUG: 18-07-2012 11:30:00.313071: copy_status: source is 4, dest is 2
mcd-DEBUG: 18-07-2012 11:30:00.313463: _mcd_channel_set_status: 0x965d9d8, 4
mcd-DEBUG: 18-07-2012 11:30:00.313859:
_mcd_dispatcher_add_channel_request: channel 0x965d9d8 is proxying
0x97429d0
mcd-DEBUG: 18-07-2012 11:30:00.764520: _mcd_channel_set_status: 0x97429d0, 5
mcd-DEBUG: 18-07-2012 11:30:00.765131: copy_status: source is 5, dest is 4
mcd-DEBUG: 18-07-2012 11:30:00.765729: _mcd_channel_set_status: 0x965db18, 5
mcd-DEBUG: 18-07-2012 11:30:00.766316: _mcd_request_set_success:
Request succeeded
mcd-DEBUG: 18-07-2012 11:30:00.767978: mcd_channel_abort: 0x965db18
mcd-DEBUG: 18-07-2012 11:30:00.768595: _mcd_channel_set_status: 0x965db18, 7
mcd-DEBUG: 18-07-2012 11:30:00.769181: _mcd_mission_set_parent: child
= 0x965db18, parent = (nil)
mcd-DEBUG: 18-07-2012 11:30:00.769778: _mcd_operation_remove_mission:
removing mission: 0x965db18
mcd-DEBUG: 18-07-2012 11:30:00.770365: _mcd_channel_dispose: 0x965db18
(is disposed = 0)
mcd-DEBUG: 18-07-2012 11:30:00.770932: _mcd_mission_dispose: mission
disposed 0x965db18
mcd-DEBUG: 18-07-2012 11:30:00.771616: _mcd_mission_finalize: mission
finalized 0x965db18
mcd-DEBUG: 18-07-2012 11:30:00.772192: copy_status: source is 5, dest is 4
mcd-DEBUG: 18-07-2012 11:30:00.772764: _mcd_channel_set_status: 0x965d9d8, 5
mcd-DEBUG: 18-07-2012 11:30:00.773346: _mcd_request_set_success:
Request succeeded
mcd-DEBUG: 18-07-2012 11:30:00.774955: mcd_channel_abort: 0x965d9d8
mcd-DEBUG: 18-07-2012 11:30:00.783513: _mcd_channel_set_status: 0x965d9d8, 7
mcd-DEBUG: 18-07-2012 11:30:00.783921: _mcd_mission_set_parent: child
= 0x965d9d8, parent = (nil)
mcd-DEBUG: 18-07-2012 11:30:00.784322: _mcd_operation_remove_mission:
removing mission: 0x965d9d8
mcd-DEBUG: 18-07-2012 11:30:00.784702: _mcd_channel_dispose: 0x965d9d8
(is disposed = 0)
mcd-DEBUG: 18-07-2012 11:30:00.785084: _mcd_mission_dispose: mission
disposed 0x965d9d8
mcd-DEBUG: 18-07-2012 11:30:00.785495: _mcd_mission_finalize: mission
finalized 0x965d9d8
mcd-DEBUG: 18-07-2012 11:30:00.785882: delegate_channels_cb: Handler
refused delegated channels
mcd-DEBUG: 18-07-2012 11:30:00.786266: try_delegating:
/org/freedesktop/Telepathy/Connection/gabble/jabber/me_40gmail_2ecom_2fe162dc12/ImChannel42
mcd-DEBUG: 18-07-2012 11:30:00.786670: try_delegating: ...but failed
to delegate it:
/org/freedesktop/Telepathy/Connection/gabble/jabber/me_40gmail_2ecom_2fe162dc12/ImChannel42


empathy-debugger window for Empathy.chat:
<empty>


strace `pidof empathy-chat` :
(...)
(should have clicked the contact around here)
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, "a\2\311:\267)d\1\3\30\10\0\20\0\0\0\0\0\0\30\30\30\30\30\0\0\3\37@\2\0\0",
4096, 0) = 32
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=7, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
recvmsg(7, {msg_name(0)=NULL,
msg_iov(1)=[{"l\4\1\1\367\0\0\0\333\25\0\0\7\1\0\0\1\1o\0\\\0\0\0/org/fre"...,
2048}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC},
MSG_CMSG_CLOEXEC) = 527
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
recvmsg(7, 0xbfebb650, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource
temporarily unavailable)
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, 0) = 1 ([{fd=5, revents=POLLIN}])
read(5, "\3\0\0\0\0\0\0\0", 16)         = 8
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=7, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
recvmsg(7, {msg_name(0)=NULL,
msg_iov(1)=[{"l\4\1\1%\0\0\0\334\25\0\0\357\0\0\0\1\1o\0\\\0\0\0/org/fre"...,
2048}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC},
MSG_CMSG_CLOEXEC) = 293
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
recvmsg(7, 0xbfebb650, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource
temporarily unavailable)
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, 0) = 1 ([{fd=5, revents=POLLIN}])
read(5, "\3\0\0\0\0\0\0\0", 16)         = 8
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=3, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, "a\2\311:\355-d\1\3\20\0\0\20\0\0\0\0\0\0\20\20\20\20\20\0\0\3\37@\3\0\0",
4096, 0) = 32
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=3, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, "\34\0\311:\254\0\0\0\327\1\0\0C.d\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
4096, 0) = 64
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=3, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, "\34\0\311:\254\0\0\0\327\1\0\0C.d\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
4096, 0) = 64
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=3, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, "\34\0\311:\254\0\0\0\327\1\0\0\200.d\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
4096, 0) = 256
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=7, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
recvmsg(7, {msg_name(0)=NULL,
msg_iov(1)=[{"l\1\0\1x\6\0\0[r\0\0\356\0\0\0\1\1o\0.\0\0\0/org/fre"...,
2048}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC},
MSG_CMSG_CLOEXEC) = 1912
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
recvmsg(7, 0xbfebb650, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource
temporarily unavailable)
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, 0) = 1 ([{fd=5, revents=POLLIN}])
read(5, "\3\0\0\0\0\0\0\0", 16)         = 8
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, 0) = 0 (Timeout)
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=3, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, "\34\0\311:\254\0\0\0\327\1\0\0/5d\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
4096, 0) = 64
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=3, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, "\34\0\311:\254\0\0\0\327\1\0\0\2075d\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
4096, 0) = 256
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1) = 1 ([{fd=3, revents=POLLIN}])
read(5, 0xbfebb80c, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, "a\2\311:\3376d\1\3\24\4\0\20\0\0\0\0\0\0\24\24\24\24\24\0\0\3\37%\2\0\0",
4096, 0) = 32
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
recv(3, 0x84f7120, 4096, 0)             = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=5, events=POLLIN}, {fd=3, events=POLLIN}, {fd=6,
events=POLLIN}, {fd=10, events=POLLIN}, {fd=13, events=POLLIN}, {fd=7,
events=POLLIN}], 6, -1^CProcess 15237 detached
 <detached ...>


Theory: connection dropps, empathy-chat gets confused, I close
empathy-chat window, it gets in a limbo state.

Should I open a bug report? Or has it been fixed somewhere?

telepathy-glib-0.18.1
telepathy-gabble-0.16.1
empathy-3.4.2.3
telepathy-mission-control-5.12.1

Thanks in advance for your help!
-- 
Pedro


More information about the telepathy mailing list