Open
Description
Describe the bug
It seems there is an issue with the quectel bg95 modem driver at the AT+CREG?
command. It gets stuck there and times out.
To Reproduce
Build and flash the cellular modem sample on a RAK5010-M-BG95 board.
I'm using a valid Claro (Dominican Republic) SIM card in an area with EGPRS signal.
Expected behavior
L4 should connect in time.
Impact
showstopper
Logs and console output
SEGGER J-Link V7.94i - Real time terminal output
SEGGER J-Link (unknown) V2.0, SN=802000342
Process: JLinkExe
*** Booting nRF Connect SDK v2.9.1-60d0d6c8d42d ***
*** Using Zephyr OS v3.7.99-ca954a6216c9 ***
Powering on modem
Bring up network interface
Waiting for L4 connected
[00:00:11.916,015] <dbg> modem_chat: modem_chat_script_start: running script: quectel_bg95_init_chat_script
[00:00:11.916,046] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 0
[00:00:11.916,076] <dbg> modem_chat: modem_chat_script_next: sending: ATE0
[00:00:21.916,137] <wrn> modem_chat: quectel_bg95_init_chat_script: timed out
[00:00:25.338,958] <dbg> modem_chat: modem_chat_on_unknown_command_received: RDY
[00:00:27.911,743] <dbg> modem_chat: modem_chat_on_unknown_command_received: APP RDY
[00:00:31.877,288] <dbg> modem_chat: modem_chat_on_unknown_command_received: RDY
[00:00:33.416,473] <dbg> modem_chat: modem_chat_script_start: running script: quectel_bg95_init_chat_script
[00:00:33.416,534] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 0
[00:00:33.416,564] <dbg> modem_chat: modem_chat_script_next: sending: ATE0
[00:00:33.437,744] <dbg> modem_chat: modem_chat_on_unknown_command_received: ATE0
[00:00:33.437,805] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.437,835] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 1
[00:00:33.437,866] <dbg> modem_chat: modem_chat_script_next: sending: AT+CFUN=4
[00:00:33.572,387] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.572,418] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 2
[00:00:33.572,448] <dbg> modem_chat: modem_chat_script_next: sending: AT+CMEE=1
[00:00:33.594,146] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.594,207] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 3
[00:00:33.594,238] <dbg> modem_chat: modem_chat_script_next: sending: AT+CREG=1
[00:00:33.615,936] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.615,966] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 4
[00:00:33.615,997] <dbg> modem_chat: modem_chat_script_next: sending: AT+CGREG=1
[00:00:33.637,695] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.637,725] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 5
[00:00:33.637,756] <dbg> modem_chat: modem_chat_script_next: sending: AT+CEREG=1
[00:00:33.659,454] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.659,484] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 6
[00:00:33.659,515] <dbg> modem_chat: modem_chat_script_next: sending: AT+CREG?
[00:00:33.681,091] <dbg> modem_chat: modem_chat_log_received_command: +CREG: 1 0
[00:00:33.681,182] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.681,213] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 7
[00:00:33.681,243] <dbg> modem_chat: modem_chat_script_next: sending: AT+CEREG?
[00:00:33.702,911] <dbg> modem_chat: modem_chat_log_received_command: +CEREG: 1 4
[00:00:33.702,972] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.703,002] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 8
[00:00:33.703,033] <dbg> modem_chat: modem_chat_script_next: sending: AT+CGREG?
[00:00:33.724,731] <dbg> modem_chat: modem_chat_log_received_command: +CGREG: 1 0
[00:00:33.724,792] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.724,822] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 9
[00:00:33.724,853] <dbg> modem_chat: modem_chat_script_next: sending: AT+CGSN
[00:00:33.746,612] <dbg> modem_chat: modem_chat_log_received_command: 864593056768822
[00:00:33.746,643] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 10
[00:00:33.746,704] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.746,704] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 11
[00:00:33.746,765] <dbg> modem_chat: modem_chat_script_next: sending: AT+CGMM
[00:00:33.768,218] <dbg> modem_chat: modem_chat_log_received_command: BG95-M3
[00:00:33.768,280] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 12
[00:00:33.768,341] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.768,341] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 13
[00:00:33.768,371] <dbg> modem_chat: modem_chat_script_next: sending: AT+CGMI
[00:00:33.789,855] <dbg> modem_chat: modem_chat_log_received_command: Quectel
[00:00:33.789,886] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 14
[00:00:33.789,947] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.789,978] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 15
[00:00:33.790,008] <dbg> modem_chat: modem_chat_script_next: sending: AT+CGMR
[00:00:33.811,492] <dbg> modem_chat: modem_chat_log_received_command: BG95M3LAR02A03
[00:00:33.811,523] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 16
[00:00:33.811,584] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.811,614] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 17
[00:00:33.811,645] <dbg> modem_chat: modem_chat_script_next: sending: AT+CIMI
[00:00:33.833,374] <dbg> modem_chat: modem_chat_log_received_command: 370021201019608
[00:00:33.833,404] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 18
[00:00:33.833,465] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.833,465] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 19
[00:00:33.833,496] <dbg> modem_chat: modem_chat_script_next: sending: AT+QCCID
[00:00:33.855,224] <dbg> modem_chat: modem_chat_log_received_command: +QCCID: 89010210524010196085
[00:00:33.855,255] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 20
[00:00:33.855,346] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:33.855,377] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_init_chat_script: step: 21
[00:00:33.855,407] <dbg> modem_chat: modem_chat_script_next: sending: AT+CMUX=0,0,5,127
[00:00:33.877,685] <dbg> modem_chat: modem_chat_on_unknown_command_received: OK
[00:00:34.155,548] <dbg> modem_chat: modem_chat_script_stop: quectel_bg95_init_chat_script: complete
[00:00:34.277,191] <inf> modem_at_shell: pipe connected
[00:00:34.277,252] <inf> modem_at_shell: opening pipe
[00:00:34.299,133] <inf> modem_at_shell: pipe opened
[00:00:34.299,194] <inf> modem_at_shell: chat attached
[00:00:34.420,684] <dbg> modem_chat: modem_chat_script_start: running script: quectel_bg95_dial_chat_script
[00:00:34.420,715] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_dial_chat_script: step: 0
[00:00:34.420,745] <dbg> modem_chat: modem_chat_script_next: sending: AT+CGACT=0,1
[00:00:34.443,969] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:34.444,000] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_dial_chat_script: step: 1
[00:00:34.444,030] <dbg> modem_chat: modem_chat_script_next: sending: AT+CGDCONT=1,"IP","internet.ideasclaro.com.do"
[00:00:34.471,679] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:34.471,710] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_dial_chat_script: step: 2
[00:00:34.471,740] <dbg> modem_chat: modem_chat_script_next: sending: AT+CFUN=1
[00:00:34.495,239] <dbg> modem_chat: modem_chat_log_received_command: OK
[00:00:34.495,269] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_dial_chat_script: step: 3
[00:00:34.495,300] <dbg> modem_chat: modem_chat_script_next: sending: ATD*99***1#
[00:00:34.495,422] <dbg> modem_chat: modem_chat_script_stop: quectel_bg95_dial_chat_script: complete
[00:00:34.519,073] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x0d because 0x7e was expected.
[00:00:34.519,073] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x0a because 0x7e was expected.
[00:00:34.519,104] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x43 because 0x7e was expected.
[00:00:34.519,134] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x4f because 0x7e was expected.
[00:00:34.519,134] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x4e because 0x7e was expected.
[00:00:34.519,165] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x4e because 0x7e was expected.
[00:00:34.519,165] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x45 because 0x7e was expected.
[00:00:34.519,195] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x43 because 0x7e was expected.
[00:00:34.519,195] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x54 because 0x7e was expected.
[00:00:34.519,226] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x20 because 0x7e was expected.
[00:00:34.519,226] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x31 because 0x7e was expected.
[00:00:34.519,256] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x35 because 0x7e was expected.
[00:00:34.519,256] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x30 because 0x7e was expected.
[00:00:34.519,287] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x30 because 0x7e was expected.
[00:00:34.519,287] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x30 because 0x7e was expected.
[00:00:34.519,317] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x30 because 0x7e was expected.
[00:00:34.519,317] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x30 because 0x7e was expected.
[00:00:34.519,348] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x30 because 0x7e was expected.
[00:00:34.519,348] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x30 because 0x7e was expected.
[00:00:34.519,378] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x0d because 0x7e was expected.
[00:00:34.519,409] <dbg> modem_ppp: modem_ppp_is_byte_expected: Dropping byte 0x0a because 0x7e was expected.
[00:00:34.908,691] <dbg> modem_chat: modem_chat_on_unknown_command_received: APP RDY
[00:00:34.908,782] <dbg> modem_chat: modem_chat_on_unknown_command_received: APP RDY
[00:00:37.650,604] <dbg> modem_chat: modem_chat_log_received_command: +CREG: 2
[00:00:37.650,726] <dbg> modem_chat: modem_chat_log_received_command: +CGREG: 2
[00:00:37.678,405] <dbg> modem_chat: modem_chat_log_received_command: +CREG: 1
[00:00:37.702,667] <dbg> modem_ppp: modem_ppp_process_received_byte: Receiving PPP frame
[00:00:37.702,880] <dbg> modem_ppp: modem_ppp_process_received_byte: Received PPP frame (len 29)
[00:00:37.703,308] <dbg> modem_ppp: modem_ppp_process_received_byte: Receiving PPP frame
[00:00:37.703,399] <dbg> modem_ppp: modem_ppp_process_received_byte: Received PPP frame (len 12)
[00:00:37.729,919] <dbg> modem_ppp: modem_ppp_process_received_byte: Receiving PPP frame
[00:00:37.730,010] <dbg> modem_ppp: modem_ppp_process_received_byte: Received PPP frame (len 13)
[00:00:37.753,875] <dbg> modem_ppp: modem_ppp_process_received_byte: Receiving PPP frame
[00:00:37.753,997] <dbg> modem_ppp: modem_ppp_process_received_byte: Received PPP frame (len 12)
[00:00:37.781,829] <dbg> modem_ppp: modem_ppp_process_received_byte: Receiving PPP frame
[00:00:37.781,951] <dbg> modem_ppp: modem_ppp_process_received_byte: Received PPP frame (len 12)
[00:00:37.782,012] <dbg> modem_ppp: modem_ppp_process_received_byte: Receiving PPP frame
[00:00:37.782,104] <dbg> modem_ppp: modem_ppp_process_received_byte: Received PPP frame (len 9)
[00:01:07.678,649] <dbg> modem_chat: modem_chat_script_start: running script: quectel_bg95_periodic_chat_script
[00:01:07.678,680] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_periodic_chat_script: step: 0
[00:01:07.678,710] <dbg> modem_chat: modem_chat_script_next: sending: AT+CREG?
[00:01:11.678,802] <wrn> modem_chat: quectel_bg95_periodic_chat_script: timed out
[00:01:41.678,985] <dbg> modem_chat: modem_chat_script_start: running script: quectel_bg95_periodic_chat_script
[00:01:41.679,046] <dbg> modem_chat: modem_chat_script_next: quectel_bg95_periodic_chat_script: step: 0
[00:01:41.679,077] <dbg> modem_chat: modem_chat_script_next: sending: AT+CREG?
[00:01:45.679,138] <wrn> modem_chat: quectel_bg95_periodic_chat_script: timed out
L4 was not connected in time
Environment (please complete the following information):
- OS: Macos
- Toolchain: Zephyr SDK / nordic vscode extension
- Commit SHA or Version used: Zephyr OS v3.7.99-ca954a6216c9
Additional context
See discussion: #88678