Unable to use the CMUX example (with BG96) (IDFGH-7328)

[jonathandreyer]

Hi everyone,

I have tried to make the simple_cmux_client example work, but that is not successful. The log is (with log set as verbose):

.
..
...
D (888) event: running task for loop 0x3fce0814
D (898) event: created task for loop 0x3fce0814
D (898) event: created event loop 0x3fce0814
D (908) esp_netif_lwip: LwIP stack has been initialized
D (908) esp_netif_lwip: esp-netif has been successfully initialized
I (918) uart: queue free spaces: 30
V (918) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (918) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (918) intr_alloc: Connected src 28 to int 13 (cpu 0)
D (938) esp_netif_objects: esp_netif_add_to_list 0x3fce5b84
D (948) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (958) esp-netif_lwip-ppp: esp_netif_new_ppp: PPP connection created: 0x3fce5eb4
D (958) esp-netif_lwip-ppp: Phase Dead
V (968) command_lib: set_cmux
V (968) command_lib: generic_command_common
V (968) command_lib: generic_command
D (978) command_lib: generic_command command AT+CMUX=0

D (988) command_lib: Response: 
OK

V (2008) intr_alloc: esp_intr_free: Disabling int, killing handler
E (2008) cmux_example: Failed to configure desired mode... exiting
D (2008) event: deleted loop 0x3fce0814

As the problem seems to come from the line (below), I have also tried to separate both actions. From: https://github.com/espressif/esp-protocols/blob/38149c8d9bdf469806fe0685558eba74f3366d73/components/esp_modem/examples/simple_cmux_client/main/simple_cmux_client_main.cpp#L90

to:

bool cmux_mode = dce->set_mode(esp_modem::modem_mode::CMUX_MODE);
ESP_LOGD(TAG, "set_mode in CMUX : %d", cmux_mode);
bool data_mode = dce->set_mode(esp_modem::modem_mode::DATA_MODE);
ESP_LOGD(TAG, "set_mode in DATA : %d", data_mode);

if (cmux_mode && data_mode) {

In this case, the log is:

.
..
...
D (888) event: running task for loop 0x3fce0764
D (888) event: created task for loop 0x3fce0764
D (898) event: created event loop 0x3fce0764
D (898) esp_netif_lwip: LwIP stack has been initialized
D (908) esp_netif_lwip: esp-netif has been successfully initialized
I (908) uart: queue free spaces: 30
V (918) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (918) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (918) intr_alloc: Connected src 28 to int 13 (cpu 0)
D (938) esp_netif_objects: esp_netif_add_to_list 0x3fce5b84
D (938) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (948) esp-netif_lwip-ppp: esp_netif_new_ppp: PPP connection created: 0x3fce5eb4
D (958) esp-netif_lwip-ppp: Phase Dead
V (958) command_lib: set_cmux
V (968) command_lib: generic_command_common
V (968) command_lib: generic_command
D (968) command_lib: generic_command command AT+CMUX=0

D (978) command_lib: Response: 
OK

V (1998) intr_alloc: esp_intr_free: Disabling int, killing handler
D (1998) cmux_example: set_mode in CMUX : 0
V (1998) command_lib: set_echo
V (1998) command_lib: generic_command_common
V (1998) command_lib: generic_command
D (2008) command_lib: generic_command command ATE0

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x8 (TG1WDT_SYS_RST),boot:0x28 (SPI_FAST_FLASH_BOOT)
Saved PC:0x4201b175
...
..
.

So the problem seems to appear during the second action, but the return code of the first action is strange. Regarding the example, it seems to me that there is a problem with the creation of SIM800 & SIM7600 object (line 83 & 75). Would it be more like dte instead of uart_dte? In the esp_modem library, I have seen that the data mode is done with the command ATD*99## (here), while in the documentation of the BG96, it indicates ATD*99# (like for sim8xx).

I have tested the PPPoS example, which works with a small fix (EXAMPLE_MODEM_UART_EVENT_TASK_STACK_SIZE set to 3072). Without that, I have a stack overflow in uart_task.

A test board, I use a Wemos D1 R32 with a ESP32-S3-WROOM-1 module and a BG96 modem (RAK 2011). As toolchain, I use the PlaformIO with custom platform to support the ESP-IDF v4.4 (https://github.com/jonathandreyer/platform-espressif32). In my case, it is the release v4.4.1.

Does somebody have an idea or have tested this CMUX example?

Best regards,

Jonathan Dreyer

[david-cermak]

Hi Jonathan,

Thanks for reporting this, it looks like there's a bug in

https://github.com/espressif/esp-protocols/blob/38149c8d9bdf469806fe0685558eba74f3366d73/components/esp_modem/src/esp_modem_cmux.cpp#L106

As the BG96 sends UIH frames of 0xef type (unlike SIM7600).

The quick fix is to replace it with

-if (data && type == 0xFF && len > 0 && dlci > 0) {
+if (data && ((type&0xEF) == 0xEF) && len > 0 && dlci > 0) {

I'll investigate the issue and fix it.

[jonathandreyer]

Hi @david-cermak,

Thanks for your support. I have tested your quick fix, but it does not seem work. With the PR #34, the simple_cmux_client example works well.

Best regards,

Jonathan Dreyer

[david-cermak]

@jonathandreyer Thanks for testing the fixes. Yes, I've discovered (with the real BG96) that it needs a small pause between switching to CMUX mode and actually accepting the CMUX commands.