GTalkSMS 1.7 goes offline and stays so

GoogleCodeExporter commented 8 years ago

GTalkSMS goes offline after some time. Pressing Start/Stop reconnects the 
jabber presence:

Jabber Client Log:
[17:13:05] My Droid is now Available (GTalkSMS - 97%)
[17:19:01] My Droid is now Offline

adb logcat:
01-09 16:28:46.121 V/gtalksms( 3459): connection established
01-09 16:28:46.121 V/gtalksms( 3459): broadcasting state transition from 1 to 2
01-09 16:28:46.129 D/gtalksms( 3459): handled action 
'com.googlecode.gtalksms.action.NETWORK_CHANGED' - state now 2
01-09 16:28:46.129 D/gtalksms( 3459): setupListenersForConnection
01-09 16:28:46.133 D/gtalksms( 3459): widget onReceive 
com.googlecode.gtalksms.XMPP_CONNECTION_CHANGED
01-09 16:28:46.137 D/gtalksms( 3459): onStart: _serviceHandler.sendMessage
01-09 16:28:46.551 D/gtalksms( 3459): handling action 
'com.googlecode.gtalksms.action.HANDLE_XMPP_NOTIFY' while in state 2
01-09 16:28:46.551 D/gtalksms( 3459): handled action 
'com.googlecode.gtalksms.action.HANDLE_XMPP_NOTIFY' - state now 2
01-09 16:28:46.551 D/gtalksms( 3459): handling action 
'com.googlecode.gtalksms.action.HANDLE_XMPP_NOTIFY' while in state 2
01-09 16:28:46.551 D/gtalksms( 3459): handled action 
'com.googlecode.gtalksms.action.HANDLE_XMPP_NOTIFY' - state now 2
01-09 16:28:46.551 D/gtalksms( 3459): handling action 
'com.googlecode.gtalksms.action.HANDLE_XMPP_NOTIFY' while in state 2
01-09 16:28:46.551 D/gtalksms( 3459): handled action 
'com.googlecode.gtalksms.action.HANDLE_XMPP_NOTIFY' - state now 2
01-09 17:19:05.387 I/gtalksms( 4319): service created
01-09 17:19:05.387 E/gtalksms( 4319): onStart: Intent null

Original issue reported on code.google.com by fschm...@gmail.com on 9 Jan 2011 at 5:25

GoogleCodeExporter commented 8 years ago

looks like the service crashes for some reason:

01-10 12:58:33.801 I/StatusBarPolicy( 2461): BAT. status:2 health:2
01-10 12:58:33.801 D/WifiService( 2461): ACTION_BATTERY_CHANGED pluggedType: 2
01-10 12:59:00.020 I/ActivityManager( 2461): No longer want 
com.googlecode.gtalksmsdonate (pid 8534): hidden #16
01-10 12:59:00.039 D/UnlockClock( 2461): GMT_update 
mRightNow.getTimeZone().getID() == Europe/Berlin
01-10 12:59:00.047 D/UnlockClock( 2461): GMT_update current == Europe/Berlin, 
TimeZone.getTimeZone(current).getID() == Europe/Berlin
01-10 12:59:00.184 W/ActivityManager( 2461): Scheduling restart of crashed 
service com.googlecode.gtalksmsdonate/com.googlecode.gtalksms.MainService in 
5000ms
01-10 12:59:05.211 I/ActivityManager( 2461): Start proc 
com.googlecode.gtalksmsdonate for service 
com.googlecode.gtalksmsdonate/com.googlecode.gtalksms.MainService: pid=10074 
uid=10058 gids={3003, 1015, 1007}
01-10 12:59:05.274 I/Zygote  (10074): Zygote: pid 10074 has INTERNET 
permission, then set capability for CAP_NET_RAW
01-10 12:59:05.352 I/gtalksms(10074): service created
01-10 12:59:05.352 E/gtalksms(10074): onStart: Intent null

Original comment by fschm...@gmail.com on 10 Jan 2011 at 1:21

GoogleCodeExporter commented 8 years ago

01-10 12:59:00.020 I/ActivityManager( 2461): No longer want 
com.googlecode.gtalksmsdonate (pid 8534): hidden #16

Your process has been kill by Android... Maybe you have no more free memory ?
Restart your phone may help.

01-10 12:59:00.184 W/ActivityManager( 2461): Scheduling restart of crashed 
service com.googlecode.gtalksmsdonate/com.googlecode.gtalksms.MainService in 
5000ms
Then it try to restart it... but we don't manage null intents so reconnection 
is never done

Todo: try to manage null intent in GTalkSMS (always start service ?)

Original comment by Florent....@gmail.com on 10 Jan 2011 at 1:27

GoogleCodeExporter commented 8 years ago

Ok looks like its no chrash, but a planed kill by the ActivityManager. While 
.startForground() could prevent this (see: 
http://stackoverflow.com/questions/3297204/android-service-killed-with-no-longer
-want-how-to-restart-it), I think the cleanest way would be to save the current 
state in a shared preference so that the newly created service can change to 
this state.

Memory is always a problem on the Galaxy S (only 348MB) :)

Original comment by fschm...@gmail.com on 10 Jan 2011 at 1:31

GoogleCodeExporter commented 8 years ago

Unfortunately we already use startforground but only with notification bar icon

Original comment by Florent....@gmail.com on 10 Jan 2011 at 9:49

GoogleCodeExporter commented 8 years ago

The docs for startService say: "This may be null if the service is being 
restarted after its process has gone away, and it had previously returned 
anything except START_STICKY_COMPATIBILITY." - which describes us.  As our 
service is only in the running state while connected, we probably don't need to 
save off the current state in a preference - the fact we get a null intent is 
enough to imply we were connected when stopped.

Original comment by skippy.hammond@gmail.com on 10 Jan 2011 at 10:49

GoogleCodeExporter commented 8 years ago

Yes I think that too, I'll try it tomorrow on my phone
Fix commited (restart xmpp connection on null intent)

Original comment by Florent....@gmail.com on 11 Jan 2011 at 12:07

Changed state: WaitingForRelease

GoogleCodeExporter commented 8 years ago

Fixed in 1.7.1

Original comment by Florent....@gmail.com on 12 Jan 2011 at 11:16

Changed state: Fixed

GoogleCodeExporter commented 8 years ago

Just tested 1.7.1 - looks like the connection on service.onStart with Null 
Intent is never started (Missing ACTION_CONNECT ?). Also there is a wrong log 
at line 415 "            Log.d(Tools.LOG_TAG, "onStart: 
ACTION_MESSAGE_RECEIVED");".

Here is the output from the log collector feature, I will try to get adb output 
too.

01-13 14:14:42.453 I/gtalksms(31268): service created
01-13 14:14:42.453 E/gtalksms(31268): onStart start connection: Intent null
01-13 14:14:42.453 D/gtalksms(31268): onStart: ACTION_MESSAGE_RECEIVED
01-13 14:15:44.364 I/gtalksms(31268): notifying that the network is unavailable
01-13 14:15:44.364 I/gtalksms(31268): notifying that a network is available...
01-13 14:15:44.371 D/gtalksms(31268): onStart: _serviceHandler.sendMessage
01-13 14:15:44.371 D/gtalksms(31268): handling action 
'com.googlecode.gtalksms.action.NETWORK_CHANGED' while in state 0
01-13 14:15:44.371 D/gtalksms(31268): network_changed with available=false and 
with state=0
01-13 14:15:44.371 D/gtalksms(31268): handled action 
'com.googlecode.gtalksms.action.NETWORK_CHANGED' - state now 0
01-13 14:15:44.371 D/gtalksms(31268): more pending intents to be delivered - 
service will not stop
01-13 14:15:44.371 D/gtalksms(31268): onStart: _serviceHandler.sendMessage
01-13 14:15:44.371 D/gtalksms(31268): handling action 
'com.googlecode.gtalksms.action.NETWORK_CHANGED' while in state 0
01-13 14:15:44.371 D/gtalksms(31268): network_changed with available=true and 
with state=0
01-13 14:15:44.371 D/gtalksms(31268): handled action 
'com.googlecode.gtalksms.action.NETWORK_CHANGED' - state now 0
01-13 14:15:44.371 D/gtalksms(31268): service is stopping (we are disconnected 
and no pending intents exist.)
01-13 14:15:44.371 I/gtalksms(31268): service destroyed
01-13 14:15:44.399 D/gtalksms(31268): teardownListenersForConnection
01-13 14:33:26.340 I/gtalksms(31268): service created
01-13 14:33:33.270 I/gtalksms(31268): service destroyed
01-13 14:33:33.270 D/gtalksms(31268): teardownListenersForConnection

Original comment by fschm...@gmail.com on 13 Jan 2011 at 1:54

GoogleCodeExporter commented 8 years ago

Original comment by Florent....@gmail.com on 13 Jan 2011 at 6:43

Changed state: Investigating

GoogleCodeExporter commented 8 years ago

Force reconnection on null intent

Original comment by Florent....@gmail.com on 16 Jan 2011 at 7:11

Changed state: WaitingForRelease

GoogleCodeExporter commented 8 years ago

Fixed in 1.7.2

Original comment by Florent....@gmail.com on 16 Jan 2011 at 7:43

Changed state: Fixed

GoogleCodeExporter commented 8 years ago

Original comment by fschm...@gmail.com on 25 Aug 2011 at 7:51

Changed state: Deployed

modmonkey / gtalksms

GTalkSMS 1.7 goes offline and stays so #44