enabling modem support on a platform with new RIL code

[Kim Schulz]

Hi 

I am working on a RIL driver for a modem which is heavily based on the reference-ril. I can load it onto my platform and see that all of the AT commands are send and responded to. 

Everything goes well until the AT+CMNI have been responded to with OK. After this around 5 seconds passes until PHONE suddenly seems to fail with RADIO_NOT_AVAILABLE.

Can anyone tell me why this is and what I need to enable in order to get ie RILJ to not say "Not starting RILReceiver: wifi-only"?

This is what the radio log shows:

01-13 19:09:00.235 I/RIL     ( 2417): Opening tty device /dev/ttySAC3

01-13 19:09:00.235 E/RILC    ( 2417): RIL_register: RIL version 7

01-13 19:09:00.240 D/RIL     ( 2417): setRadioState(0)

01-13 19:09:00.240 D/RIL     ( 2417): DEBUG: sending out state changed

01-13 19:09:00.240 D/AT      ( 2417): AT> ATE0Q0V1

01-13 19:09:00.275 D/AT      ( 2417): AT< ATE0Q0V1

01-13 19:09:00.275 D/AT      ( 2417): AT< OK

01-13 19:09:00.525 D/RIL     ( 2417): query_ctec. current: 1076190656, preferred: 1076190660

01-13 19:09:00.525 D/AT      ( 2417): AT> AT+CTEC?

01-13 19:09:00.565 D/AT      ( 2417): AT< +CTEC: 6

01-13 19:09:00.565 D/AT      ( 2417): AT< OK

01-13 19:09:00.565 D/RIL     ( 2417): Response: +CTEC: 6

01-13 19:09:00.565 D/RIL     ( 2417): line remaining after int: (null)

01-13 19:09:00.565 D/RIL     ( 2417): return is 1

01-13 19:09:00.565 D/AT      ( 2417): AT> AT+WNAM

01-13 19:09:00.600 D/AT      ( 2417): AT< ERROR

01-13 19:09:00.600 I/RIL     ( 2417): Found GSM Modem

01-13 19:09:00.600 D/AT      ( 2417): AT> ATE0Q0V1

01-13 19:09:00.635 D/AT      ( 2417): AT< ATE0Q0V1

01-13 19:09:00.635 D/AT      ( 2417): AT< OK

01-13 19:09:00.635 D/AT      ( 2417): AT> ATS0=0

01-13 19:09:00.670 D/AT      ( 2417): AT< OK

01-13 19:09:00.670 D/AT      ( 2417): AT> AT+CMEE=1

01-13 19:09:00.705 D/AT      ( 2417): AT< OK

01-13 19:09:00.705 D/AT      ( 2417): AT> AT+CREG=2

01-13 19:09:00.750 D/AT      ( 2417): AT< +CREG: 1,2,2

01-13 19:09:00.750 D/AT      ( 2417): AT< OK

01-13 19:09:00.750 D/AT      ( 2417): AT> AT+CGREG=1

01-13 19:09:00.780 D/AT      ( 2417): AT< OK

01-13 19:09:00.780 D/AT      ( 2417): AT> AT+CCWA=1

01-13 19:09:00.815 D/AT      ( 2417): AT< OK

01-13 19:09:00.815 D/AT      ( 2417): AT> AT+CMOD=0

01-13 19:09:00.845 D/AT      ( 2417): AT< OK

01-13 19:09:00.845 D/AT      ( 2417): AT> AT+CMUT=0

01-13 19:09:00.875 D/AT      ( 2417): AT< OK

01-13 19:09:00.875 D/AT      ( 2417): AT> AT+CSSN=0,1

01-13 19:09:00.910 D/AT      ( 2417): AT< OK

01-13 19:09:00.910 D/AT      ( 2417): AT> AT+COLP=0

01-13 19:09:00.940 D/AT      ( 2417): AT< OK

01-13 19:09:00.940 D/AT      ( 2417): AT> AT+CSCS="HEX"

01-13 19:09:00.975 D/AT      ( 2417): AT< OK

01-13 19:09:00.975 D/AT      ( 2417): AT> AT+CUSD=1

01-13 19:09:01.010 D/AT      ( 2417): AT< OK

01-13 19:09:01.010 D/AT      ( 2417): AT> AT+CGEREP=1,0

01-13 19:09:01.045 D/AT      ( 2417): AT< OK

01-13 19:09:01.045 D/AT      ( 2417): AT> AT+CMGF=0

01-13 19:09:01.075 D/AT      ( 2417): AT< OK

01-13 19:09:01.075 D/AT      ( 2417): AT> AT+CFUN?

01-13 19:09:01.110 D/AT      ( 2417): AT< +CFUN: 1

01-13 19:09:01.110 D/AT      ( 2417): AT< OK

01-13 19:09:01.110 D/RIL     ( 2417): setRadioState(10)

01-13 19:09:01.110 D/RIL     ( 2417): DEBUG: sending out state changed

01-13 19:09:01.110 D/RIL     ( 2417): DEBUG: onRadioPowerOn() called

01-13 19:09:01.110 D/RIL     ( 2417): DEBUG: sState is RADIO_STATE_SIM_NOT_READY

01-13 19:09:01.110 D/RIL     ( 2417): DEBUG: sim status is 2

01-13 19:09:01.110 I/RIL     ( 2417): SIM_READY

01-13 19:09:01.110 D/AT      ( 2417): AT> AT+CSMS=1

01-13 19:09:01.150 D/AT      ( 2417): AT< +CSMS: 1

01-13 19:09:01.150 D/AT      ( 2417): AT< OK

01-13 19:09:01.150 D/AT      ( 2417): AT> AT+CNMI=1,2,2,1,1

01-13 19:09:01.190 D/AT      ( 2417): AT< OK

01-13 19:09:06.615 I/PHONE   ( 3005): Network Mode set to 0

01-13 19:09:06.615 I/PHONE   ( 3005): lteOnCdma is 0 use SUBSCRIPTION_FROM_NV

01-13 19:09:06.615 I/PHONE   ( 3005): Cdma Subscription set to 1

01-13 19:09:06.625 D/RILJ    ( 3005): RIL(context, preferredNetworkType=0 cdmaSubscription=1)

01-13 19:09:06.635 D/RILJ    ( 3005): Not starting RILReceiver: wifi-only

01-13 19:09:06.635 D/RIL_UiccController( 3005): Creating UiccController

01-13 19:09:06.635 I/PHONE   ( 3005): Creating GSMPhone

01-13 19:09:06.645 D/PHONE   ( 3005): mDoesRilSendMultipleCallRing=true

01-13 19:09:06.645 D/PHONE   ( 3005): mCallRingDelay=3000

01-13 19:09:06.680 D/RILJ    ( 3005): setPhoneType=1 old value=0

01-13 19:09:06.725 D/SMS     ( 3005): SMSDispatcher: ctor mSmsCapable=true format=3gpp mSmsReceiveDisabled=false mSmsSendDisabled=false

01-13 19:09:06.730 D/GSM     ( 3005): [GsmDCT] DCT.constructor

01-13 19:09:06.745 D/GSM     ( 3005): [GsmDCT] GsmDCT.constructor

01-13 19:09:06.770 D/RILB    ( 3005): registerForRilConnected h=Handler (com.android.internal.telephony.PhoneProxy) {411346a8} w=4

01-13 19:09:06.770 D/RIL_IccCardProxy( 3005): Creating

01-13 19:09:06.800 D/RIL_IccCardProxy( 3005): Broadcasting intent ACTION_SIM_STATE_CHANGED NOT_READY reason null

01-13 19:09:06.810 D/RIL_IccCardProxy( 3005): Setting radio tech UMTS

01-13 19:09:06.825 D/RIL_IccCardProxy( 3005): updateQuietMode: 3GPP subscription -> newQuietMode=false

01-13 19:09:06.825 D/RIL_IccCardProxy( 3005): updateQuietMode: QuietMode is false (app_type=1 isLteOnCdmaMode=false cdmaSource=-1)

01-13 19:09:07.265 D/RILJ    ( 3005): [0000]> GET_CURRENT_CALLS

01-13 19:09:07.265 D/RILJ    ( 3005): [0000]< GET_CURRENT_CALLS error: com.android.internal.telephony.CommandException: RADIO_NOT_AVAILABLE

01-13 19:09:07.265 D/GSM     ( 3005): [GsmSST] Poll ServiceState done:  oldSS=[1 home null null null  Unknown CSS not supported 0 0 RoamInd=0 DefRoamInd=0 EmergOnly=false] newSS=[1 home null null null  Unknown CSS not supported -1 -1 RoamInd=-1 DefRoamInd=-1 EmergOnly=false] oldGprs=1 newData=1 oldMaxDataCalls=1 mNewMaxDataCalls=1 oldReasonDataDenied=-1 mNewReasonDataDenied=-1 oldType=Unknown newType=Unknown

01-13 19:09:07.265 D/GSM     ( 3005): [GsmSST] updateSpnDisplay: radio is on but out of service, set plmn='No service.'

01-13 19:09:07.265 D/GSM     ( 3005): [GsmSST] updateSpnDisplay: changed sending intent rule=0 showPlmn='true' plmn='No service.' showSpn='false' spn=''

01-13 19:09:07.270 D/GSM     ( 3005): [GsmSST] operatorNumeric is null

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] handleMessage msg={ what=270369 when=-591ms obj=android.os.AsyncResult@41143748 }

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] handleMessage msg={ what=270342 when=-572ms obj=android.os.AsyncResult@41144428 }

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] onRadioOffOrNotAvailable: is off and clean up all connections

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] cleanUpAllConnections: tearDown=false reason=radioTurnedOff

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] stopNetStatPoll

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] handleMessage msg={ what=270345 when=-573ms obj=android.os.AsyncResult@41144700 }

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] onDataConnectionDetached: stop polling and notify detached

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] stopNetStatPoll

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] notifyDataConnection: reason=dataDetached

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] handleMessage msg={ what=270348 when=-573ms obj=android.os.AsyncResult@41144858 }

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] onRoamingOff

01-13 19:09:07.320 D/GSM     ( 3005): [GsmDCT] notifyDataConnection: reason=roamingOff

[Gianmaria Iaculo]

Hi Kim,

did you succed with it? I have same problem 

Not starting RILReceiver: wifi-only

Regards,

Gianmaria

[Richard Osterloh]

I'm also having this problem. Any update?