PPP now connecting but com.android.phone crashes soon after

[Dave McLaughlin]

I finally got PPP dial up to work after many hours chasing down policies etc. The whole thing will be documented shortly after it all works on my blog and I will post the link here when it is done.

Now when it connects, I get a popup saying that the process com.android.phone has stopped.

The logcat shows the following:

D/TelephonyProvider( 2749): subIdString = 1 subId = 1
W/AppOps  (  418): Bad call: specified package android under uid 1001 but it is really 1000
D/TelephonyProvider( 2749): subIdString = 1 subId = 1
D/ConnectivityService(  418): setProvNotificationVisible: E visible=false networkType=0 action=com.android.internal.telephony.PROVISION0
D/ConnectivityService(  418): setProvNotificationVisibleIntent: E visible=false networkType=0 extraInfo=null
E/AndroidRuntime( 2749): FATAL EXCEPTION: DcHandlerThread
E/AndroidRuntime( 2749): Process: com.android.phone, PID: 2749
E/AndroidRuntime( 2749): java.lang.SecurityException: Package android does not belong to 1001
E/AndroidRuntime( 2749): at android.os.Parcel.readException(Parcel.java:1546)
E/AndroidRuntime( 2749): at android.os.Parcel.readException(Parcel.java:1499)
E/AndroidRuntime( 2749): at android.net.IConnectivityManager$Stub$Proxy.registerNetworkAgent(IConnectivityManager.java:2030)
E/AndroidRuntime( 2749): at android.net.ConnectivityManager.registerNetworkAgent(ConnectivityManager.java:2001)
E/AndroidRuntime( 2749): at android.net.NetworkAgent.<init>(NetworkAgent.java:145)
E/AndroidRuntime( 2749): at com.android.internal.telephony.dataconnection.DataConnection$DcNetworkAgent.<init>(DataConnection.java:1958)
E/AndroidRuntime( 2749): at com.android.internal.telephony.dataconnection.DataConnection$DcActiveState.enter(DataConnection.java:1735)
E/AndroidRuntime( 2749): at com.android.internal.util.StateMachine$SmHandler.invokeEnterMethods(StateMachine.java:1008)
E/AndroidRuntime( 2749): at com.android.internal.util.StateMachine$SmHandler.performTransitions(StateMachine.java:854)
E/AndroidRuntime( 2749): at com.android.internal.util.StateMachine$SmHandler.handleMessage(StateMachine.java:800)
E/AndroidRuntime( 2749): at android.os.Handler.dispatchMessage(Handler.java:102)
E/AndroidRuntime( 2749): at android.os.Looper.loop(Looper.java:135)
E/AndroidRuntime( 2749): at android.os.HandlerThread.run(HandlerThread.java:61)
W/ActivityManager(  418): Process com.android.phone has crashed too many times: killing!
I/OpenGLRenderer(  418): Initialized EGL, version 1.4
E/[EGL-ERROR](  418): EGLBoolean __egl_platform_create_surface_window(egl_surface*, mali_base_ctx_handle):933: =========> usage 0x900
I/VacuumService( 1388): Vacuum at: now=1451635473933 tag=VacuumService
I/Process ( 2749): Sending signal. PID: 2749 SIG: 9
W/InputMethodManagerService(  418): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@b6b9051 attribute=null, token = android.os.BinderProxy@2352780c
[  282.212000] binder: release 2749:2770 transaction 88537 in, still active
[  282.216000] binder: send failed reply for transaction 88537 to 1388:1659
I/ServiceManager(  131): service 'isub' died
I/ServiceManager(  131): service 'simphonebook' died
I/ServiceManager(  131): service 'iphonesubinfo' died
I/ServiceManager(  131): service 'isms' died
I/ServiceManager(  131): service 'phone' died
I/ServiceManager(  131): service 'sip' died
D/WifiService(  418): Client connection lost with reason: 4
I/ActivityManager(  418): Process com.android.phone (pid 2749) has died
W/ActivityManager(  418): Scheduling restart of crashed service com.android.phone/.TelephonyDebugService in 0ms
I/ActivityManager(  418): Start proc 2824:com.android.phone/1001 for restart com.android.phone
D/pppd    ( 2805): rcvd [LCP TermReq id=0xf]
I/pppd    ( 2805): LCP terminated by peer
I/pppd    ( 2805): Connect time 0.4 minutes.
I/pppd    ( 2805): Sent 0 bytes, received 0 bytes.
D/pppd    ( 2805): sent [LCP TermAck id=0xf]
I/pppd    ( 2805): Modem hangup
I/pppd    ( 2805): Connection terminated.
D/TelephonyProvider( 2824): dbh.onOpen: ok, queried table=siminfo
D/TelephonyProvider( 2824): dbh.onOpen: ok, queried table=carriers
D/GpsLocationProvider(  418): received SIM realted action:
V/KeyguardUpdateMonitor(  847): action android.intent.action.SIM_STATE_CHANGED state: NOT_READY slotId: 0 subid: -2
E/DcSwitchStateMachine-0( 2824): DctController is not ready
E/ConnectivityService(  418): Failed to find Messenger in unregisterNetworkFactory
D/ConnectivityService(  418): Got NetworkFactory Messenger for Telephony
D/GpsLocationProvider(  418): SIM MCC/MNC is still not available
D/KeyguardUpdateMonitor(  847): handleSimStateChange(subId=-2, slotId=0, state=UNKNOWN)
W/KeyguardUpdateMonitor(  847): invalid subId in handleSimStateChange()
I/art     (  418): Explicit concurrent mark sweep GC freed 15485(1421KB) AllocSpace objects, 15(240KB) LOS objects, 33% free, 9MB/14MB, paused 2.018ms total 59.731ms
D/BluetoothManagerService(  418): Message: 20
D/BluetoothManagerService(  418): Added callback: android.bluetooth.IBluetoothManagerCallback$Stub$Proxy@3ff4fdf0:true
D/BluetoothManagerService(  418): Message: 30
D/BluetoothManagerService(  418): Trying to bind to profile: 1, while Bluetooth was disabled
I/Telephony( 2824): TtyManager: updateUiTtyMode -1 -> 0
D/TelephonyDebugService( 2824): TelephonyDebugService()
D/GpsLocationProvider(  418): received SIM realted action:
V/KeyguardUpdateMonitor(  847): action android.intent.action.SIM_STATE_CHANGED state: ABSENT slotId: 0 subid: -2
D/GpsLocationProvider(  418): SIM MCC/MNC is still not available
D/KeyguardUpdateMonitor(  847): handleSimStateChange(subId=-2, slotId=0, state=ABSENT)
W/KeyguardUpdateMonitor(  847): invalid subId in handleSimStateChange()
D/WifiService(  418): New client listening to asynchronous messages
I/Telephony( 2824): PstnIncomingCallNotifier: Registering: Handler (com.android.internal.telephony.gsm.GSMPhone) {1fe03d48}

Searching on the various errors throws up no solutions.

The only thing I can see is that this might be related to an SMS message incoming but that worked before I got PPP to work.

[Dave McLaughlin]

I have finally tracked this down and fixed it so that it can work but the issue that causes this is still in the code.

The fault is caused when NetworkMonitor handles the CAPTIVE_PORTAL_SERVER using the property ro.net.captive_server in setprop.

    mServer = Settings.Global.getString(mContext.getContentResolver(),
            Settings.Global.CAPTIVE_PORTAL_SERVER);
    if (mServer == null) {
        mServer = SystemProperties.get("ro.net.captive_server");
        if (mServer == null || mServer.length() == 0) {
            mServer = DEFAULT_SERVER;
        } else {
            Settings.Global.putString(mContext.getContentResolver(),
                    Settings.Global.CAPTIVE_PORTAL_SERVER, mServer);
        }
    }

By commenting out the ro.net.captive_portal in the setprop file for the platform build, the connection now uses the default server for connection checking.

The fault lies in the line where Settings.Global.putString is called. This causes an exception. Why? I do not yet know.