Hi, Looks like the AT channel is blocked because of some blocking AT command. Thats the reason there is a timeout in couple of occasions and also lot of requests pending in queue. Looks like you are using only one AT channel to send these commands to the modem, which will block the whole communication when some blocking AT commands like CSQ etc is issued. By the time you make the phone call, the AT channel is already not responding.
Can share the whole ril log and also capture the app side logs ? Also try issuing the dial when there is no such blocking in the channel. BR, Rajesh On Mon, Feb 14, 2011 at 9:44 AM, animesh arora <animesharora...@gmail.com>wrote: > Hi Nimit > > am facing the problem while maiking GSM call. > I followed the link which i got from the below link. > > https://groups.google.com/group/android-porting/browse_thread/thread/21d5d270a793e876?hl=ja<https://hcltmail-chn.hcl.in/OWA/redir.aspx?C=082ec09ba3be44bf87589ffce67d66cd&URL=https%3a%2f%2fgroups.google.com%2fgroup%2fandroid-porting%2fbrowse_thread%2fthread%2f21d5d270a793e876%3fhl%3dja> > > > And getting the below message after running logcat -b radio on the device > with cupcake version. > > is there any problem which i am getting in my log > > E/RILC ( 1750): 1:Failed to get socket 'rild' > > because firstly rild was connected only later it is showing failed, > > > what is the problem for making call? > > # logcat -b radio & > # I/RIL ( 1621): Opening tty device /dev/ttyUSB0 > I/RILC ( 1621): libril: new connection > I/RILC ( 1621): RIL Daemon version: android reference-ril 1.0 > I/RILJ ( 1676): Connected to 'rild' socket > D/RILJ ( 1676): [UNSL]< UNSOL_RESPONSE_RADIO_STATE_CHANGED > RADIO_UNAVAILABLE > W/GSM ( 1676): Can't open /system/etc/voicemail-conf.xml > W/GSM ( 1676): Can't open /system/etc/spn-conf.xml > D/GSM ( 1676): [DSAC DEB] registerForPsRestrictedEnabled > D/GSM ( 1676): [DSAC DEB] registerForPsRestrictedDisabled > D/RILJ ( 1676): [0000]> GET_CURRENT_CALLS > D/RIL ( 1621): onRequest: GET_CURRENT_CALLS > D/RILJ ( 1676): [0000]< GET_CURRENT_CALLS error: > com.android.internal.telephony.gsm.CommandException: RADIO_NOT_AVAILABLE > D/GSM ( 1676): Poll ServiceState done: oldSS=[1 home null null null ] > newSS=[1 home null null null ] oldGprs=1 newGprs=1 oldType=unknown > newType=unknown > D/GSM ( 1676): [DataConnectionTracker] Radio is off and clean up all > connection > D/GSM ( 1676): [DataConnectionTracker] Clean up connection due to > radioTurnedOff > D/GSM ( 1676): [DataConnection] Stop poll NetStat > D/GSM ( 1676): [DataConnectionTracker] setState: IDLE > D/GSM ( 1676): [DataConnection] Stop poll NetStat > D/GSM ( 1676): [DataConnectionTracker] ***trySetupData due to > roamingOff > D/GSM ( 1676): [DSAC DEB] trySetupData with mIsPsRestricted=false > D/GSM ( 1676): [DataConnectionTracker] trySetupData: Not ready for > data: dataState=IDLE gprsState=1 sim=false UMTS=false phoneState=IDLE > dataEnabled=true roaming=false dataOnRoamingEnable=false ps restricted=false > D/GSM ( 1676): [GsmSimCard] Broadcasting intent > SIM_STATE_CHANGED_ACTION NOT_READY reason null > D/RILJ ( 1676): [0001]> RADIO_POWER > D/GSM ( 1676): Notifying: radio available > D/RILJ ( 1676): [0002]> SCREEN_STATE: true > D/AT ( 1621): AT> ATE0Q0V1 > D/AT ( 1621): AT< ATE0Q0V1 > D/AT ( 1621): AT< OK > D/GSM ( 1676): Poll ServiceState done: oldSS=[1 home null null null ] > newSS=[3 home null null null ] oldGprs=1 newGprs=1 oldType=unknown > newType=unknown > D/RILJ ( 1676): [UNSL]< UNSOL_RESPONSE_RADIO_STATE_CHANGED RADIO_OFF > D/AT ( 1621): AT> ATE0Q0V1 > D/AT ( 1621): AT< 0 > D/AT ( 1621): AT< 4 > D/RILJ ( 1676): [0003]> BASEBAND_VERSION > D/RILJ ( 1676): [0004]> GET_IMEI > D/RILJ ( 1676): [0005]> GET_IMEISV > I/RIL ( 1750): Opening tty device /dev/ttyUSB0 > W/RILC ( 1750): RIL_onUnsolicitedResponse called before RIL_register > D/AT ( 1750): AT> ATE0Q0V1 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> ATS0=0 > E/RILC ( 1750): 1:Failed to get socket 'rild' > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CMEE=1 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CREG=2 > D/AT ( 1621): AT< OK > > D/AT ( 1621): AT> AT+CGREG=1 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CCWA=1 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CMOD=0 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CMUT=0 > D/AT ( 1621): AT< +CMUT: > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CSSN=0,1 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+COLP=0 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CSCS="HEX" > D/AT ( 1621): AT< ERROR > D/AT ( 1621): AT> AT+CUSD=1 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CGEREP=1,0 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CMGF=0 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CFUN? > D/AT ( 1621): AT< +CFUN: 1 > D/AT ( 1621): AT< OK > D/GSM ( 1676): Notifying: Radio On > D/RILJ ( 1676): [UNSL]< UNSOL_RESPONSE_RADIO_STATE_CHANGED SIM_NOT_READY > D/RILJ ( 1676): [0006]> OPERATOR > D/RILJ ( 1676): [0007]> GPRS_REGISTRATION_STATE > D/AT ( 1621): AT> AT+CPIN? > D/AT ( 1621): AT< +CPIN: READY > D/AT ( 1621): AT< OK > D/GSM ( 1676): Notifying: SIM ready > D/RILJ ( 1676): [UNSL]< UNSOL_RESPONSE_RADIO_STATE_CHANGED SIM_READY > D/AT ( 1621): AT> AT+CSMS=1 > D/RILJ ( 1676): [0008]> REGISTRATION_STATE > D/AT ( 1621): AT< +CSMS: 1,1,1 > D/AT ( 1621): AT< OK > D/AT ( 1621): AT> AT+CNMI=1,2,2,1,1 > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: RADIO_POWER > D/RILJ ( 1676): [0001]< RADIO_POWER > D/RIL ( 1621): onRequest: SCREEN_STATE > D/RILJ ( 1676): [0009]> QUERY_NETWORK_SELECTION_MODE > D/RILJ ( 1676): [0002]< SCREEN_STATE error: > com.android.internal.telephony.gsm.CommandException: REQUEST_NOT_SUPPORTED > D/RIL ( 1621): onRequest: BASEBAND_VERSION > D/RIL ( 1621): onRequest: GET_IMEI > D/AT ( 1621): AT> AT+CGSN > D/AT ( 1621): AT< 352679010163850 > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: GET_IMEISV > D/RIL ( 1621): onRequest: OPERATOR > D/AT ( 1621): AT> AT+COPS=3,0;+COPS?;+COPS=3,1;+COPS?;+COPS=3,2;+COPS? > D/RILJ ( 1676): [0003]< BASEBAND_VERSION error: > com.android.internal.telephony.gsm.CommandException: REQUEST_NOT_SUPPORTED > D/RILJ ( 1676): [0004]< GET_IMEI > D/RILJ ( 1676): [0010]> GET_CURRENT_CALLS > D/AT ( 1621): AT< +COPS: 0,0,"AirTel",0 > D/AT ( 1621): AT< +COPS: 0,1,"AirTel",0 > D/AT ( 1621): AT< +COPS: 0,2,"40440",0 > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: GPRS_REGISTRATION_STATE > D/AT ( 1621): AT> AT+CGREG? > D/AT ( 1621): AT< +CGREG: 1,1,1F54,1DE3 > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: REGISTRATION_STATE > D/RILJ ( 1676): [0005]< GET_IMEISV error: > com.android.internal.telephony.gsm.CommandException: REQUEST_NOT_SUPPORTED > D/RILJ ( 1676): [0011]> OPERATOR > D/AT ( 1621): AT> AT+CREG? > D/AT ( 1621): AT< +CREG: 2,1,1F54,1DE3 > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: QUERY_NETWORK_SELECTION_MODE > D/AT ( 1621): AT> AT+COPS? > D/RILJ ( 1676): [0006]< OPERATOR {AirTel, AirTel, 40440} > D/RILJ ( 1676): [0012]> GPRS_REGISTRATION_STATE > D/AT ( 1621): AT< +COPS: 0,2,"40440",0 > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: GET_CURRENT_CALLS > D/AT ( 1621): AT> AT+CLCC > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: OPERATOR > D/AT ( 1621): AT> AT+COPS=3,0;+COPS?;+COPS=3,1;+COPS?;+COPS=3,2;+COPS? > D/AT ( 1621): AT< +COPS: 0,0,"AirTel",0 > D/AT ( 1621): AT< +COPS: 0,1,"AirTel",0 > D/AT ( 1621): AT< +COPS: 0,2,"40440",0 > D/AT ( 1621): AT< OK > D/RILJ ( 1676): [0007]< GPRS_REGISTRATION_STATE {1, 8020, 7651} > D/RILJ ( 1676): [0008]< REGISTRATION_STATE {1, 8020, 7651} > D/RILJ ( 1676): [0013]> REGISTRATION_STATE > D/RIL ( 1621): onRequest: GPRS_REGISTRATION_STATE > D/AT ( 1621): AT> AT+CGREG? > D/AT ( 1621): AT< +CGREG: 1,1,1F54,1DE3 > D/AT ( 1621): AT< OK > D/RILJ ( 1676): [0014]> QUERY_NETWORK_SELECTION_MODE > D/RILJ ( 1676): [0009]< QUERY_NETWORK_SELECTION_MODE {0} > D/RIL ( 1621): onRequest: REGISTRATION_STATE > D/AT ( 1621): AT> AT+CREG? > D/AT ( 1621): AT< +CREG: 2,1,1F54,1DE3 > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: QUERY_NETWORK_SELECTION_MODE > D/AT ( 1621): AT> AT+COPS? > D/AT ( 1621): AT< +COPS: 0,2,"40440",0 > D/AT ( 1621): AT< OK > D/RILJ ( 1676): [0010]< GET_CURRENT_CALLS > D/RILJ ( 1676): [0011]< OPERATOR {AirTel, AirTel, 40440} > D/RILJ ( 1676): [0012]< GPRS_REGISTRATION_STATE {1, 8020, 7651} > D/RILJ ( 1676): [0015]> SET_NETWORK_SELECTION_AUTOMATIC > D/RILJ ( 1676): [0013]< REGISTRATION_STATE {1, 8020, 7651} > D/RIL ( 1621): onRequest: SET_NETWORK_SELECTION_AUTOMATIC > D/AT ( 1621): AT> AT+COPS=0 > D/RILJ ( 1676): [0014]< QUERY_NETWORK_SELECTION_MODE {0} > D/RILJ ( 1676): [0016]> OPERATOR > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: OPERATOR > D/AT ( 1621): AT> AT+COPS=3,0;+COPS?;+COPS=3,1;+COPS?;+COPS=3,2;+COPS? > D/AT ( 1621): AT< +COPS: 0,0,"AirTel",0 > D/AT ( 1621): AT< +COPS: 0,1,"AirTel",0 > D/AT ( 1621): AT< +COPS: 0,2,"40440",0 > D/AT ( 1621): AT< OK > D/RILJ ( 1676): [0017]> GPRS_REGISTRATION_STATE > D/RILJ ( 1676): [0016]< OPERATOR {AirTel, AirTel, 40440} > D/RIL ( 1621): onRequest: GPRS_REGISTRATION_STATE > D/AT ( 1621): AT> AT+CGREG? > D/AT ( 1621): AT< +CGREG: 1,1,1F54,1DE3 > D/AT ( 1621): AT< OK > D/RILJ ( 1676): [0018]> REGISTRATION_STATE > D/RILJ ( 1676): [0017]< GPRS_REGISTRATION_STATE {1, 8020, 7651} > D/RIL ( 1621): onRequest: REGISTRATION_STATE > D/AT ( 1621): AT> AT+CREG? > D/AT ( 1621): AT< +CREG: 2,1,1F54,1DE3 > D/AT ( 1621): AT< OK > D/RILJ ( 1676): [0019]> QUERY_NETWORK_SELECTION_MODE > D/RILJ ( 1676): [0018]< REGISTRATION_STATE {1, 8020, 7651} > D/RIL ( 1621): onRequest: QUERY_NETWORK_SELECTION_MODE > D/AT ( 1621): AT> AT+COPS? > D/AT ( 1621): AT< +COPS: 0,2,"40440",0 > D/AT ( 1621): AT< OK > D/GSM ( 1676): [GsmSimCard] Broadcasting intent > SIM_STATE_CHANGED_ACTION READY reason null > D/RILJ ( 1676): [0019]< QUERY_NETWORK_SELECTION_MODE {0} > V/GSM ( 1676): SIMRecords:fetchSimRecords 0 > D/RILJ ( 1676): [0020]> getIMSI:RIL_REQUEST_GET_IMSI 11 GET_IMSI > D/RIL ( 1621): onRequest: GET_IMSI > D/AT ( 1621): AT> AT+CIMI > D/AT ( 1621): AT< 5600300002083733 > D/AT ( 1621): AT< OK > D/RILJ ( 1676): [0020]< GET_IMSI > D/RILJ ( 1676): [0021]> simIO: SIM_IO 0xc0 0x2fe2 0,0,15 > D/RIL ( 1621): onRequest: SIM_IO > D/AT ( 1621): AT> AT+CRSM=192,12258,0,0,15 > D/RILJ ( 1676): [0022]> simIO: SIM_IO 0xc0 0x6f40 0,0,15 > D/RILJ ( 1676): [0023]> simIO: SIM_IO 0xc0 0x6fc9 0,0,15 > D/AT ( 1621): AT< +CRSM: 144,0,"0000000A2FE2040005FF5501020000" > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: SIM_IO > D/AT ( 1621): AT> AT+CRSM=192,28480,0,0,15 > D/RILJ ( 1676): [0021]< SIM_IO SimIoResponse sw1:0x90 sw2:0x0 > D/RILJ ( 1676): [0024]> simIO: SIM_IO 0xc0 0x6fad 0,0,15 > D/AT ( 1621): AT< +CRSM: 144,0,"000000576F40040011FF550102011D" > D/AT ( 1621): AT< OK > D/RIL ( 1621): onRequest: SIM_IO > D/AT ( 1621): AT> AT+CRSM=192,28617,0,0,15 > D/RILJ ( 1676): [0022]< SIM_IO SimIoResponse sw1:0x90 sw2:0x0 > D/AT ( 1621): AT< +CME ERROR: 22 > D/RIL ( 1621): onRequest: SIM_IO > D/AT ( 1621): AT> AT+CRSM=192,28589,0,0,15 > D/RILJ ( 1676): [0023]< SIM_IO error: > com.android.internal.telephony.gsm.CommandException: GENERIC_FAILURE > D/RILJ ( 1676): [0025]> simIO: SIM_IO 0xc0 0x6fca 0,0,15 > D/RILJ ( 1676): [0026]> simIO: SIM_IO 0xc0 0x6f11 0,0,15 > D/AT ( 1621): AT< +CRSM: 144,0,"000000036FAD040005FF5501020000" > D/AT ( 1621): AT< OK > D/RILJ ( 1676): [0024]< SIM_IO SimIoResponse sw1:0x90 sw2:0x0 > D/RIL ( 1621): onRequest: SIM_IO > D/AT ( 1621): AT> AT+CRSM=192,28618,0,0,15 > D/AT ( 1621): AT< +CME ERROR: 22 > D/RILJ ( 1676): [0025]< SIM_IO error: > com.android.internal.telephony.gsm.CommandException: GENERIC_FAILURE > D/RIL ( 1621): onRequest: SIM_IO > D/AT ( 1621): AT> AT+CRSM=192,28433,0,0,15 > D/RILJ ( 1676): [0027]> simIO: SIM_IO 0xc0 0x6fcb 0,0,15 > D/RILJ ( 1676): [0028]> simIO: SIM_IO 0xc0 0x6f13 0,0,15 > D/RILJ ( 1676): [0029]> simIO: SIM_IO 0xc0 0x6f46 0,0,15 > D/RILJ ( 1676): [0030]> simIO: SIM_IO 0xc0 0x6fcd 0,0,15 > D/RILJ ( 1676): [0031]> simIO: SIM_IO 0xc0 0x6fc5 0,0,15 > D/RILJ ( 1676): [0032]> simIO: SIM_IO 0xc0 0x6f38 0,0,15 > D/RILJ ( 1676): [0033]> simIO: SIM_IO 0xc0 0x6f16 0,0,15 > D/RILJ ( 1676): [0034]> GET_SIM_STATUS > D/RILJ ( 1676): [0035]> QUERY_FACILITY_LOCK > D/RILJ ( 1676): [0036]> QUERY_FACILITY_LOCK > D/GSM ( 1676): Poll ServiceState done: oldSS=[3 home null null null ] > newSS=[0 home AirTel AirTel 40440 ] oldGprs=1 newGprs=0 oldType=unknown > newType=unknown > D/GSM ( 1676): IMSI: 404400xxxxxxxxx > D/GSM ( 1676): [GsmSimCard] Broadcasting intent > SIM_STATE_CHANGED_ACTION IMSI reason null > D/RILJ ( 1676): [0037]> simIO: SIM_IO 0xb0 0x2fe2 0,0,10 > D/RILJ ( 1676): [0038]> simIO: SIM_IO 0xb2 0x6f40 1,4,29 > D/RILJ ( 1676): [0039]> simIO: SIM_IO 0xb0 0x6fad 0,0,3 > D/GSM ( 1676): [DataConnectionTracker] ***trySetupData due to > gprsAttached > D/GSM ( 1676): [DSAC DEB] trySetupData with mIsPsRestricted=false > D/GSM ( 1676): [DataConnectionTracker] trySetupData: Not ready for > data: dataState=IDLE gprsState=0 sim=false UMTS=false phoneState=IDLE > dataEnabled=true roaming=false dataOnRoamingEnable=false ps restricted=false > D/RILJ ( 1676): [0040]> simIO: SIM_IO 0xc0 0x6f17 0,0,15 > D/RILJ ( 1676): [0041]> REQUEST_GET_NEIGHBORING_CELL_IDS > > //message while trying to make GSM call using dialer app. > # D/RILJ ( 1676): WAKE_LOCK_TIMEOUT mReqPending=0 mRequestList=17 > D/RILJ ( 1676): 0: [15] SET_NETWORK_SELECTION_AUTOMATIC > D/RILJ ( 1676): 1: [26] SIM_IO > D/RILJ ( 1676): 2: [27] SIM_IO > D/RILJ ( 1676): 3: [28] SIM_IO > D/RILJ ( 1676): 4: [29] SIM_IO > D/RILJ ( 1676): 5: [30] SIM_IO > D/RILJ ( 1676): 6: [31] SIM_IO > D/RILJ ( 1676): 7: [32] SIM_IO > D/RILJ ( 1676): 8: [33] SIM_IO > D/RILJ ( 1676): 9: [34] GET_SIM_STATUS > D/RILJ ( 1676): 10: [35] QUERY_FACILITY_LOCK > D/RILJ ( 1676): 11: [36] QUERY_FACILITY_LOCK > D/RILJ ( 1676): 12: [37] SIM_IO > D/RILJ ( 1676): 13: [38] SIM_IO > D/RILJ ( 1676): 14: [39] SIM_IO > D/RILJ ( 1676): 15: [40] SIM_IO > D/RILJ ( 1676): 16: [41] REQUEST_GET_NEIGHBORING_CELL_IDS > select 1725 (app_process), adj 14, size 3480, to kill > select 1735 (app_process), adj 15, size 4088, to kill > send sigkill to 1735 (app_process), adj 15, size 4088 > > // > # D/RILJ ( 1676): [0042]> SIGNAL_STRENGTH > D/RILJ ( 1676): WAKE_LOCK_TIMEOUT mReqPending=0 mRequestList=18 > D/RILJ ( 1676): 0: [15] SET_NETWORK_SELECTION_AUTOMATIC > D/RILJ ( 1676): 1: [26] SIM_IO > D/RILJ ( 1676): 2: [27] SIM_IO > D/RILJ ( 1676): 3: [28] SIM_IO > D/RILJ ( 1676): 4: [29] SIM_IO > D/RILJ ( 1676): 5: [30] SIM_IO > D/RILJ ( 1676): 6: [31] SIM_IO > D/RILJ ( 1676): 7: [32] SIM_IO > D/RILJ ( 1676): 8: [33] SIM_IO > D/RILJ ( 1676): 9: [34] GET_SIM_STATUS > D/RILJ ( 1676): 10: [35] QUERY_FACILITY_LOCK > D/RILJ ( 1676): 11: [36] QUERY_FACILITY_LOCK > D/RILJ ( 1676): 12: [37] SIM_IO > D/RILJ ( 1676): 13: [38] SIM_IO > D/RILJ ( 1676): 14: [39] SIM_IO > D/RILJ ( 1676): 15: [40] SIM_IO > D/RILJ ( 1676): 16: [41] REQUEST_GET_NEIGHBORING_CELL_IDS > D/RILJ ( 1676): 17: [42] SIGNAL_STRENGTH > > > Please help me out for it. > > Regards > > ANI > > -- > unsubscribe: android-porting+unsubscr...@googlegroups.com > website: http://groups.google.com/group/android-porting > -- unsubscribe: android-porting+unsubscr...@googlegroups.com website: http://groups.google.com/group/android-porting
