using wired connection, gabble does not attempt reconnect to jabber server

[mikus]

When I asked "how to restart gabble?", one response I received was:

... just to wait a bit as Gabble will constantly try to connect to the jabber server using an exponential backoff

As far as I can tell, Gabble tries initially, but NEVER tries again.

G1G1, approximately at Joyride 1858 (I updated libertas-usb8388 via yum).

[Once upon a time, my USB-ethernet adapter was accessed through interface 'eth0'. Nowadays it seems to be through 'eth1'.]

[mikus]

log long after reboot. gabble seems to have tried jabber server only once

[gdesmott]

Humm Gabble seems to be connecting to your server. Could you enable LM_DEBUG=net in your log please? See http://wiki.laptop.org/go/Telepathy-debug

[mikus]

Replying to gdesmott:

Humm Gabble seems to be connecting to your server. Could you enable LM_DEBUG=net in your log please? See http://wiki.laptop.org/go/Telepathy-debug

I do not understand your request.

LM_DEBUG=net is already enabled in my /home/olpc/.xsession file. I believe it *has* been enabled for all the telepathy logs I've been attaching, going back several months.

[gdesmott]

Humm that's really weird. Was telepathy-gabble still running when you take this log? Could you try using olpc.collabora.co.uk as Jabber server instead of your own?

[mikus]

server_plugin.py not patched to access proxy (gabble ended, salut is running)

[mikus]

new build. Gabble ended. No change to telepathy logs afterwards (for hours and hours)

[gdesmott]

Humm interesting. I never saw this error before:

Freeing up IOChannel and file descriptor
** (telepathy-gabble:1774): DEBUG: connection_disconnected_cb: called with reason 3
** (telepathy-gabble:1774): DEBUG: connection_disconnected_cb: unexpected; calling tp_base_connection_change_status

[gdesmott]

I'd like to understand why you got this in your log

1208370564.758024 WARNING telepathy.client.interfacefactory: Exception from asynchronous method call:
org.freedesktop.DBus.Error.UnknownMethod: Method "GetStatus" with signature "" on interface "org.freedesktop.Telepathy.Connection" doesn't exist

I added few debug outputs to PS. I'll ask to ship a new PS with them in Joyride. Or maybe you could manually apply it? The patch: https://dev.laptop.org/git?p=projects/presence-service;a=commitdiff_plain;h=58834c901da02177301ec63b610e5cf7afde00ec

[gdesmott]

About the weird disconnection

<ptlo> cassidy: no idea, it might have been innocous debug message; but afaik, lm doesn't spontaneously end connections, so if it was terminated, i think it was probably a network error

[mikus]

proxy not running; logs taken an hour after XO boot

[mikus]

proxy up; booted XO; collabora jabber o.k.; Neighborhood depopulated; captured logs showing Gabble going away

[gdesmott]

Could you apply this PS patch and retry please: https://dev.laptop.org/git?p=projects/presence-service;a=blobdiff_plain;f=src/telepathy_plugin.py;fp=src/telepathy_plugin.py;h=c85bdd143e60b11d1be3a8a6e07ddf5221beb31f;hp=737023b6326d3a28e3cac2b1739c73fe298a1369;hb=507e53d55d2f0767f35777e2db40abd654605f08;hpb=58834c901da02177301ec63b610e5cf7afde00ec

[mikus]

probably not helpful - XO had trouble setting up IPv4 link

[mikus]

gabble doesn't appear to be failing today -- usually it "gives up" after an hour or two

[mikus]

gabble gave up just as I was trying to capture logs. Here are logs a bit later - gabble is up again.

[gdesmott]

Great, so Gabble properly reconnect as expected. Closing this bug.

[mikus]

You are too quick to close this ticket - should users keep restarting Sugar in order to have Gabble work as it should ??

Did you even look at the log before saying 'fixed'? Which entries in the log show a reconnect taking place ??

This morning the Neighborhood view was depopulated. 'ps ax | grep telepathy' shows both gabble and salut present. The last thing in telpathy-gabble log is gabble giving up. Nothing that would show to me that "Gabble properly reconnect as expected".

I'm reopening this ticket - I don't see it being 'fixed'.

[mikus]

log shows Gabble giving up (a couple hours before the log was taken)

[gdesmott]

Replying to mikus:

Did you even look at the log before saying 'fixed'? Which entries in the log show a reconnect taking place ??

Yes I did. Look at presenceservice.log and grep for "ServerPlugin". It appears the ServerPlugin was disconnected and reconnected a lot of times.

But I agree, something did wrong. At the end of this file, the ServerPlugin is reported as connecting and then log stops. That's weird because according telepathy-gabble log (this file only contains log about the last connection) it did connect but then the connection was closed. I didn't notice that the first time because I only checked PS log which does indicate that Gabble tries to reconnect. Sorry.

[mikus]

Just did ctl-alt-erase. salut came up, not gabble. [This is second try. On first try (same situation), even two hours after the Sugar restart, none of the .sugar/default/logs had changed their timestamps nor size -- i.e., no evidence of gabble retrying.]

WHAT can I do at the console to restart gabble ?

[mikus]

after ctl-alt-erase, salut comes up. gabble appears not to retry.

[gdesmott]

WHAT can I do at the console to restart gabble ?

You can't

Looking at your latest logs. Gabble wasn't started because for some reason network-manager doesn't inform PS of your IP address. So it didn't try to connect Gabble.

[mikus]

FYI - two more logs (my mind is blank; I think they show gabble nor running). Taken with Joyride 1894 (with telepathy_plugin.py as it came in 1894).

From what you said earlier, I take it that gabble replaces its previous log each time it starts anew. Did not realize that.

[mikus]

Running with latest sugar-presence-service (0.79.3-1.olpc2).

I guess I'm seeing that the *narrow* definition of this ticket is now being met -- Gabble does restart automatically, such that some six hours after I booted the XO, there are intervals when the Neighborhood screen is populated (with icons for users connected to the jabber server).

HOWEVER, there are also intervals when Salut is running instead of Gabble (and the Neighborhood screen shows no icons besides mine). Sometimes I have to wait and wait in order to see Gabble again populating the Neighborhood screen with the icons of the users connected to the jabber server. I do not think that "not seeing Gabble output" can be considered 'fixed' by simply claiming that "oh, Gabble will come back eventually".

[mikus]

presence as in 1896. logs taken shortly after boot. gabble restarted afterward

[mikus]

presence as in 1896. logs taken 5+ hours after booting.

[gdesmott]

According the end of your presence-service.log:

1209026906.321914 DEBUG s-p-s.telepathy_plugin: <ServerPlugin object at 0x81fa89c (telepathy_plugin+TelepathyPlugin at 0x828ca00)>: restart reconnect time out (320 seconds)

So, it didn't try to reconnect Gabble after 320 seconds?

[mikus]

Replying to gdesmott:

So, it didn't try to reconnect Gabble after 320 seconds?

Seeing that my XO Neighborhood screen is currently populated (some 16 hours after being booted), Gabble *did* reconnect.

But I DEFINITELY do not have the patience to wait 5+ minutes to re-establish contact (via jabber server) with another user. I doubt whether a child would have that much patience, either.

[mikus]

rainbow disabled. Neighborhood depopulated. Looked at Neighborhood 15 min later - still depopualated. 'ps' shows salut AND gabble - I believe here Gabble is not restarting

[mikus]

Figured out what is happening. Gabble properly accesses the proxy, but when the proxy tries to access olpc.collabora.co.uk, what it gets back is a packet with the 'RST' flag set. That causes the proxy to tell Gabble "503 Service Unavailable". Gabble then continues to wait for a connection, and Salut takes over.

I do not know if Gabble does/does_not attempt to restart (if it does, what it is writing out is a new log that looks just like the previous log).

[mikus]

Wireless. Gabble could not connect to olpc.collabora.co.uk (ping works)

[mikus]

This ticket has been open long enough -- I'm going to close it. I'll consider the specific item described in the Summary to be fixed -- I *have* seen Gabble restart after sugar-presence-service was updated to 0.79.3-1.olpc2.

I'm STILL not seeing my Neighborhood view being populated with user-icons by Gabble -- but let that problem be addressed in a different ticket (e.g., #6949).

[gregorio]

Milestone Never Assigned deleted