espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.92k stars 7.33k forks source link

pppos client crash (IDFGH-1201) #3506

Closed yavortomov closed 4 years ago

yavortomov commented 5 years ago

Environment

Problem Description

I have a Quectel chip connected to ESP32 and utilizing the pppos_client from the IDF examples (https://github.com/espressif/esp-idf/tree/master/examples/protocols/pppos_client) The Quectel chip will power on and display all information and pull an IP address. I'm able to send and receive messages via MQTT. However, at the point of the switching between data mode to AT mode so I the chip can be powered down properly via AT command the ESP errors out and crashes.

I think the problem is with the line below in the bg96.c file. Looks like the "+++" command is not successfully sent and that causes all the error checks to fail. DCE_CHECK(dte->send_cmd(dte, "+++", MODEM_COMMAND_TIMEOUT_MODE_CHANGE) == ESP_OK, "send command failed", err); I was able to switch the Quectel chip from data mode to AT command mode via an AT command (Using UART directly to my PC) "+++" so that is the correct command. Also, I tried adding a delay before and after due to the manufacture time requirements.

The error:
I (26387) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE I (26397) pppos_example: MQTT other event id: 7 I (26827) MQTT_CLIENT: Sending MQTT CONNECT message, type: 1, id: 0000 I (27177) pppos_example: MQTT_EVENT_CONNECTED I (27177) pppos_example: sent subscribe successful, msg_id=27866 I (27237) pppos_example: MQTT_EVENT_SUBSCRIBED, msg_id=27866 I (27247) pppos_example: sent publish successful, msg_id=0 I (27307) pppos_example: MQTT_EVENT_DATA TOPIC=/topic/esp-pppos DATA=Here 2 I (27307) pppos_example: Before MQTT destroy

I (27567) pppos_example: MQTT_EVENT_DATA TOPIC=/topic/esp-pppos DATA=Hello From BMK via cell!!! I (27617) pppos_example: Modem PPP Stopped I (29567) esp-modem: Reached Shutdown E (33567) esp-modem: esp_modem_dte_send_cmd(216): process command timeout E (33567) bg96: bg96_set_working_mode(301): send command failed E (33567) esp-modem: esp_modem_dte_change_mode(305): set new working mode:0 failed E (33577) esp-modem: esp_modem_exit_ppp(619): enter command mode failed ESP_ERROR_CHECK failed: esp_err_t 0xffffffff (ESP_FAIL) at 0x40085088 0x40085088: _esp_error_check_failed at /root/esp/esp-idf/components/esp32/panic.c:720

file: "/root/esp/Yavor/workspace/pppos_client/main/pppos_client_main.c" line 252 func: app_main expression: esp_modem_exit_ppp(dte)

ELF file SHA256: 6964fb894b25fc4303d8b1a605d98939a5fa567bf9c04168c7ab5b8a8b2fbfef

Backtrace: 0x40084c20:0x3ffb5f00 0x4008508b:0x3ffb5f20 0x400d4233:0x3ffb5f40 0x400d247e:0x3ffb6000 0x40086b8d:0x3ffb6020 0x40084c20: invoke_abort at /root/esp/esp-idf/components/esp32/panic.c:715

0x4008508b: _esp_error_check_failed at /root/esp/esp-idf/components/esp32/panic.c:721

0x400d4233: app_main at /root/esp/Yavor/workspace/pppos_client/main/pppos_client_main.c:252 (discriminator 1)

0x400d247e: main_task at /root/esp/esp-idf/components/esp32/cpu_start.c:526

0x40086b8d: vPortTaskWrapper at /root/esp/esp-idf/components/freertos/port.c:403

================== CURRENT THREAD REGISTERS =================== pc 0x40084cf8 0x40084cf8 <invoke_abort+24> lbeg 0x400014fd 1073747197 lend 0x4000150d 1073747213 lcount 0xfffffffb 4294967291 sar 0x4 4 ps 0x60520 394528 threadptr br scompare1 acclo acchi m0 m1 m2 m3 expstate f64r_lo f64r_hi f64s fcr fsr a0 0x400851d2 1074287058 a1 0x3ffb64e0 1073439968 a2 0x3ffb1d24 1073421604 a3 0x40000000 1073741824 a4 0x3f4035d8 1061172696 a5 0xfc 252 a6 0x3f403914 1061173524 a7 0x3f40380c 1061173260 a8 0x0 0 a9 0x3ffb64c0 1073439936 a10 0x0 0 a11 0x84 132 a12 0x14 20 a13 0xffffffff -1 a14 0x0 0 a15 0xffffffe8 -24

==================== CURRENT THREAD STACK =====================

0 0x40084cf8 in invoke_abort () at /root/esp/esp-idf/components/esp32/panic.c:156

1 0x400851d2 in _esp_error_check_failed (rc=-1, file=0x3f4035d8 \"/root/esp/Yavor/workspace/pppos_client/main/pppos_client_main.c\", line=1074287058, function=0x3ffb64e0 \"\330\065@\", <incomplete sequence \374>, expression=0x3ffb1d24 \"ESP_ERROR_CHECK\") at /root/esp/esp-idf/components/esp32/panic.c:721

2 0x400d4326 in app_main () at /root/esp/Yavor/workspace/pppos_client/main/pppos_client_main.c:252

3 0x400d2339 in main_task (args=0x0) at /root/esp/esp-idf/components/esp32/cpu_start.c:526

4 0x400872a8 in vPortTaskWrapper (pxCode=0x400d22d4 , pvParameters=0x0) at /root/esp/esp-idf/components/freertos/port.c:143

======================== THREADS INFO ========================= Id Target Id Frame 9 process 8 0x400870cd in xQueueGenericReceive (xQueue=0x3ffafe10, pvBuffer=0x0, xTicksToWait=4294967295, xJustPeeking=0) at /root/esp/esp-idf/components/freertos/queue.c:1592 8 process 7 0x400870cd in xQueueGenericReceive (xQueue=0x3ffbc470, pvBuffer=0x0, xTicksToWait=4294967295, xJustPeeking=0) at /root/esp/esp-idf/components/freertos/queue.c:1592 7 process 6 0x400870cd in xQueueGenericReceive (xQueue=0x3ffb4a68, pvBuffer=0x0, xTicksToWait=4294967295, xJustPeeking=0) at /root/esp/esp-idf/components/freertos/queue.c:1592 6 process 5 0x400870cd in xQueueGenericReceive (xQueue=0x3ffaea50, pvBuffer=0x0, xTicksToWait=4294967295, xJustPeeking=0) at /root/esp/esp-idf/components/freertos/queue.c:1592 5 process 4 0x400890c4 in prvProcessTimerOrBlockTask (xNextExpireTime=, xListWasEmpty=) at /root/esp/esp-idf/components/freertos/timers.c:589 4 process 3 0x400870cd in xQueueGenericReceive (xQueue=0x3ffb9af8, pvBuffer=0x3ffbada0, xTicksToWait=10, xJustPeeking=0) at /root/esp/esp-idf/components/freertos/queue.c:1592 3 process 2 0x40127206 in esp_pm_impl_waiti () at /root/esp/esp-idf/components/esp32/pm_esp32.c:487 2 process 1 0x40127206 in esp_pm_impl_waiti () at /root/esp/esp-idf/components/esp32/pm_esp32.c:487

======================= ALL MEMORY REGIONS ========================

Any guidance will be helpful. Thanks

suda-morris commented 5 years ago

@yavortomov Thanks for your interest in this example. Just like what you said, after esp32 sends out the "+++", it doesn't received any response it want in time. How often this example failed at this line? Does any delay before ESP_ERROR_CHECK(esp_modem_exit_ppp(dte)); help? Because I guess that the modem has treat the "+++" as data.

yavortomov commented 5 years ago

@suda-morris

I also tried making the MODEM_COMMAND_TIMEOUT_CHANGE to 3000 & 5000. Same issue.

Dissecting the program: while exiting the PPP mode, the modem sets the working mode to 0 and sends the +++ by using the following line:

DCE_CHECK(dte->send_cmd(dte, "+++", MODEM_COMMAND_TIMEOUT_MODE_CHANGE) == ESP_OK, "send command failed", err);

Now if you check inside, send_cmd function the following lines get executed;

uart_write_bytes(esp_dte->uart_port, command, strlen(command)); MODEM_CHECK(xSemaphoreTake(esp_dte->process_sem, pdMS_TO_TICKS(timeout)) == pdTRUE, "process command timeout", err);

This means, the +++ is written by uart_write_bytes function and a semaphore is issued for about 3000 ms. Now I dont know how does the program control goes from here to static esp_err_t bg96_handle_exit_data_mode(modem_dce_t dce, const char line)). Here is where the response gets parsed. I tried putting a print line inside the function. The program control never reaches here.

Thank you

suda-morris commented 5 years ago

Hi @yavortomov what you explained is pretty right. BG96 may need more time to change working mode. I don't know why the original setting of 3000 ms also doesn't work for me now. But after I change it to a larger value (e.g. 5000 or 10000), BG96 worked again. Have a try.

Now I dont know how does the program control goes from here to static esp_err_t bg96_handle_exit_data_mode(modem_dce_t dce, const char line)).

After esp32 send "+++" to bg96, it will wait for a semaphore. After bg96 response something, the uart_event_task_entry will get the content and pass to the handler( here is bg96_handle_exit_data_mode). You can understand in this way, that the handler is called by uart pattern detection interrupt. In the handler, we will verify the response and give the semaphore so that function esp_modem_dte_send_cmd can return.

yavortomov commented 5 years ago

Thanks for the response about the program. That was very helpful.

But even with the increase in the timeout to 5000 or 10000, I am getting the same issue .

Finding 1

It looks like after "+++" command is issued, the uart pattern detection interrupt is never triggered. I have inserted print statements inside the uart_event_task_entry code block static void uart_event_task_entry(void *param) , so that I get a log message whenever the uart event happens. But after sending "+++", I cannot see any message. In that case, Is it right to say that the uart event never happens after sending "+++"?

Finding 2 Inside esp_modem_exit_ppp(modem_dte_T * dte), change_mode command tries to put the Modem in to MODEM_COMMAND_MODE. When looked into change_mode function, the uart pattern detector interrupt is set as: uart_enable_pattern_det_intr(esp_dte->uart_port, '\n', 1, MIN_PATTERN_INTERVAL, MIN_POST_IDLE, MIN_PRE_IDLE);. I think setting an interrupt which expects '\n' is a problem since after sending "+++" there are no '\n'. If the uart_rx interrupt is looking for \n, it will never get triggered. Do you think changing it to something else will solve this issue?

According to Quectel documentation, we need to pause 1 sec, send "+++" and then pause 1 sec to successfully put the modem into PPP_Modem. I think my modem does go into command mode successfully, but the uart_rx interrupt never detects it and classifies it as a UART_PATTERN_DET switch case.

Thanks again!

suda-morris commented 5 years ago

@yavortomov Yes, seems like the detect pattern interrupt doesn't be triggered. Thanks for reporting this issue. The reason why we detect the \n is in the command mode, the modem''s response will always end with \n. So after sending +++ we need to wait for response like NO CARRIER\n. It's so weird because I tested with SIM800L and BG96 again and I can detect this pattern in the interrupt. Regarding to the delay, yes you might add vTaskDelay(pdMS_TO_TICKS(1000)); after this line for a try. If this doesn't have help, my suggestion will be hack the code in bg96_set_working_mode a little bit, disable the return check of dte->send_cmd. e.g.

case MODEM_PPP_MODE:
        dce->handle_line = bg96_handle_atd_ppp;
        // DCE_CHECK(dte->send_cmd(dte, "ATD*99***1#\r", MODEM_COMMAND_TIMEOUT_MODE_CHANGE) == ESP_OK, "send command failed", err);
        // DCE_CHECK(dce->state == MODEM_STATE_SUCCESS, "enter ppp mode failed", err);
        // ESP_LOGD(DCE_TAG, "enter ppp mode ok");
        dte->send_cmd(dte, "ATD*99***1#\r", MODEM_COMMAND_TIMEOUT_MODE_CHANGE);
        vTaskDelay(pdMS_TO_TICKS(1000));
        dce->mode = MODEM_PPP_MODE;
        break;

If you really get the response and get into command mode successfully, you might see a warning in the log like "Unknown response: NO CARRIER" next time you send any AT commands.

yavortomov commented 5 years ago

@suda-morris Thank you for all of your help and effort. We ended up adding a 2nd AT command (AT) right after the "+++". Basically, an additional check that the modem is in AT mode. The uart pattern detection is triggered by the "OK" response of the 2nd AT command.
Additionally, I had to change the "MODEM_COMMAND_TIMEOUT_POWEROFF" Thanks, for the help

yavortomov commented 5 years ago

@suda-morris I have one more question what values do you use for the "UART Configuration" (Task sizes, Event Queue Size, Buffer Size) in the make menuconfig?

Thanks

suda-morris commented 5 years ago

@yavortomov Thanks for your feedback. For the configuration, I just use the default value. But if it's not efficient for your application, there might be some warnings in the log, it's OK to change them in the menuconfig.

9lash commented 5 years ago

@suda-morris I have been following this thread. Thanks very much for your feedback on "+++" issues. Just a quick question, is there an example on how to run the ppos client in loop? I renamed the void app_main() in your code as void modem_cycle() and set a timer which calls modem_cycle every 4 minutes.

This successfully posts the data once and in the second iteration, it gets stuck forever after entering into ppp mode. I believe this is because tcp_adapter_init() function gets called everytime without getting destructed in each cycle. Under void tcp_adapter_init() documentation they mention that esp_wifi_stop() should kill the lower level layers established by tcp_adapter_init(), but my compiler cant see that function.

I am acquiring sensor data using 3 sensor_tasks every 1 sec. I would like to spawn the modem_task to push all the data every 15 minutes and then shutdown modem & go back to sensor acquisition. please let me know if there is an example which would be helpful.

suda-morris commented 5 years ago

@9lash If I understand you correctly, why not put the tcpip_adapter_init outside your modem_cycle? The TCPIP adapter should be initialized only once globally.

9lash commented 5 years ago

@suda-morris Yes I tried putting tcpip_adapter_init fcuntion outside the modem_cycle. In this case, the modem does everything as expected on the first time but in the second iteration, while setting up the ppp mode, it changes the mode of the dte to MODEM_PPP_MODE successfully and then gets stuck inside the esp_dte->ppp = pppapi_pppos_create(&(esp_dte->pppif), pppos_low_level_output, on_ppp_status_changed, dte) function forever.

gardi-innovation commented 5 years ago

@9lash I'm facing the exact same issue that you are mentioning. I want to run the ppos client in a loop in such a way that the client can be turned off/on (in my case depending on wether or not I have WiFi access or not). But it only works the first time. The second time calls to pppapi_pppos_create() trigger the watchdog. Did you manage to create a new instance of the ppos client in a loop?

palpopite commented 5 years ago

I'm also having problems trying to reconnect via PPP. I'm using BG96 module too, but In my case, i want to reconnect after a signal loss. I think my implementation is very similar to @9lash , but instead of disconnecting by command, I'm trying to handle a disconnect after a signal lost. I'm also using Wifi, and after a disconnect in PPP, I'm unable to reconnect via Wifi, It connects to the AP but never gets and IP and the connection is closed, after that my wifi state machine returns to a scan mode, but esp wifi scan never ends.

palpopite commented 5 years ago

I made a workaround in my code by calling ppp functions directly, without the pppapi layer, from what I saw here: http://lists.openvehicles.com/pipermail/ovmsdev/2018-April/004622.html this may be not thread-safe however. So I'm successfully running PPP in a loop, but potentially not in a thread safe way. @9lash and @gardi-innovation , can you check if calling pppos_create directly, instead of pppapi_pppos_create for example, solves the problem for you?

fromeijn commented 5 years ago

got the same problem. after calling esp_modem_exit_ppp the esp_modem_setup_ppp seems to freeze. It seems like the code stops on the pppapi_pppos_create call, but no idea why. As if the PPP_PHASE_ESTABLISH is never called the second time. I tried to replace pppapi_pppos_create with pppos_create but with no luck so far

GVLEVA commented 5 years ago

I have the same problem as @fromeijn . Reconnecting does not work. @Torarqui and @gardi-innovation , have you found a solution in the meantime? Any update would be appreciated!

palpopite commented 5 years ago

@fromeijn @GVLEVA I'm using IDF release 3.3. Based on the pppos example, I made some changes to esp_modem.c and for me they made PPP run in loop without getting stuck:

The call sequence for a successful reconnection for me Is:

  1. Wait disconnect event
  2. Call esp_modem_exit_ppp
  3. Wait for MODEM_EVENT_PPP_STOP
  4. Reinit everything from zero, modem and PPP

From my understanding, making those changes makes the code not thread-safe from the tcpip point of view. pppapi were intended to be a thread-safe way to call tcpip functions from inside It's own task context, but when we call ppp functions directly, we are running then in the caller task context and that may lead to problems. I reckon there's some kind of semaphore_give missing in pppapi_close.

Can you try the changes I mentioned and see how it goes for you? Then we could try to pinpoint whats wrong inside the pppapi calls.

fromeijn commented 5 years ago

@Torarqui Thanks for your feedback, I did apply the changes you suggested and that worked! Thank you for that. Still I like to find out what is going wrong here, so we can fix it the right way. I would like to dive in to it, only don't actual have any time at this moment. Maybe next week. By the way I'm also using IDF V3.3 release.

fromeijn commented 5 years ago

mmm if i do ppp_close(esp_dte->ppp, 0), then it also doesn't work :neutral_face:

palpopite commented 5 years ago

Yeah I saw that too, but I have no clue on why that happens. For now I'm just using 1. 🤷🏻‍♂

iCarletto commented 4 years ago

Hi all, I'm succesfully using the pppos_client example (IDF master branch) with the Sequans Monarch LTE CAT M1/NB-IoT chipset of Pycom modules. The sequence of AT commands is quite different from the one in the examples SIM800/BG96, but I managed to make it work.

The problem is that the original example code crashes because the pattern detection does not work properly. To show what happens in response to an AT command I had to comment the receive callback inside esp_handle_uart_data which would otherwise result in a Guru Meditation Error:

I (465) dce_service: Sync [AT] UART pattern (2 bytes): 0d0a [\r\n] UART data (4 bytes): 4f4b0d0a [OK\r\n] UART pattern (0 bytes):

It seems that a spurious UART_DATA event is randomly emitted before UART_PATTERN_DET event. My workaround is to reject all the UART_DATA events when in MODEM_COMMAND_MODE. However, the unreliability of the uart pattern detection makes the code more complex, especially when handling the transitions between the working modes.

The modem is by default configured for a baudrate of 921600, but I tried also with lower ones. I also tried unsuccefully to change the default uart configurations parameters.

AxelLin commented 4 years ago

Hi @yavortomov what you explained is pretty right. BG96 may need more time to change working mode. I don't know why the original setting of 3000 ms also doesn't work for me now. But after I change it to a larger value (e.g. 5000 or 10000), BG96 worked again. Have a try.

Hi @suda-morris Just wondering why the MODEM_COMMAND_TIMEOUT_MODE_CHANGE is still 3000 in current master tree since you already confirm it does not work.

fetiennex commented 4 years ago

Hi all, I'm succesfully using the pppos_client example (IDF master branch) with the Sequans Monarch LTE CAT M1/NB-IoT chipset of Pycom modules. The sequence of AT commands is quite different from the one in the examples SIM800/BG96, but I managed to make it work.

The problem is that the original example code crashes because the pattern detection does not work properly. To show what happens in response to an AT command I had to comment the receive callback inside esp_handle_uart_data which would otherwise result in a Guru Meditation Error:

I (465) dce_service: Sync [AT] UART pattern (2 bytes): 0d0a [\r\n] UART data (4 bytes): 4f4b0d0a [OK\r\n] UART pattern (0 bytes):

It seems that a spurious UART_DATA event is randomly emitted before UART_PATTERN_DET event. My workaround is to reject all the UART_DATA events when in MODEM_COMMAND_MODE. However, the unreliability of the uart pattern detection makes the code more complex, especially when handling the transitions between the working modes.

The modem is by default configured for a baudrate of 921600, but I tried also with lower ones. I also tried unsuccefully to change the default uart configurations parameters.

Hi, I'm trying to run the pppos_client example with sim800 without crashing that first time. I think you described the problem well: the problem is a call to esp_handle_uart_data that needs ppp to be initialized (for pppos_input_tcpip) , which it is not yet set (correct me if i am wrong). Do you have an example of how you managed to do what you described ?

iCarletto commented 4 years ago

Hi @fetiennex, if you refer to the errors resulting from the not properly handled pattern recognition, it turned out to be a delay in between the bytes sent by the modem. I managed to solve it by setting properly the timeout with uart_set_rx_timeout. You can have a look to this issue https://github.com/espressif/esp-idf/issues/4707

fetiennex commented 4 years ago

Hello @iCarletto , thanks for your suggestion and sorry for my late response. I managed this issue with a boolean in the uart_event_task_entry which gets set to true when the modem is properly setup, inhibiting data from being handled too soon. You mentioned you managed to make it work on a FiPY with the Sequans Monarch LTE CAT M1/NB-IoT chipset, and I now have the same chipset on a slightly different pycom board (the gpy). Could you tell me how you did that ? I tried changing just the pin numbers as per the gpy documentation, but it seems it doesn't respond the first AT command

I (0) cpu_start: Starting scheduler on APP CPU.
I (440) uart: queue free spaces: 30
W (450) esp-modem: Rx Break
E (17440) esp-modem: esp_modem_dte_send_cmd(215): process command timeout
E (17440) dce_service: esp_modem_dce_sync(48): send command failed
E (17440) sim800: sim800_init(482): sync failed

Does it mean i set the uart_config wrong ? I noticed in your code you use a .source_clk field, but when i tried to compile it it told me this wasn't a valid field of the uart_config struct, also the espressif documentation doesn't mention it. Is there a reason you included this field ?

iCarletto commented 4 years ago

Hi @fetiennex , I actually just copied the the struct field .source_clk from the code in the ppos_example at line 408.

Regarding the use of the Sequans Monarch modem, I did test only the NB-IoT and not the LTE CAT-M1 feature. The code is 99% from the ppos_example, but the template in the example does not work out of the box with this modem and few key changes in the AT command sequence are required. The code I developed is freely available in the firmware folder of my Iot-AIO project repository, an IoT Adapter for Analog Industrial Transducers. You can just extract the LTE folder from the components.

If you don't receive a response to the AT command, most probably something is wrong in the configuration, either the pin or the baudrate. Here is a modified version of the uart_echo example I used to test the AT commands:

/* Uart Events Example

   This example code is in the Public Domain (or CC0 licensed, at your option.)

   Unless required by applicable law or agreed to in writing, this
   software is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR
   CONDITIONS OF ANY KIND, either express or implied.
*/
#include <stdio.h>
#include <string.h>
#include <stdlib.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_system.h"
#include "nvs_flash.h"
#include "driver/uart.h"
#include "driver/gpio.h"
#include "freertos/queue.h"
#include "esp_log.h"

/**
 * This is a example example which echos any data it receives on UART back to the sender.
 *
 * - port: UART2
 * - rx buffer: on
 * - tx buffer: off
 * - flow control: off
 *
 * This example has been tested on a 3 node RS485 Serial Bus
 * 
 */

// Note: UART2 default pins IO16, IO17 do not work on ESP32-WROVER module 
// because these pins connected to PSRAM
#define ECHO_TEST_TXD   (33)
#define ECHO_TEST_RXD   (34)

// RTS for RS485 Half-Duplex Mode manages DE/~RE
#define ECHO_TEST_RTS   (32)

// CTS is not used in RS485 Half-Duplex Mode
#define ECHO_TEST_CTS   (35)

#define BUF_SIZE        (1024)
#define BAUD_RATE       (921600)

// Read packet timeout
#define PACKET_READ_TICS        (100 / portTICK_RATE_MS)
#define ECHO_TASK_STACK_SIZE    (2048)
#define ECHO_TASK_PRIO          (10)

#define ECHO_TEST_FLOW_HW
static const char *TAG = "ECHO_APP";

// An example of echo test with hardware flow control on UART
static void uart_modem2esp(void *arg)
{
    int len = 0;
    // Allocate buffers for UART
    uint8_t* data = (uint8_t*) malloc(BUF_SIZE);

    while(1) {
        //Read data from UART
        len = uart_read_bytes(UART_NUM_1, data, BUF_SIZE, PACKET_READ_TICS);

        //Write data back to UART
        if (len > 0){
            // ESP_LOGI(TAG, "Received %d bytes: %.s", len, data);
            uart_write_bytes(UART_NUM_0, (char*)data, len);
        }
        vTaskDelay(100 / portTICK_PERIOD_MS);
    }
}

static void uart_esp2modem(void *arg)
{
    int len = 0;
    // Allocate buffers for UART
    uint8_t* data = (uint8_t*) malloc(BUF_SIZE);

    while(1) {
        //Read data from UART
        len = uart_read_bytes(UART_NUM_0, data, BUF_SIZE, PACKET_READ_TICS);

        //Write data back to UART
        if (len > 0)
            uart_write_bytes(UART_NUM_1, (char*)data, len);

        vTaskDelay(1000 / portTICK_PERIOD_MS);
    }
}

void app_main(void)
{
    uart_config_t uart0_config = {
        .baud_rate = 115200,
        .data_bits = UART_DATA_8_BITS,
        .parity = UART_PARITY_DISABLE,
        .stop_bits = UART_STOP_BITS_1,
        .flow_ctrl = UART_HW_FLOWCTRL_DISABLE,
        .rx_flow_ctrl_thresh = 122,
        .source_clk = UART_SCLK_APB,
    };

    uart_config_t uart1_config = {
        .baud_rate = 921600,
        .data_bits = UART_DATA_8_BITS,
        .parity = UART_PARITY_DISABLE,
        .stop_bits = UART_STOP_BITS_1,
#ifdef ECHO_TEST_FLOW_HW
        .flow_ctrl = UART_HW_FLOWCTRL_CTS_RTS,
#elif ECHO_TEST_FLOW_NONE
        .flow_ctrl = UART_HW_FLOWCTRL_DISABLE,
#endif
        .rx_flow_ctrl_thresh = 122,
        .source_clk = UART_SCLK_APB,
    };

    // Set UART log level
    esp_log_level_set(TAG, ESP_LOG_INFO);

    ESP_LOGI(TAG, "Start Modem application test and configure UART.");

    // Install UART driver (we don't need an event queue here)
    // In this example we don't even use a buffer for sending data.
    uart_driver_install(UART_NUM_0, BUF_SIZE * 2, 0, 0, NULL, 0);
    uart_driver_install(UART_NUM_1, BUF_SIZE * 2, 0, 0, NULL, 0);
    // Configure UART parameters
    uart_param_config(UART_NUM_0, &uart0_config);
    uart_param_config(UART_NUM_1, &uart1_config);

    ESP_LOGI(TAG, "UART set pins, mode and install driver.");
    // Set UART1 pins(TX: IO23, RX: I022, RTS: IO18, CTS: IO19)
    uart_set_pin(UART_NUM_0, UART_PIN_NO_CHANGE, UART_PIN_NO_CHANGE, UART_PIN_NO_CHANGE, UART_PIN_NO_CHANGE);
#ifdef ECHO_TEST_FLOW_HW
    uart_set_pin(UART_NUM_1, ECHO_TEST_TXD, ECHO_TEST_RXD, ECHO_TEST_RTS, ECHO_TEST_CTS);
#elif ECHO_TEST_FLOW_NONE
    uart_set_pin(UART_NUM_1, ECHO_TEST_TXD, ECHO_TEST_RXD, UART_PIN_NO_CHANGE, UART_PIN_NO_CHANGE);
    gpio_set_direction((gpio_num_t)ECHO_TEST_RTS, GPIO_MODE_OUTPUT);
    gpio_set_level((gpio_num_t)ECHO_TEST_RTS, 0);
#endif

    // Set regular UART mode
    uart_set_mode(UART_NUM_0, UART_MODE_UART);
    uart_set_mode(UART_NUM_1, UART_MODE_UART);

    //A uart read/write example without event queue;
    xTaskCreate(uart_modem2esp, "uart_modem2esp", ECHO_TASK_STACK_SIZE, NULL, ECHO_TASK_PRIO, NULL);
    xTaskCreate(uart_esp2modem, "uart_esp2modem", ECHO_TASK_STACK_SIZE, NULL, ECHO_TASK_PRIO, NULL);
}
fetiennex commented 4 years ago

@iCarletto thanks a lot for this code and the repo ! I will verify my pin definitions and baudrate too, but this is great help !

luzhichao1997606 commented 4 years ago
esp_err_t esp_modem_stop_ppp(modem_dte_t* dte)
{
    modem_dce_t* dce = dte->dce;
    MODEM_CHECK(dce, "DTE has not yet bind with DCE", err);
    esp_modem_dte_t* esp_dte = __containerof(dte, esp_modem_dte_t, parent);

    /* post PPP mode stopped event */
    esp_event_post_to(esp_dte->event_loop_hdl, ESP_MODEM_EVENT, ESP_MODEM_EVENT_PPP_STOP, NULL, 0, 0);
    /* Enter command mode */
    MODEM_CHECK(dte->change_mode(dte, MODEM_COMMAND_MODE) == ESP_OK, "enter command mode failed", timeout);
    /* Hang up */
    MODEM_CHECK(dce->hang_up(dce) == ESP_OK, "hang up failed", err);
    return ESP_OK;
timeout:
    ESP_LOGI("AT", "enter command mode failed !");
    vTaskDelay(pdMS_TO_TICKS(1000));
    dce->mode = MODEM_COMMAND_MODE;
    MODEM_CHECK(dce->hang_up(dce) == ESP_OK, "hang up failed", err);
    return ESP_OK;
err:
    return ESP_FAIL;
}

I solved it this way, and finally can mount the test for a long time

kannannair084 commented 4 years ago

@luzhichao1997606 you managed to solve this ppp init and deinit in cycle? could you share with me ? i copied the esp_modem_stop_pp and i am getting this error:

E (63433) esp-modem: esp_dte_handle_line(85): handle line failed W (63433) HTTP_CLIENT: Unknown line received: ~!E E (67283) esp-modem: esp_dte_handle_line(85): handle line failed W (67283) HTTP_CLIENT: Unknown line received: ~!E E (72483) esp-modem: esp_modem_dte_send_cmd(216): process command timeout E (72483) bg96: bg96_set_working_mode(343): send command failed E (72483) esp-modem: esp_modem_dte_change_mode(304): set new working mode:0 failed E (72493) esp-modem: esp_modem_stop_ppp(694): enter command mode failed

I (72493) AT: enter command mode failed ! E (75243) esp-modem: esp_dte_handle_line(85): handle line failed W (75243) HTTP_CLIENT: Unknown line received: ~!E

E (163503) esp-modem: esp_modem_dte_send_cmd(216): process command timeout E (163503) dce_service: esp_modem_dce_hang_up(121): send command failed E (163503) esp-modem: esp_modem_stop_ppp(702): hang up failed I (163513) NewEsp: i am failing here 3 E (164513) esp-modem: esp_modem_dte_send_cmd(216): process command timeout E (164513) bg96: bg96_power_down(377): send command failed I (164513) HTTP_CLIENT: Power down E (164523) esp-modem: esp_dte_handle_line(80): DTE has not yet bind with DCE E (164573) esp-modem: esp_dte_handle_line(80): DTE has not yet bind with DCE

PIYUSHGIRI2021 commented 3 years ago
  dte->send_cmd(dte, "ATD*99***1#\r", MODEM_COMMAND_TIMEOUT_MODE_CHANGE);
        vTaskDelay(pdMS_TO_TICKS(1000));

Hii , @yavortomov and @suda-morris ...i get a same issue ...check below error.. i stuck at here,i successfully connect MQTT but after that...pppos client crash...and module restart..automatically i follow whatever changes done by you in above quote..but did not get proper way..please let me know if any one know...how to resolve this error.. //*** espidf consol o/p **// I (8959) pppos_example: MQTT_EVENT_CONNECTED I (8959) pppos_example: sent subscribe successful, msg_id=52611 I (9559) pppos_example: MQTT_EVENT_SUBSCRIBED, msg_id=52611 I (9559) pppos_example: sent publish successful, msg_id=0 I (10459) pppos_example: MQTT_EVENT_DATA TOPIC=/topic/esp-pppos DATA=esp32-pppos I (11059) pppos_example: Modem PPP Stopped before sim800_handle_exit_data_mode after sim800_handle_exit_data_mode before uart_write after uart_write cmd =+++ I (11159) esp-netif_lwip-ppp: User interrupt W (12659) esp-modem: Pattern Queue Size too small UART_PATTERN_DET_event.type-->7 W (12759) esp-modem: Pattern Queue Size too small UART_PATTERNDETevent.type-->7 E (14059) esp-modem: esp_modem_dte_send_cmd(241): process command timeout E (14059) sim800: sim800_set_working_mode(299): send command failed E (14059) esp-modem: esp_modem_dte_change_mode(331): set new working mode:0 failed E (14069) esp-modem: esp_modem_stop_ppp(519): enter command mode failed ESP_ERROR_CHECK failed: esp_err_t 0xffffffff (ESP_FAIL) at 0x40083ecc 0x40083ecc: _esp_error_check_failed at C:/Users/Frank/Desktop/esp-idf/components/esp_common/src/esp_err.c:45

file: "../main/pppos_client_main.c" line 305 func: app_main expression: esp_modem_stop_ppp(dte)

abort() was called at PC 0x40083ecf on core 0 0x40083ecf: _esp_error_check_failed at C:/Users/Frank/Desktop/esp-idf/components/esp_common/src/esp_err.c:46

Backtrace:0x4008501f:0x3ffb56d0 0x400856bd:0x3ffb56f0 0x4008938a:0x3ffb5710 0x40083ecf:0x3ffb5780 0x400d59de:0x3ffb57a0 0x400d3f62:0x3ffb58d0 0x400856c5:0x3ffb5900

CamilaTurrieta commented 3 years ago

Hello everyone! I'm using the structure of pppos client example with the sim7600 and it have the same problem that all of you mentioned. The esp_modem_setup_ppp() is working only for the first time, but the code fails when I try another iteration.

I followed all the step like the example, but the code can't pass the next line esp_dte->ppp = ppp_create(&(esp_dte->pppif), pppos_low_level_output, on_ppp_status_changed, dte) . I will appreciate any help.

PIYUSHGIRI2021 commented 3 years ago

hello everyone i am using sim800 like quectelm95 module,i run many time and its work very fine but today whole day i try but its crash,check below logs and pls let me know how to resolve this issue...

after uart_write cmd =AT+CBC I (20527) pppos_example: Battery voltage: 3873 mV before uart_write after uart_write cmd =AT+CGDCONT=1,"IP","www" esp_modem.c____inside MODEM_PPP_MODE inside MODEM_PPP_MODE before uart_write after uart_write cmd =ATD*99# I (24527) pppos_example: Modem PPP Started Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.

Core 0 register dump: PC : 0x400d481a PS : 0x00060833 A0 : 0x800d4ba9 A1 : 0x3ffb5ff0 0x400d481a: find_task_in_twdt_list at C:/Users/Frank/Desktop/esp-idf/components/esp_common/src/task_wdt.c:102

A2 : 0x00000000 A3 : 0x3ffb6010 A4 : 0x00000014 A5 : 0x000000a5 A6 : 0x000000a5 A7 : 0x00060023 A8 : 0x00019700 A9 : 0x00000000 A10 : 0x3ffb6130 A11 : 0x00060823 A12 : 0x00060823 A13 : 0x00060823 A14 : 0x00000001 A15 : 0x0000001b SAR : 0x00000000 EXCCAUSE: 0x0000001c EXCVADDR: 0x00019700 LBEG : 0x00000000 LEND : 0x00000000 LCOUNT : 0x00000000

Backtrace:0x400d4817:0x3ffb5ff0 0x400d4ba6:0x3ffb6010 0x400d4bd3:0x3ffb6040 0x400d4c71:0x3ffb6060 0x40086051:0x3ffb6080 0x400856c5:0x3ffb60a0 0x400d4817: find_task_in_twdt_list at C:/Users/Frank/Desktop/esp-idf/components/esp_common/src/task_wdt.c:101

0x400d4ba6: esp_task_wdt_reset at C:/Users/Frank/Desktop/esp-idf/components/esp_common/src/task_wdt.c:324

0x400d4bd3: idle_hook_cb at C:/Users/Frank/Desktop/esp-idf/components/esp_common/src/task_wdt.c:88

0x400d4c71: esp_vApplicationIdleHook at C:/Users/Frank/Desktop/esp-idf/components/esp_common/src/freertos_hooks.c:51 (discriminator 1)

0x40086051: prvIdleTask at C:/Users/Frank/Desktop/esp-idf/components/freertos/tasks.c:3386 (discriminator 1)

0x400856c5: vPortTaskWrapper at C:/Users/Frank/Desktop/esp-idf/components/freertos/xtensa/port.c:143

ELF file SHA256: 75d841c28aafad82

Rebooting... ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x12 (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:2 load:0x3fff0030,len:4 load:0x3fff0034,len:7112 load:0x40078000,len:13212 load:0x40080400,len:4568 0x40080400: _init at ??:?

entry 0x400806f4 I (29) boot: ESP-IDF v4.2-dirty 2nd stage bootloader I (29) boot: compile time 18:18:33 I (29) boot: chip revision: 3 I (32) boot_comm: chip revision: 3, min. bootloader chip revision: 0 I (39) boot.esp32: SPI Speed : 40MHz I (44) boot.esp32: SPI Mode : DIO I (49) boot.esp32: SPI Flash Size : 2MB I (53) boot: Enabling RNG early entropy source... I (59) boot: Partition Table: I (62) boot: ## Label Usage Type ST Offset Length I (69) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (77) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (84) boot: 2 factory factory app 00 00 00010000 00100000 I (92) boot: End of partition table I (96) boot_comm: chip revision: 3, min. application chip revision: 0 I (103) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1960c (103948) map I (152) esp_image: segment 1: paddr=0x00029634 vaddr=0x3ffb0000 size=0x02170 ( 8560) load I (156) esp_image: segment 2: paddr=0x0002b7ac vaddr=0x40080000 size=0x00404 ( 1028) load 0x40080000: _WindowOverflow4 at C:/Users/Frank/Desktop/esp-idf/components/freertos/xtensa/xtensa_vectors.S:1730

I (159) esp_image: segment 3: paddr=0x0002bbb8 vaddr=0x40080404 size=0x04460 ( 17504) load I (175) esp_image: segment 4: paddr=0x00030020 vaddr=0x400d0020 size=0x6764c (423500) map 0x400d0020: _stext at ??:?

I (337) esp_image: segment 5: paddr=0x00097674 vaddr=0x40084864 size=0x06ee0 ( 28384) load 0x40084864: prvReceiveGeneric at C:/Users/Frank/Desktop/esp-idf/components/esp_ringbuf/ringbuf.c:766 (discriminator 1)

I (357) boot: Loaded app from partition at offset 0x10000 I (357) boot: Disabling RNG early entropy source... I (357) cpu_start: Pro cpu up. I (361) cpu_start: Application information: I (366) cpu_start: Project name: pppos_client I (371) cpu_start: App version: v4.2-dirty I (376) cpu_start: Compile time: Jun 4 2021 18:18:10 I (382) cpu_start: ELF file SHA256: 75d841c28aafad82... I (388) cpu_start: ESP-IDF: v4.2-dirty I (393) cpu_start: Starting app cpu, entry point is 0x400818e4 0x400818e4: call_start_cpu1 at C:/Users/Frank/Desktop/esp-idf/components/esp32/cpu_start.c:287

I (386) cpu_start: App cpu up. I (404) heap_init: Initializing. RAM available for dynamic allocation: I (411) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM I (417) heap_init: At 3FFB3A50 len 0002C5B0 (177 KiB): DRAM I (423) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM I (430) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM I (436) heap_init: At 4008B744 len 000148BC (82 KiB): IRAM I (442) cpu_start: Pro cpu start user code I (461) spi_flash: detected chip: generic I (461) spi_flash: flash io: dio W (461) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header. I (472) cpu_start: Starting scheduler on PRO CPU. I (0) cpu_start: Starting scheduler on APP CPU. baud_rate-->115200,data_bits-->3,parity-->0,stop_bits-->1,flow_control-->0 else : uart_port-->1,tx_io_num-->15,rx_io_num-->14,rts_io_num-->27,cts_io_num-->23 I (507) uart: queue free spaces: 30 before uart_write after uart_write cmd =AT E (1617) esp-modem: esp_dte_handle_line(91): handle line failed W (1617) pppos_example: Unknow line received: NO CARRIER

E (3017) esp-modem: esp_modem_dte_send_cmd(243): process command timeout E (3017) dce_service: esp_modem_dce_sync(49): send command failed E (3017) sim800: sim800_init(468): sync failed assertion "dce != NULL" failed: file "../main/pppos_client_main.c", line 269, function: app_main