olliiiver / esp_lte_modem

ESP32 / esp-idf LTE UART modem library for sim7600 with cmux support
MIT License
56 stars 20 forks source link

BG96 compatibility #3

Open Pablopabota opened 3 years ago

Pablopabota commented 3 years ago

Hi, I'm trying to run this code on a BG96. After setting everything to it I flash the code and here is the ouput log:

I (12) boot: ESP-IDF v4.2.1 2nd stage bootloader
I (12) boot: compile time 17:29:12
I (12) boot: chip revision: 1
I (14) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (21) boot.esp32: SPI Speed      : 40MHz
I (26) boot.esp32: SPI Mode       : DIO
I (30) boot.esp32: SPI Flash Size : 16MB
I (35) boot: Enabling RNG early entropy source...
I (40) boot: Partition Table:
I (44) boot: ## Label            Usage          Type ST Offset   Length
I (51) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (59) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (66) boot:  2 factory          factory app      00 00 00010000 00100000
I (74) boot: End of partition table
I (78) boot_comm: chip revision: 1, min. application chip revision: 0
I (85) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x17f3c ( 98108) map
I (131) esp_image: segment 1: paddr=0x00027f64 vaddr=0x3ffb0000 size=0x02160 (  8544) load
I (135) esp_image: segment 2: paddr=0x0002a0cc vaddr=0x40080000 size=0x00404 (  1028) load
0x40080000: _WindowOverflow4 at /home/pablo/esp/esp-idf/components/freertos/xtensa/xtensa_vectors.S:1730

I (138) esp_image: segment 3: paddr=0x0002a4d8 vaddr=0x40080404 size=0x05b40 ( 23360) load
I (157) esp_image: segment 4: paddr=0x00030020 vaddr=0x400d0020 size=0x6475c (411484) map
0x400d0020: _stext at ??:?

I (314) esp_image: segment 5: paddr=0x00094784 vaddr=0x40085f44 size=0x05840 ( 22592) load
0x40085f44: prvCheckTasksWaitingTermination at /home/pablo/esp/esp-idf/components/freertos/tasks.c:3632

I (331) boot: Loaded app from partition at offset 0x10000
I (331) boot: Disabling RNG early entropy source...
I (331) cpu_start: Pro cpu up.
I (335) cpu_start: Application information:
I (340) cpu_start: Project name:     pppos_client
I (345) cpu_start: App version:      7964ebd-dirty
I (351) cpu_start: Compile time:     Jun  2 2021 17:29:04
I (357) cpu_start: ELF file SHA256:  5b88b8300bc17c5c...
I (363) cpu_start: ESP-IDF:          v4.2.1
I (368) cpu_start: Starting app cpu, entry point is 0x400818e0
0x400818e0: call_start_cpu1 at /home/pablo/esp/esp-idf/components/esp32/cpu_start.c:287

I (0) cpu_start: App cpu up.
I (378) heap_init: Initializing. RAM available for dynamic allocation:
I (385) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (391) heap_init: At 3FFB3A30 len 0002C5D0 (177 KiB): DRAM
I (397) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (403) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (410) heap_init: At 4008B784 len 0001487C (82 KiB): IRAM
I (416) cpu_start: Pro cpu start user code
I (435) spi_flash: detected chip: gd
I (435) spi_flash: flash io: dio
I (435) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (443) uart: queue free spaces: 30
I (453) pppos_example: Trying to initialize modem on GPIO TX: 23 / RX: 22
E (1953) esp-modem: esp_modem_dte_send_cmd(417): process command timeout
E (1953) dce_service: esp_modem_dce_sync(67): send command failed
E (1953) bg96: bg96_init(539): sync failed
I (2453) pppos_example: Trying to initialize modem on GPIO TX: 23 / RX: 22
I (2503) bg96: CMUX setup
I (2903) bg96: PIN ASK response: +CPIN: READY

I (3003) bg96: PIN ASK response: OK

I (4153) bg96: CMUX command success
I (4153) bg96: enter CMUX mode ok
Guru Meditation Error: Core  0 panic'ed (InstrFetchProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x00000000  PS      : 0x00060c30  A0      : 0x800d6924  A1      : 0x3ffb5750  
A2      : 0x00000000  A3      : 0x00000002  A4      : 0x3ffb4470  A5      : 0x00000000  
A6      : 0x3f404514  A7      : 0x00000001  A8      : 0x800d60bc  A9      : 0x3ffb5730  
A10     : 0x3ffb4470  A11     : 0x00000000  A12     : 0x3ffb0114  A13     : 0x00060823  
A14     : 0x00000001  A15     : 0x00000001  SAR     : 0x00000004  EXCCAUSE: 0x00000014  
EXCVADDR: 0x00000000  LBEG    : 0x400014fd  LEND    : 0x4000150d  LCOUNT  : 0xfffffffe  

Backtrace:0xfffffffd:0x3ffb5750 0x400d6921:0x3ffb5780 0x400d5775:0x3ffb57b0 0x400d3e2a:0x3ffb58f0 0x400856cd:0x3ffb5920
0x400d6921: esp_modem_start_cmux at /home/pablo/ESP32_projects/esp_lte_modem/build/../components/modem/src/esp_modem.c:832 (discriminator 2)

0x400d5775: app_main at /home/pablo/ESP32_projects/esp_lte_modem/build/../main/pppos_client_main.c:271

0x400d3e2a: main_task at /home/pablo/esp/esp-idf/components/esp32/cpu_start.c:609 (discriminator 2)

0x400856cd: vPortTaskWrapper at /home/pablo/esp/esp-idf/components/freertos/xtensa/port.c:143

ELF file SHA256: 5b88b8300bc17c5c

Rebooting...

It seems that the start_cmux function isn't working but I don't understand which instruction is prohibited, Any idea of what could be wrong?

Best regards, P

olliiiver commented 3 years ago

Hi. Will it panic without CMUX enabled (by commenting/removing esp_modem_start_cmux(dte))?

Pablopabota commented 3 years ago

Hi. No, it won't panic, but it won't switch between modes, right?

I (2453) pppos_example: Trying to initialize modem on GPIO TX: 23 / RX: 22
I (2503) bg96: CMUX setup
I (2903) bg96: PIN ASK response: +CPIN: READY

I (3003) bg96: PIN ASK response: OK

I (4253) pppos_example: Module: BG96
I (4253) pppos_example: Operator: "Movistar movistar"
I (4253) pppos_example: IMEI: xxxx
I (4253) pppos_example: IMSI: xxxx
I (4453) pppos_example: rssi: 10, ber: 99
I (4653) pppos_example: Battery voltage: 3717 mV
I (4653) esp-modem: APN: xxxx
I (4753) esp-modem: PPP MODE
I (4853) DCE_TAG: ATD response: CONNECT 150000000

I (4853) pppos_example: Modem PPP Started
I (64853) esp-netif_lwip-ppp: Connection lost
I (64853) pppos_example: Modem Disconnect from PPP Server

This is the log now

olliiiver commented 3 years ago

No it won't. You can move this line around and enable CMUX every time you're not in PPP (or CMUX) mode.

I think you need to check what's happening at esp_modem.c:832

Pablopabota commented 3 years ago

at esp_modem.c:832 dte->change_mode is executed to change to MODEM_CMUX_MODE which is a pretty simple function. So I'm not that sure of what could be happening there.

Also the start_cmux is being executed in that piece of code, I was hoping you could tell me what to do, or what could I try to debug it.

FabITA1 commented 2 years ago

Seems that the problem is the missing of the: bg96_dce->parent.setup_cmux = esp_modem_dce_setup_cmux; line in the bg96_init() function.