Telit he910 ---- modem port got stuck

Hello,

I am using Telit HE910 modem, the version of firmware is 12.00.03.

Sometimes, the modem port got stuck after sending AT+CGDCONT=1. (Such as AT+CGDCONT=1,"IP","internet.tele2.se").

When this problem happened, I could not get any information from the modem port
after this command..

The following was the situation when this problem happened
Aux: > AT+CRSM=192,28621\r
Modem: > AT+CGDCONT=1,"IP","internet.tele2.se"\r
Modem: < AT+CGDCONT=1,"IP","internet.tele2.se"\r
Aux: < \r\n+CME ERROR: 4\r\n

According to Telit AT Commands Reference Guide:
/3.2.5. Command Issuing Timing/

/The chain Command -> Response shall always be respected and a new command must not be//
//issued before the module has terminated all the sending of its response result code (whatever it//
//may be)./

It seems that this problem is caused by "Command Issuing TIming"

Since there were alway some pending responses on the AUX port when this problem happened.
and there was no pending response on the AUX port when it worked.

when it worked:
Aux: > AT+CRSM=192,28621\r
Aux: < \r\n+CME ERROR: 4\r\n
Aux: > AT+CRSM=192,28437\r
Aux: < \r\n+CRSM: 148,4\r\n\r\nOK\r\n drivers/atmodem/gprs-context.c:at_gprs_activate_primary() cid 1
Modem: > AT+CGDCONT=1,"IP","internet.tele2.se"\r
Modem: < AT+CGDCONT=1,"IP","internet.tele2.se"\r\r\nOK\r\n

I added sleep(1) just before sending out
AT+CGDCONT=1,"IP","internet.tele2.se command.
It worked well. I know this is a bad idea.

If this problem is really caused by "Command Issuing TIming", How should we solve or work around this problem?

Thanks.

Mingli

The following is trace log.

Aux: > ATE0 +CMEE=1\r
Aux: < ATE0 +CMEE=1\r\r\nOK\r\n
Aux: > AT#QSS=0\r
Aux: < \r\nOK\r\n
Aux: > AT+CFUN=1\r
Aux: < \r\nOK\r\n
plugins/telit.c:cfun_enable_cb() 0x9b6af8 src/modem.c:modem_change_state() old state: 0, new state: 1 plugins/telit.c:telit_pre_sim() 0x9b6af8
Aux: > AT&C0\r
src/sim.c:ofono_sim_add_state_watch() 0x9afc98 src/sim.c:ofono_sim_add_state_watch() 0x9afc98 src/sim.c:ofono_sim_add_state_watch() 0x9afc98
Aux: < \r\nOK\r\n
Aux: > AT+GCAP\r
Aux: < \r\n+GCAP: +CGSM,+DS,+FCLASS,+MS,+ES\r\n\r\nOK\r\n
Aux: > AT+CRC=1\r
Aux: < \r\nOK\r\n
Aux: > AT+CLIP=1\r
Aux: < \r\nOK\r\n
Aux: > AT+CDIP=1\r
Aux: < \r\nERROR\r\n
Aux: > AT+CNAP=1\r
Aux: < \r\nERROR\r\n
Aux: > AT+COLP=1\r
Aux: < \r\nOK\r\n
Aux: > AT+CSSN=1,1\r
Aux: < \r\nOK\r\n
Aux: > AT+VTD?\r
Aux: < \r\n0\r\n\r\nOK\r\n
Aux: > AT+CCWA=1\r
Aux: < \r\nOK\r\n drivers/atmodem/voicecall.c:at_voicecall_initialized() voicecall_init:
registering to notifications
src/sim.c:ofono_sim_add_state_watch() 0x9afc98
Aux: > AT#AUTOATT=0\r
Aux: < \r\nOK\r\n
Aux: > AT#QSS=2\r
Aux: < \r\nOK\r\n
Aux: > AT#QSS?\r
Aux: < \r\n#QSS: 2,1\r\n\r\nOK\r\n
plugins/telit.c:telit_qss_notify() 0x9b6af8
plugins/telit.c:switch_sim_state_status() 0x9b6af8, SIM status: 1
Aux: > AT+CGMI\r
Aux: < \r\nTelit\r\n\r\nOK\r\n
Aux: > AT+CLCC\r
Aux: < \r\nOK\r\n
Aux: > AT+CPIN?\r
Aux: < \r\n+CPIN: READY\r\n\r\nOK\r\n
Aux: > AT+CGMM\r
Aux: < \r\nHE910\r\n\r\nOK\r\n
Aux: > AT+CPMS?\r
Aux: < \r\n+CPMS: "SM",0,25,"SM",0,25,"SM",0,25\r\n\r\nOK\r\n
Aux: > AT+CGMR\r
Aux: < \r\n12.00.002\r\n\r\nOK\r\n
Aux: > AT+CSCS=?\r
Aux: < \r\n+CSCS: ("GSM","IRA","8859-1","PCCP437","UCS2")\r\n\r\nOK\r\n
Aux: > AT+CSMS=?\r
Aux: < \r\n+CSMS: (0,1)\r\n\r\nOK\r\n drivers/atmodem/sms.c:at_csms_query_cb() CSMS query parsed successfully
Aux: > AT+CRSM=192,28599\r
Aux: < \r\n+CRSM: 148,4\r\n\r\nOK\r\n src/voicecall.c:ecc_g2_read_cb() 0
Aux: > AT+CGSN\r
Aux: < \r\n357164045019588\r\n\r\nOK\r\n
Aux: > AT+CPBS=?\r
Aux: < \r\n+CPBS: ("SM","FD","LD","MC","RC","DC","ME","ON")\r\n\r\nOK\r\n
Aux: > AT+CSMS=1\r
Aux: < \r\n+CSMS: 1,1,1\r\n\r\nOK\r\n
Aux: > AT+CRSM=192,28599\r
Aux: < \r\n+CRSM: 148,4\r\n\r\nOK\r\n src/voicecall.c:ecc_g3_read_cb() 0
Aux: > AT+CSMS?\r
Aux: < \r\n
Aux: < +CSMS: 1,1,1,1\r\n\r\nOK\r\n
Aux: > AT+CRSM=192,12258\r
Aux: < \r\n+CRSM: 144,0,0000000A2FE204000EFFEE01020000\r\n\r\nOK\r\n drivers/atmodem/sim.c:at_crsm_info_cb() crsm_info_cb: 90, 00, 15
Aux: > AT+CMGF=?\r
Aux: < \r\n+CMGF: (0,1)\r\n\r\nOK\r\n
Aux: > AT+CRSM=176,12258,0,0,10\r
Aux: < \r\n+CRSM: 144,0,98640244020000105139\r\n\r\nOK\r\n drivers/atmodem/sim.c:at_crsm_read_cb() crsm_read_cb: 90, 00, 10 src/simfs.c:sim_fs_op_read_block_cb() bufoff: 0, dataoff: 0, tocopy: 10
Aux: > AT+CPMS=?\r
Aux: < \r\n+CPMS: ("SM"),("SM"),("SM")\r\n\r\nOK\r\n
Aux: > AT+CRSM=192,28421\r
Aux: < \r\n+CME ERROR: 4\r\n
Aux: > AT+CMGF=0\r
Aux: < \r\nOK\r\n
Aux: > AT+CRSM=192,12037\r
Aux: < \r\n+CME ERROR: 4\r\n
Aux: > AT+CPMS="SM","SM","SM"\r
Aux: < \r\n+CPMS: 0,25,0,25,0,25\r\n\r\nOK\r\n
Aux: > AT+CPIN?\r
Aux: < \r\n+CPIN: READY\r\n\r\nOK\r\n drivers/atmodem/sim.c:at_cpin_cb() crsm_pin_cb: READY drivers/atmodem/sim.c:at_pin_retries_query()
Aux: > AT+CNMI=?\r
Aux: < \r\n+CNMI: (0-3),(0-3),(0,2),(0-2),(0,1)\r\n\r\nOK\r\n drivers/atmodem/sms.c:build_cnmi_string() drivers/atmodem/sms.c:construct_ack_pdu()
Aux: > AT#PCT\r
Aux: < \r\n#PCT: 3\r\n\r\nOK\r\n
drivers/atmodem/sim.c:at_pct_cb() Note: No password required,
returning maximum retries:
drivers/atmodem/sim.c:at_pct_cb() retry counter id=1, val=3 drivers/atmodem/sim.c:at_pct_cb() retry counter id=4, val=3 drivers/atmodem/sim.c:at_pct_cb() retry counter id=9, val=10 drivers/atmodem/sim.c:at_pct_cb() retry counter id=11, val=10
Aux: > AT+CRSM=192,28590\r
Aux: < \r\n+CME ERROR: 4\r\n
Aux: > AT+CNMI=2,2,2,1,0\r
Aux: < \r\nOK\r\n
src/sms.c:sms_restore_tx_queue() plugins/push-notification.c:sms_watch() registered plugins/smart-messaging.c:sms_watch() registered
Aux: > AT+CRSM=192,28589\r
Aux: < \r\n+CRSM: 144,0,000000036FAD04000EFFEE01020000\r\n\r\nOK\r\n drivers/atmodem/sim.c:at_crsm_info_cb() crsm_info_cb: 90, 00, 15
Aux: > AT+CMGL=4\r
Aux: < \r\nOK\r\n
drivers/atmodem/sms.c:at_cmgl_done()
Aux: > AT+CGSMS=3\r
Aux: < \r\nOK\r\n
Aux: > AT+CRSM=176,28589,0,0,3\r
Aux: < \r\n
Aux: < +CRSM: 144,0,00FFFF\r\n\r\nOK\r\n drivers/atmodem/sim.c:at_crsm_read_cb() crsm_read_cb: 90, 00, 3 src/simfs.c:sim_fs_op_read_block_cb() bufoff: 0, dataoff: 0, tocopy: 3 EFad does not specify (optional) MNC length, defaulting to 2
Aux: > AT+CRSM=192,28438\r
Aux: < \r\n+CRSM: 148,4\r\n\r\nOK\r\n
Aux: > AT+CRSM=192,28472\r
Aux: < \r\n+CRSM: 144,0,0000000E6F3804001EFFEE01020000\r\n\r\nOK\r\n drivers/atmodem/sim.c:at_crsm_info_cb() crsm_info_cb: 90, 00, 15
Aux: > AT+CRSM=176,28472,0,0,14\r
Aux: < \r\n+CRSM: 144,0,FF3FFF0F0300FC03000CC300F0C0\r\n\r\nOK\r\n drivers/atmodem/sim.c:at_crsm_read_cb() crsm_read_cb: 90, 00, 14 src/simfs.c:sim_fs_op_read_block_cb() bufoff: 0, dataoff: 0, tocopy: 14
Aux: > AT+CRSM=192,28502\r
Aux: < \r\n+CME ERROR: 4\r\n
Aux: > AT+CIMI\r
Aux: < \r\n240075990001159\r\n\r\nOK\r\n drivers/atmodem/sim.c:at_cimi_cb() cimi_cb: 240075990001159 src/modem.c:modem_change_state() old state: 1, new state: 2 plugins/telit.c:telit_post_sim() 0x9b6af8 drivers/atmodem/gprs-context.c:at_gprs_context_probe()
Aux: > AT+CGDCONT=?\r
plugins/telit.c:telit_set_online() modem 0x9b6af8 online
Aux: < \r\n+CGDCONT: (1-5),"IP",,,(0,1),(0,1)\r\n\r\nOK\r\n
Aux: > AT+CFUN=1,0\r
Aux: < \r\nOK\r\n
src/modem.c:modem_change_state() old state: 2, new state: 3 plugins/telit.c:telit_post_online() 0x9b6af8
Aux: > AT#QSS?\r
Aux: < \r\n#QSS: 2,1\r\n\r\nOK\r\n
plucins/telit.c:telit_qss_notify() 0x9b6af8 plugins/telit.c:switch_sim_state_status() 0x9b6af8, SIM status: 1
Aux: > AT+CRSM=192,28480\r
Aux: < \r\n+CRSM: 144,0,000000386F40040011FFEE0102011C\r\n\r\nOK\r\n drivers/atmodem/sim.c:at_crsm_info_cb() crsm_info_cb: 90, 00, 15
Aux: > AT+CGREG=?\r
Aux: < \r\n+CGREG: (0-2)\r\n\r\nOK\r\n
Aux: > AT+CREG=?\r
Aux: < \r\n
Aux: < +CREG: (0-2)\r\n\r\nOK\r\n
Aux: > AT+CSCS?\r
Aux: < \r\n+CSCS: "IRA"\r\n\r\nOK\r\n
Aux: > AT+CUSD=1\r
Aux: < \r\nOK\r\n
Aux: > AT+CAOC=2\r
Aux: < \r\nOK\r\n
Aux: > AT+CCWE=1\r
Aux: < \r\nOK\r\n
Aux: > AT+CPIN?\r
Aux: < \r\n+CPIN: READY\r\n\r\nOK\r\n
Aux: > AT+CRSM=178,28480,1,4,28\r
Aux: < \r\n+CRSM:
144,0,FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF\r\n\r\nOK\r\n
drivers/atmodem/sim.c:at_crsm_read_cb() crsm_read_cb: 90, 00, 28
Aux: > AT+CGREG=2\r
Aux: < \r\nOK\r\n
Aux: > AT+CGAUTO=0\r
Aux: < \r\nERROR\r\n
Aux: > AT+CGEREP=2,1\r
Aux: < \r\nOK\r\n
Aux: > AT+CREG=2\r
Aux: < \r\nOK\r\n
Aux: > AT+CPMS?\r
Aux: < \r\n+CPMS: "SM",0,25,"SM",0,25,"SM",0,25\r\n\r\nOK\r\n
Aux: > AT+CRSM=178,28480,2,4,28\r
Aux: < \r\n+CRSM:
144,0,FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF\r\n\r\nOK\r\n
drivers/atmodem/sim.c:at_crsm_read_cb() crsm_read_cb: 90, 00, 28
Aux: > AT#PSNT=1\r
Aux: < \r\nOK\r\n
Aux: > AT+CPSB=1\r
Aux: < \r\nERROR\r\n
Aux: > AT+CIND=?\r
Aux: < \r\n+CIND:
(("battchg",(0-5,99)),("signal",(0-7,99)),("service",(0,1)),("sounder",(0,1)),("messn
Aux: > AT+CRSM=192,28489\r
Aux: < \r\n+CRSM: 148,4\r\n\r\nOK\r\n
Aux: > AT+CMER=?\r
Aux: < \r\n+CMER: (0-3),(0),(0),(0,2),(0,1)\r\n\r\nOK\r\n drivers/atmodem/network-registration.c:build_cmer_string()
Aux: > AT+CRSM=192,20256\r
Aux: < \r\n+CME ERROR: 4\r\n
Aux: > AT+CMER=3,0,0,2\r
Aux: < \r\nOK\r\n
Aux: < \r\n+CIEV: battchg,0\r\n\r\n+CIEV: signal,7\r\n\r\n+CIEV:
service,1\r\n\r\n+CIEV: sounder,0\r\nn
src/sim.c:ofono_sim_add_spn_watch() 0x9afc98 src/network.c:__ofono_netreg_add_status_watch() 0x9b9ff0 src/network.c:__ofono_netreg_add_status_watch() 0x9b9ff0
Aux: > AT+CRSM=192,28618\r
Aux: < \r\n+CRSM: 148,4\r\n\r\nOK\r\n
Unable to read waiting messages numbers from SIM
Aux: > AT+CREG?\r
Aux: < \r\n+CREG: 2,1,"00D4","0D45D96",2\r\n\r\nOK\r\n src/network.c:ofono_netreg_status_notify() /telit_0 status 1 tech 2 src/gprs.c:netreg_status_changed() 1
Aux: > AT+CRSM=192,28617\r
Aux: < \r\n+CRSM: 148,4\r\n\r\nOK\r\n
Unable to read mailbox identifies from SIM
Aux: > AT+COPS=3,2\r
Aux: < \r\nOK\r\n
Aux: > AT+COPS?\r
Aux: < \r\n+COPS: 0,2,"24005",2\r\n\r\nOK\r\n drivers/atmodem/network-registration.c:cops_numeric_cb() Cops numeric
got mcc: 240, mnc: 05
Aux: > AT+CIND?\r
Aux: < \r\n+CIND: 0,7,1,0,0,0,0,0,5\r\n\r\nOK\r\n src/network.c:ofono_netreg_strength_notify() strength 100
Aux: > AT+CGATT=1\r
Aux: < \r\nOK\r\n
Aux: < \r\n+CGREG: 1,"00D4","0D45D96",2,"01"\r\n src/gprs.c:gprs_attach_callback() /telit_0 error = 0 src/gprs.c:ofono_gprs_status_notify() /telit_0 status 1
Aux: > AT+CIND?\r
Aux: < \r\n+CIND: 0,7,1,0,0,0,0,0,5\r\n\r\nOK\r\n
Aux: > AT+CRSM=192,28433\r
Aux: < \r\n+CRSM: 148,4\r\n\r\nOK\r\n src/message-waiting.c:mw_cphs_mwis_read_cb() No CPHS MWIS on SIM
Aux: > AT+COPS=3,0\r
Aux: < \r\nOK\r\n
Aux: > AT+COPS?\r
Aux: < \r\n+COPS: 0,0,"S 05",2\r\n\r\nOK\r\n drivers/atmodem/network-registration.c:cops_cb() cops_cb: S 05, 240 05 2 src/network.c:current_operator_callback() 0x9b9ff0, (nil) src/gprs.c:netreg_status_changed() 1
Aux: > AT+CGREG?\r
Aux: < \r\n
Aux: < +CGREG: 2,1,"00D4","0D45D96",2,"01"\r\n\r\nOK\r\n src/gprs.c:registration_status_cb() /telit_0 error 0 status 1 src/gprs.c:ofono_gprs_status_notify() /telit_0 status 1
Aux: > AT+CRSM=192,28435\r
Aux: < \r\n+CRSM: 148,4\r\n\r\nOK\r\n src/simfs.c:sim_fs_op_read_block() bufoff: 0, seekoff: 39, toread: 17
Aux: > AT+CRSM=192,28621\r drivers/atmodem/gprs-context.c:at_gprs_activate_primary() cid 1
Modem: > AT+CGDCONT=1,"IP","internet.tele2.se"\r
Modem: < AT+CGDCONT=1,"IP","internet.tele2.se"\r
Aux: < \r\n+CME ERROR: 4\r\n
Aux: > AT+CRSM=192,28437\r

The problem, in short, is that the Telit HE910 does not support sending any AT command on the Modem port while there is an outstanding command on the Aux port (this should be true for all Telit modems). Does Ofono support synchronizing these two channels so that they effectively share a common command queue? If yes, how?

/Jonas

Hi Jonas,

Many M2M setups use the modem from multiple applications (e.g. one app uses one port for SMS, another for data, another for GPRS). So I'd be surprised if the Telit firmware had such a limitation. If that is the case, then the Telit firmware is broken and should be fixed.

There is no such capability. That would defeat the purpose of having multiple channels in the first place. About the only thing you can do is drive everything off of the AUX serial port and only use the Modem port for entering into PPP mode.

Regards,
-Denis