[Galaxy S I9000 Android Development] caosorio:
Losing connectivity to voice and data network

Hi

I'm having an issue after updating from Nigthly 38 to more recent versions. The phone randomly loses connectivity to the voice and data network (HSDPA, not WiFi) and it doesn't reconnect.

I've tried activating airplane mode it doesn't do anything. And it can't deactivate it.

If I kill rild sometimes it reconnects by itself but not always. Usually I have to restart the phone to be able to reconnect.

I don't have any custom kernels installed. Tried different versions after 38 (39, RC1, 47, 49) and all have the same problem. Also wiping cache and dalvik doesn't solve the problem.

I'm seeing in the radio log that rild gets disconnected from the radio:

07-06 19:18:34.565 D/RILJ ( 1066): [0419]< REQUEST_GET_NEIGHBORING_CELL_IDS error: com.android.internal.telephony.CommandException: REQUEST_NOT_SU
PPORTED
07-06 19:18:41.866 E/RIL ( 112): [EVT]:Req(0), RX(1)
07-06 19:18:41.866 E/RIL ( 112): RIL_onMultiClientUnsolicitedResponse:
07-06 19:18:41.866 E/RIL ( 112): unsupported multiclient unsolicited response code 1009
07-06 19:18:44.463 E/RIL ( 112): [EVT]:Req(0), RX(1)
07-06 19:18:44.463 E/RIL ( 112): RIL_onMultiClientUnsolicitedResponse:
07-06 19:18:44.463 E/RIL ( 112): unsupported multiclient unsolicited response code 1009
07-06 19:18:46.393 E/RILJ ( 1066): Hit EOS reading message length
07-06 19:18:46.393 I/RILJ ( 1066): Disconnected from 'rild' socket
07-06 19:18:46.428 D/RILB ( 1066): Notifying: radio not available
07-06 19:18:46.428 D/RILB ( 1066): Notifying: radio off or not available
07-06 19:18:46.455 I/RILJ ( 1066): Connected to 'rild' socket
07-06 19:18:46.463 D/GSM ( 1066): Poll ServiceState done: oldSS=[0 home Bell Bell 302610 UMTS CSS not supported -1 -1RoamInd: -1DefRoamInd: -1E
mergOnly: false] newSS=[1 home null null null Unknown CSS not supported -1 -1RoamInd: -1DefRoamInd: -1EmergOnly: false] oldGprs=0 newGprs=0 oldType=
UMTS newType=UMTS
07-06 19:18:46.537 D/RILJ ( 1066): [0000]> GET_CURRENT_CALLS
07-06 19:18:46.588 D/GSM ( 1066): [GsmDataConnection-1] DcInactiveState: msg.what=EVENT_RESET, ignore we're already reset
07-06 19:18:46.588 D/GSM ( 1066): [GsmDataConnection-1] NotifyDisconnectCompleted
07-06 19:18:46.588 D/GSM ( 1066): [GsmDataConnection-1] clearSettings
07-06 19:18:46.588 D/GSM ( 1066): [DataConnection] Stop poll NetStat
07-06 19:18:46.643 D/GSM ( 1066): [IccCard] Broadcasting intent ACTION_SIM_STATE_CHANGED NOT_READY reason null
07-06 19:18:46.776 W/RILC ( 112): EOS. Closing command socket.
07-06 19:18:47.284 D/RILJ ( 1066): [0001]> REQUEST_GET_NEIGHBORING_CELL_IDS
07-06 19:18:47.303 I/RILJ ( 1066): 'rild' socket closed
07-06 19:18:47.303 I/RILJ ( 1066): java.io.IOException: Connection reset by peer
07-06 19:18:47.303 I/RILJ ( 1066): at android.net.LocalSocketImpl.readba_native(Native Method)
07-06 19:18:47.303 I/RILJ ( 1066): at android.net.LocalSocketImpl.access$400(LocalSocketImpl.java:29)
07-06 19:18:47.303 I/RILJ ( 1066): at android.net.LocalSocketImpl$SocketInputStream.read(LocalSocketImpl.java:92)
07-06 19:18:47.303 I/RILJ ( 1066): at com.android.internal.telephony.RIL.readRilMessage(RIL.java:468)
07-06 19:18:47.303 I/RILJ ( 1066): at com.android.internal.telephony.RIL.access$200(RIL.java:207)
07-06 19:18:47.303 I/RILJ ( 1066): at com.android.internal.telephony.RIL$RILReceiver.run(RIL.java:567)
07-06 19:18:47.303 I/RILJ ( 1066): at java.lang.Thread.run(Thread.java:1019)
07-06 19:18:47.303 I/RILJ ( 1066): Disconnected from 'rild' socket
07-06 19:18:47.303 D/RILJ ( 1066): [0000]< GET_CURRENT_CALLS error: com.android.internal.telephony.CommandException: RADIO_NOT_AVAILABLE
07-06 19:18:47.303 D/RILJ ( 1066): [0001]< REQUEST_GET_NEIGHBORING_CELL_IDS error: com.android.internal.telephony.CommandException: RADIO_NOT_AVAI
LABLE
07-06 19:18:47.338 E/RILJ ( 1066): IOException
07-06 19:18:47.338 E/RILJ ( 1066): java.io.IOException: Broken pipe
07-06 19:18:47.338 E/RILJ ( 1066): at android.net.LocalSocketImpl.writeba_native(Native Method)
07-06 19:18:47.338 E/RILJ ( 1066): at android.net.LocalSocketImpl.access$600(LocalSocketImpl.java:29)
07-06 19:18:47.338 E/RILJ ( 1066): at android.net.LocalSocketImpl$SocketOutputStream.write(LocalSocketImpl.java:126)
07-06 19:18:47.338 E/RILJ ( 1066): at android.net.LocalSocketImpl$SocketOutputStream.write(LocalSocketImpl.java:113)
07-06 19:18:47.338 E/RILJ ( 1066): at com.android.internal.telephony.RIL$RILSender.handleMessage(RIL.java:355)
07-06 19:18:47.338 E/RILJ ( 1066): at android.os.Handler.dispatchMessage(Handler.java:99)
07-06 19:18:47.338 E/RILJ ( 1066): at android.os.Looper.loop(Looper.java:130)
07-06 19:18:47.338 E/RILJ ( 1066): at android.os.HandlerThread.run(HandlerThread.java:60)
07-06 19:18:51.373 I/RILJ ( 1066): Couldn't find 'rild' socket; retrying after timeout
07-06 19:18:52.112 E/RIL ( 112): [EVT]:Req(0), RX(1)
07-06 19:18:52.112 E/RIL ( 112): RIL_onMultiClientUnsolicitedResponse:
07-06 19:18:52.112 E/RIL ( 112): unsupported multiclient unsolicited response code 1009
07-06 19:18:55.373 I/RILJ ( 1066): Couldn't find 'rild' socket; retrying after timeout
07-06 19:18:57.233 E/RIL ( 112): [EVT]:Req(0), RX(1)
07-06 19:18:57.233 E/RIL ( 112): RIL_onMultiClientUnsolicitedResponse:
07-06 19:18:57.233 E/RIL ( 112): unsupported multiclient unsolicited response code 1009
07-06 19:18:59.373 I/RILJ ( 1066): Couldn't find 'rild' socket; retrying after timeout

There doesn't seem to be anything interesting in main log:

07-06 19:18:35.862 D/WifiService( 202): releaseWifiLockLocked: WifiLock{NetworkLocationLocator type=2 binder=android.os.BinderProxy@409d3e38}
07-06 19:18:36.776 D/dalvikvm( 760): GC_EXTERNAL_ALLOC freed 156K, 36% free 9137K/14151K, external 2030K/2102K, paused 46ms
07-06 19:18:39.799 D/dalvikvm( 760): GC_EXTERNAL_ALLOC freed 697K, 28% free 10262K/14151K, external 2131K/2138K, paused 55ms
07-06 19:18:40.209 D/dalvikvm( 760): GC_CONCURRENT freed 797K, 25% free 10667K/14151K, external 1552K/1863K, paused 5ms+5ms
07-06 19:18:40.838 D/dalvikvm( 760): GC_CONCURRENT freed 1101K, 24% free 11670K/15239K, external 1449K/1848K, paused 3ms+5ms
07-06 19:18:41.116 D/TrafficAppWidgetUpdateService( 760): Got widget id to update: 42
07-06 19:18:41.116 I/TrafficAppWidgetUpdateService( 760): App widget going to sleep: 42 (Home)
07-06 19:18:41.127 D/TrafficAppWidgetUpdateService( 760): No longer requesting location updates.
07-06 19:18:41.127 D/TrafficAppWidgetUpdateService( 760): Scheduled update for 42 in 29 s.
07-06 19:18:41.815 D/dalvikvm( 760): GC_CONCURRENT freed 1707K, 26% free 12024K/16199K, external 1549K/1848K, paused 3ms+13ms
07-06 19:18:41.826 D/TrafficAppWidgetUpdateService( 760): Got widget id to update: 45
07-06 19:18:41.830 I/TrafficAppWidgetUpdateService( 760): App widget going to sleep: 45 (Work)
07-06 19:18:41.842 D/TrafficAppWidgetUpdateService( 760): No longer requesting location updates.
07-06 19:18:41.850 D/TrafficAppWidgetUpdateService( 760): Scheduled update for 45 in 29 s.
07-06 19:18:42.580 D/dalvikvm( 760): GC_CONCURRENT freed 1597K, 25% free 12514K/16583K, external 1456K/1847K, paused 3ms+9ms
07-06 19:18:43.600 D/dalvikvm( 760): GC_CONCURRENT freed 1946K, 27% free 12603K/17031K, external 1755K/1847K, paused 4ms+17ms
07-06 19:18:44.600 D/dalvikvm( 760): GC_CONCURRENT freed 2031K, 27% free 12630K/17159K, external 1712K/1847K, paused 4ms+13ms
07-06 19:18:44.686 D/dalvikvm( 760): GC_FOR_MALLOC freed 556K, 30% free 12074K/17159K, external 1688K/1847K, paused 84ms
07-06 19:18:44.686 I/dalvikvm-heap( 760): Grow heap (frag case) to 15.998MB for 155828-byte allocation
07-06 19:18:44.760 D/dalvikvm( 760): GC_EXTERNAL_ALLOC freed 128K, 31% free 12098K/17351K, external 1688K/1847K, paused 63ms
07-06 19:18:44.842 D/dalvikvm( 760): GC_FOR_MALLOC freed 17K, 30% free 12209K/17351K, external 1930K/2441K, paused 41ms
07-06 19:18:45.518 D/dalvikvm( 760): GC_CONCURRENT freed 1564K, 27% free 12693K/17351K, external 2092K/2441K, paused 8ms+8ms
07-06 19:18:46.373 D/dalvikvm( 760): GC_CONCURRENT freed 1509K, 24% free 13219K/17351K, external 2124K/2441K, paused 33ms+44ms
07-06 19:18:46.494 I/TelephonyRegistry( 202): notifyServiceState: 1 home null null null Unknown CSS not supported -1 -1RoamInd: -1DefRoamInd: -1Eme
rgOnly: false
07-06 19:18:46.588 I/TelephonyRegistry( 202): notifyDataConnection: state=0 isDataConnectivityPossible=false reason=radioTurnedOff interfaceName=nul
l networkType=0
07-06 19:18:47.284 D/dalvikvm( 1066): GC_CONCURRENT freed 410K, 48% free 3277K/6215K, external 0K/0K, paused 131ms+58ms
07-06 19:18:47.717 D/dalvikvm( 760): GC_CONCURRENT freed 1594K, 23% free 13673K/17735K, external 2092K/2441K, paused 3ms+9ms
07-06 19:18:47.862 D/vending ( 896): [17] 1.run(): Clearing cache in response to android.intent.action.SIM_STATE_CHANGED
07-06 19:18:48.209 D/dalvikvm( 760): GC_FOR_MALLOC freed 697K, 22% free 14373K/18247K, external 2092K/2441K, paused 214ms
07-06 19:18:48.592 I/com.keramidas.MediaSync.sync.SyncService( 968): Worker thread woke up !
07-06 19:18:48.690 D/dalvikvm( 760): GC_EXTERNAL_ALLOC freed 460K, 20% free 14615K/18247K, external 2302K/2348K, paused 71ms
07-06 19:18:48.713 I/ActivityManager( 202): Process com.google.android.youtube (pid 4975) has died.

I restored a backup of #38 and couldn't repro the problem.

To exclude problems with my SIM card, used a different one, from a different provider and the problem still happens.

Has anybody seen this?

Update: Wiped all data and restored apps with TB (but not system settings) and problem seems to be fixed.