[Rtcomm] [Rtcomm] [Bug 3455] telepathy-gabble deadlooping

Wed May 13 05:02:13 EEST 2009

https://bugs.maemo.org/show_bug.cgi?id=3455

------- Comment #15 from maemo at subs.maneos.org  2009-05-13 05:02 GMT+3 -------
I saw this again earlier on a bad bt/hspa connection.  Unfortunately I didn't
have debug symbols installed, but for what it's worth this is the information I
managed to get out of it:

strace showed it looping on

    gettimeofday({1242165304, 759838}, NULL) = 0
    read(5, 0xa46a8, 5)                     = -1 EAGAIN (Resource temporarily
unavailable)

at around 200Hz, with the tz argument to gettimeofday() changing every time.   
I interrupted it with gdb a number of times and it seemed to be bouncing
between libc/libssl/libcrypto.  There was no output at all from ltrace.  FD 5
was a socket.

Telepathy-gabble was running with GABBLE_DEBUG=connection, and it logged the
following:

22:48:14 GLIB DEBUG default - started version 0.6.2.1 (telepathy-glib version
0.7.0)
22:48:14 GLIB DEBUG default - tp_base_connection_class_init: Initializing
(TpBaseConnectionClass *)0x693b8
22:48:14 GLIB DEBUG default - gabble_connection_class_init: Initializing
(GabbleConnectionClass *)0x69658
22:48:14 GLIB DEBUG default - tp_base_connection_init: Initializing
(TpBaseConnection *)0x6c808
22:48:14 GLIB DEBUG default - gabble_connection_init: Initializing
(GabbleConnection *)0x6c808
22:48:14 GLIB DEBUG default - tp_base_connection_constructor:
Post-construction: (TpBaseConnection *)0x6c808
22:48:14 GLIB DEBUG default - tp_base_connection_constructor: Handle repo for
type #0 at (nil)
22:48:14 GLIB DEBUG default - tp_base_connection_constructor: Handle repo for
type #1 at 0x6b320
22:48:14 GLIB DEBUG default - tp_base_connection_constructor: Handle repo for
type #2 at 0x6b350
22:48:14 GLIB DEBUG default - tp_base_connection_constructor: Handle repo for
type #3 at 0x5ebc0
22:48:14 GLIB DEBUG default - tp_base_connection_constructor: Handle repo for
type #4 at 0x6b380
22:48:14 GLIB DEBUG default - tp_base_connection_constructor: Channel factory
#0 at 0x6b400
22:48:14 GLIB DEBUG default - tp_base_connection_constructor: Channel factory
#1 at 0x6b430
22:48:14 GLIB DEBUG default - tp_base_connection_constructor: Channel factory
#2 at 0x6e410
22:48:14 GLIB DEBUG default - tp_base_connection_constructor: Channel factory
#3 at 0x5ece0
22:48:14 GLIB DEBUG default - gabble_connection_constructor: Post-construction:
(GabbleConnection *)0x6c808
22:48:14 GLIB DEBUG default - tp_base_connection_register: bus name
org.freedesktop.Telepathy.Connection.gabble.jabber.lucas_40maneos_2eorg_2fN810
22:48:14 GLIB DEBUG default - tp_base_connection_register: object path
/org/freedesktop/Telepathy/Connection/gabble/jabber/lucas_40maneos_2eorg_2fN810
22:48:16 GLIB DEBUG default - _gabble_connection_connect: disabling SRV because
"server" or "port" parameter specified, will connect to home.maneos.org
22:48:16 GLIB DEBUG default - do_connect: calling lm_connection_open
22:48:16 GLIB DEBUG default - tp_base_connection_change_status: was 4294967295,
now 1, for reason 1
22:48:16 GLIB DEBUG default - tp_base_connection_change_status: emitting
status-changed to 1, for reason 1
22:48:43 GLIB DEBUG default - do_auth: authenticating with username: lucas,
password: <hidden>, resource: N810 

and the server logs show:

=INFO REPORT==== 2009-05-12 22:48:43 ===
I(<0.272.0>:ejabberd_listener:116) : (#Port<0.7291>) Accepted connection
{{0,0,0
,0,0,65535,55723,33090},48659} -> {{0,0,0,0,0,65535,20923,21156},5222}

=INFO REPORT==== 2009-05-12 22:48:43 ===
D(<0.12746.0>:ejabberd_receiver:306) : Received XML on stream = "<?xml
version='
1.0' encoding='UTF-8'?>"

=INFO REPORT==== 2009-05-12 22:48:43 ===
D(<0.12746.0>:ejabberd_receiver:306) : Received XML on stream = "<stream:stream 
version=\"1.0\" xmlns=\"jabber:client\"
xmlns:stream=\"http://etherx.jabber.org/
streams\" to=\"maneos.org\" id=\"98850496166\">"

=INFO REPORT==== 2009-05-12 22:48:43 ===
D(<0.12747.0>:ejabberd_c2s:1352) : Send XML on stream = "<?xml
version='1.0'?><s
tream:stream xmlns='jabber:client'
xmlns:stream='http://etherx.jabber.org/stream
s' id='2015248111' from='maneos.org' version='1.0' xml:lang='en'>"

=INFO REPORT==== 2009-05-12 22:48:43 ===
D(<0.12747.0>:ejabberd_c2s:1352) : Send XML on stream =
"<stream:features><start
tls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms
xmlns='urn:ietf:params:
xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism><mechanism>PLAIN</mechanism><
/mechanisms><register
xmlns='http://jabber.org/features/iq-register'/></stream:f
eatures>"

=INFO REPORT==== 2009-05-12 22:48:43 ===
D(<0.12746.0>:ejabberd_receiver:306) : Received XML on stream = "<starttls
xmlns
=\"urn:ietf:params:xml:ns:xmpp-tls\" id=\"8461984942\"></starttls>\n"

=INFO REPORT==== 2009-05-12 22:48:43 ===
D(<0.12746.0>:shaper:61) : State: {maxrate,1000,0,1242164923130174}, Size=78
M=39.0, I=540.718

=INFO REPORT==== 2009-05-12 22:48:43 ===
D(<0.12746.0>:ejabberd_receiver:306) : Received XML on stream = []

=INFO REPORT==== 2009-05-12 22:48:43 ===
D(<0.12746.0>:shaper:61) : State: {maxrate,1000,72.11485122151463,
                                      1242164923670978}, Size=0
M=0.0, I=11.84

=INFO REPORT==== 2009-05-12 22:48:44 ===
D(<0.12746.0>:ejabberd_receiver:306) : Received XML on stream = []

=INFO REPORT==== 2009-05-12 22:48:44 ===
D(<0.12746.0>:shaper:61) : State: {maxrate,1000,36.05742561075731,
                                      1242164923682899}, Size=0
M=0.0, I=985.167

I couldn't reproduce later.

Other info: the libloudmouth used has the patch from bug 4119, and ipv6.ko was
loaded.

-- 
Configure bugmail: https://bugs.maemo.org/userprefs.cgi?tab=email
Replies to this email are NOT read, instead please add comments at
https://bugs.maemo.org/show_bug.cgi?id=3455
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.