Strange behaviour when integrating pppos example into bigger project (IDFGH-9470)

Hi, I have succesfuly tried the pppos example. I attach the code (with some modifications) below. Basically I have implemented the pwrkey and enable control and added a while() to retry on the failed commands.

I'm using IDF v4.4.4 and a SIM7080G with esp_modem to 0.1.26

#include <string.h>
#include "freertos/FreeRTOS.h"
#include "freertos/event_groups.h"
#include "esp_netif.h"
#include "esp_netif_ppp.h"
#include "esp_modem_api.h"
#include "esp_log.h"
#include "sdkconfig.h"
#include "driver/gpio.h"
#include "modem.h"
#include "esp_event.h"

#if defined(CONFIG_EXAMPLE_FLOW_CONTROL_NONE)
#define EXAMPLE_FLOW_CONTROL ESP_MODEM_FLOW_CONTROL_NONE
#elif defined(CONFIG_EXAMPLE_FLOW_CONTROL_SW)
#define EXAMPLE_FLOW_CONTROL ESP_MODEM_FLOW_CONTROL_SW
#elif defined(CONFIG_EXAMPLE_FLOW_CONTROL_HW)
#define EXAMPLE_FLOW_CONTROL ESP_MODEM_FLOW_CONTROL_HW
#endif

#define SIMCOM_PWR_KEY    GPIO_NUM_1 //GPIO_NUM_23
#define SIMCOM_EN_PWR     GPIO_NUM_45 //GPIO_NUM_26
#define MODEM_UART_TX_PIN GPIO_NUM_41 //12
#define MODEM_UART_RX_PIN GPIO_NUM_40 //25

static const char *TAG = "Modem";
static EventGroupHandle_t event_group = NULL;
static const int CONNECT_BIT = BIT0;
static const int GOT_DATA_BIT = BIT2;
static TaskHandle_t modem_task_handle;

static void on_ppp_changed(void *arg, esp_event_base_t event_base,
                           int32_t event_id, void *event_data)
{
    ESP_LOGI(TAG, "PPP state changed event %d", event_id);
    if (event_id == NETIF_PPP_ERRORUSER) {
        /* User interrupted event from esp-netif */
        esp_netif_t *netif = event_data;
        ESP_LOGI(TAG, "User interrupted event from netif:%p", netif);
    }
}

static void on_ip_event(void *arg, esp_event_base_t event_base,
                        int32_t event_id, void *event_data)
{
    ESP_LOGD(TAG, "IP event! %d", event_id);
    if (event_id == IP_EVENT_PPP_GOT_IP) {
        esp_netif_dns_info_t dns_info;

        ip_event_got_ip_t *event = (ip_event_got_ip_t *)event_data;
        esp_netif_t *netif = event->esp_netif;

        ESP_LOGI(TAG, "Modem Connect to PPP Server");
        ESP_LOGD(TAG, "~~~~~~~~~~~~~~");
        ESP_LOGD(TAG, "IP          : " IPSTR, IP2STR(&event->ip_info.ip));
        ESP_LOGD(TAG, "Netmask     : " IPSTR, IP2STR(&event->ip_info.netmask));
        ESP_LOGD(TAG, "Gateway     : " IPSTR, IP2STR(&event->ip_info.gw));
        esp_netif_get_dns_info(netif, 0, &dns_info);
        ESP_LOGD(TAG, "Name Server1: " IPSTR, IP2STR(&dns_info.ip.u_addr.ip4));
        esp_netif_get_dns_info(netif, 1, &dns_info);
        ESP_LOGD(TAG, "Name Server2: " IPSTR, IP2STR(&dns_info.ip.u_addr.ip4));
        ESP_LOGD(TAG, "~~~~~~~~~~~~~~");
        xEventGroupSetBits(event_group, CONNECT_BIT);

        ESP_LOGD(TAG, "GOT ip event!!!");
    } else if (event_id == IP_EVENT_PPP_LOST_IP) {
        ESP_LOGW(TAG, "Modem Disconnect from PPP Server");
    } else if (event_id == IP_EVENT_GOT_IP6) {
        ESP_LOGI(TAG, "GOT IPv6 event!");

        ip_event_got_ip6_t *event = (ip_event_got_ip6_t *)event_data;
        ESP_LOGI(TAG, "Got IPv6 address " IPV6STR, IPV62STR(event->ip6_info.ip));
    }
}

void start_modem(){
    xTaskCreate(modem_task, "modem task", 16384, NULL, 10, &modem_task_handle);
}

void modem_task(void* args)
{
    gpio_set_direction(SIMCOM_EN_PWR, GPIO_MODE_OUTPUT);
    gpio_set_direction(SIMCOM_PWR_KEY, GPIO_MODE_OUTPUT);
    gpio_set_level(SIMCOM_EN_PWR, 0);
    gpio_set_level(SIMCOM_PWR_KEY, 1);
    gpio_set_level(SIMCOM_PWR_KEY, 0);

    ESP_LOGI(TAG, "Modem Init");
    ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY = 0");
    ESP_LOGD(TAG, "Modem SIMCOM_EN_PWR = 0");

    vTaskDelay(pdMS_TO_TICKS(500));

    gpio_set_level(SIMCOM_EN_PWR, 1);

    ESP_LOGD(TAG, "Modem SIMCOM_EN_PWR = 1");

    vTaskDelay(pdMS_TO_TICKS(500));

    //vTaskDelay(pdMS_TO_TICKS(15000));

    //gpio_set_level(SIMCOM_EN_PWR, 0);
    //vTaskDelay(pdMS_TO_TICKS(1000));

    //gpio_set_level(SIMCOM_EN_PWR, 1);

    ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY = 1");

    gpio_set_level(SIMCOM_PWR_KEY, 1);

    vTaskDelay(pdMS_TO_TICKS(20000));

    ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY = 0");

    gpio_set_level(SIMCOM_PWR_KEY, 0);

    vTaskDelay(pdMS_TO_TICKS(10000));

    /* Init and register system/core components */
    ESP_ERROR_CHECK(esp_netif_init());
    ESP_ERROR_CHECK(esp_event_loop_create_default());
    ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, &on_ip_event, NULL));
    ESP_ERROR_CHECK(esp_event_handler_register(NETIF_PPP_STATUS, ESP_EVENT_ANY_ID, &on_ppp_changed, NULL));

    /* Configure the PPP netif */
    esp_modem_dce_config_t dce_config = ESP_MODEM_DCE_DEFAULT_CONFIG(CONFIG_EXAMPLE_MODEM_PPP_APN);
    esp_netif_config_t netif_ppp_config = ESP_NETIF_DEFAULT_PPP();
    esp_netif_t *esp_netif = esp_netif_new(&netif_ppp_config);
    assert(esp_netif);

    event_group = xEventGroupCreate();

    /* Configure the DTE */

    esp_modem_dte_config_t dte_config = ESP_MODEM_DTE_DEFAULT_CONFIG();
    /* setup UART specific configuration based on kconfig options */
    dte_config.uart_config.tx_io_num = MODEM_UART_TX_PIN;
    dte_config.uart_config.rx_io_num = MODEM_UART_RX_PIN;
    dte_config.uart_config.rts_io_num = CONFIG_EXAMPLE_MODEM_UART_RTS_PIN;
    dte_config.uart_config.cts_io_num = CONFIG_EXAMPLE_MODEM_UART_CTS_PIN;
    dte_config.uart_config.flow_control = EXAMPLE_FLOW_CONTROL;
    dte_config.uart_config.rx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE;
    dte_config.uart_config.tx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_TX_BUFFER_SIZE;
    dte_config.uart_config.event_queue_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_QUEUE_SIZE;
    dte_config.task_stack_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_STACK_SIZE;
    dte_config.task_priority = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_PRIORITY;
    dte_config.dte_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE / 2;

    ESP_LOGI(TAG, "Initializing esp_modem for the SIM7070 module...");
    esp_modem_dce_t *dce = esp_modem_new_dev(ESP_MODEM_DCE_SIM7070, &dte_config, &dce_config, esp_netif);

    assert(dce);
    if (dte_config.uart_config.flow_control == ESP_MODEM_FLOW_CONTROL_HW) {
        esp_err_t err = esp_modem_set_flow_control(dce, 2, 2);  //2/2 means HW Flow Control.
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "Failed to set the set_flow_control mode");
            return;
        }
        ESP_LOGI(TAG, "HW set_flow_control OK");
    }

    xEventGroupClearBits(event_group, CONNECT_BIT | GOT_DATA_BIT);

    /* Run the modem demo app */
#if CONFIG_EXAMPLE_NEED_SIM_PIN == 1
    // check if PIN needed
    bool pin_ok = false;
    if (esp_modem_read_pin(dce, &pin_ok) == ESP_OK && pin_ok == false) {
        if (esp_modem_set_pin(dce, CONFIG_EXAMPLE_SIM_PIN) == ESP_OK) {
            vTaskDelay(pdMS_TO_TICKS(1000));
        } else {
            abort();
        }
    }
#endif

    esp_err_t err;
    int rssi, ber;
    while (true)
    {
        err = esp_modem_get_signal_quality(dce, &rssi, &ber);
        if (err != ESP_OK) {
            ESP_LOGW(TAG, "esp_modem_get_signal_quality failed with %d %s", err, esp_err_to_name(err));
        }
        else
            break;
    }
    ESP_LOGI(TAG, "Signal quality: rssi=%d, ber=%d", rssi, ber);

    while (true)
    {
        err = esp_modem_set_mode(dce, ESP_MODEM_MODE_DATA);
        if (err != ESP_OK) {
            ESP_LOGW(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with %d", err);
            vTaskDelay(pdMS_TO_TICKS(500));
        }
        else{
            ESP_LOGD(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_DATA) success");
            break;
        }
    }

    EventBits_t res;
    /* Wait for IP address */
    ESP_LOGI(TAG, "Waiting for IP address");
    res= xEventGroupWaitBits(event_group, CONNECT_BIT, pdFALSE, pdFALSE, portMAX_DELAY);

    if(res & CONNECT_BIT){
        ESP_LOGI(TAG, "Connected!");
    }
    else{
        ESP_LOGE(TAG, "Timeout!");
    }

}

It works well:

I (782) Modem: Modem Init I (31792) Modem: Initializing esp_modem for the SIM7070 module... I (31792) uart: queue free spaces: 30 W (32292) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (32792) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (33292) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (33792) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (34292) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT I (34292) Modem: Signal quality: rssi=99, ber=99 I (34692) Modem: Waiting for IP address I (40732) esp-netif_lwip-ppp: Connected I (40732) esp-netif_lwip-ppp: Name Server1: 85.62.229.135 I (40732) esp-netif_lwip-ppp: Name Server2: 85.62.229.136 I (40742) Modem: Modem Connect to PPP Server I (40742) Modem: Connected!

And here the data being exchanged via UART (using a logic analyzer):

Now with the odd part. I have copied the entire file into my project to enable LTE connection. You can see how the retries increase a lot and the second part (where the MODE DATA is set) never works:

I (05:55:36.705) Modem: Initializing esp_modem for the SIM7070 module... I (05:55:36.706) uart: ESP_INTR_FLAG_IRAM flag not set while CONFIG_UART_ISR_IN_IRAM is enabled, flag updated I (05:55:36.712) uart: queue free spaces: 30 W (05:55:37.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:37.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:38.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:39.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:39.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:40.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:40.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:41.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:42.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:42.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:43.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:43.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:44.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:45.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:45.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:46.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:46.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:47.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:48.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:48.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:49.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:49.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:50.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:51.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:51.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:52.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:52.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:53.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:54.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:54.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:55.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:55.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:56.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:57.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:57.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:58.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:58.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:55:59.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:00.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:00.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:01.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:01.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:02.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:03.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:03.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:04.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:04.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:05.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:06.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:06.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:07.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:07.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:08.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:09.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:09.618) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:10.218) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:10.818) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:11.418) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (05:56:12.018) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT I (05:56:12.122) Modem: Signal quality: rssi=23, ber=99 W (05:56:12.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:13.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:14.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:15.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:16.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:17.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:18.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:19.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:20.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:21.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:22.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:23.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:24.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:25.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:26.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:27.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:28.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (05:56:29.722) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1

And analyzing the UART data I can understand why the code has to retry so much. What I don't understand is why it is different if the code is the same: And it just hangs there, the call to esp_modem_set_mode(dce, ESP_MODEM_MODE_DATA); blocks the execution and no more data is sent (the watchdog doesn't trigger).

I know it's kind of a long shot because the problem arises when I join my project with the example. But I'm out of ideas on what could be happening 😢

To try to narrow down the error I have tried the following:

In my project I have disabled everything and only the modem code is executed. So the app_main() looks like this:

extern "C" void app_main() {
  ESP_ERROR_CHECK(esp_event_loop_create_default());
  start_modem();
  while (true)
  {
      vTaskDelay(pdMS_TO_TICKS(5000));
  };
}

And I'm still getting the same results. So it doesn't seem like my code is affecting the modem. It has to be something related to configuration but I have already checked that all the configurations are equal on both example and my project.

Looking at the UART data, it seems like you're mixing the COMMAND and DATA mode. The last screenshot clearly shows that the ESP32 is sending PPPoS data (as well as the commands), but the modem is still in command mode. It looks like the states between the device and the ESP32 got somehow out of sync. Switching between command and data modes has always been a little tricky and depend on the specific device (even its FW version). Which modem are you using? General idea (since you're already driving PWR and reset pins), is to simply reset the device to get it in sync, starting in the AT command mode.

Oh, sorry, have missed it was SIM7080G. I don't have this device with me so I cannot test it, but I'd suggest trying a simple application with a while(1) {} loop with just switching modes between AT and PPP. Does it work reliably?

As said above, switching modes always depends on the specific device (a little bit) and this part of the modem library has been developed, tuned and tested mainly for devices like BG96 and SIM7600, SIM800. It is possible that SIM7080G still might not switch between modes reliably enough.

Looking at the UART data, it seems like you're mixing the COMMAND and DATA mode. The last screenshot clearly shows that the ESP32 is sending PPPoS data (as well as the commands), but the modem is still in command mode. It looks like the states between the device and the ESP32 got somehow out of sync. Switching between command and data modes has always been a little tricky and depend on the specific device (even its FW version). Which modem are you using? General idea (since you're already driving PWR and reset pins), is to simply reset the device to get it in sync, starting in the AT command mode.

Hi @david-cermak and thanks for the blazing-fast response.

I'm using the SIM7080G.

But I still don't understand how using the same code (on the example and my project) yields different results.

Oh, sorry, have missed it was SIM7080G. I don't have this device with me so I cannot test it, but I'd suggest trying a simple application with a while(1) {} loop with just switching modes between AT and PPP. Does it work reliably?

As said above, switching modes always depends on the specific device (a little bit) and this part of the modem library has been developed, tuned and tested mainly for devices like BG96 and SIM7600, SIM800. It is possible that SIM7080G still might not switch between modes reliably enough.

This is the code I'm trying:

    gpio_set_direction(SIMCOM_EN_PWR, GPIO_MODE_OUTPUT);
    gpio_set_direction(SIMCOM_PWR_KEY, GPIO_MODE_OUTPUT);
    gpio_set_level(SIMCOM_EN_PWR, 0);
    gpio_set_level(SIMCOM_PWR_KEY, 1);
    gpio_set_level(SIMCOM_PWR_KEY, 0);

    ESP_LOGI(TAG, "Modem Init");
    ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY = 0");
    ESP_LOGD(TAG, "Modem SIMCOM_EN_PWR = 0");

    vTaskDelay(pdMS_TO_TICKS(500));

    gpio_set_level(SIMCOM_EN_PWR, 1);

    ESP_LOGD(TAG, "Modem SIMCOM_EN_PWR = 1");

    vTaskDelay(pdMS_TO_TICKS(500));

    //vTaskDelay(pdMS_TO_TICKS(15000));

    //gpio_set_level(SIMCOM_EN_PWR, 0);
    //vTaskDelay(pdMS_TO_TICKS(1000));

    //gpio_set_level(SIMCOM_EN_PWR, 1);

    ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY = 1");

    gpio_set_level(SIMCOM_PWR_KEY, 1);

    vTaskDelay(pdMS_TO_TICKS(20000));

    ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY = 0");

    gpio_set_level(SIMCOM_PWR_KEY, 0);

    vTaskDelay(pdMS_TO_TICKS(10000));

    /* Init and register system/core components */
    ESP_ERROR_CHECK(esp_netif_init());
    //ESP_ERROR_CHECK(esp_event_loop_create_default());
    ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, &on_ip_event, NULL));
    ESP_ERROR_CHECK(esp_event_handler_register(NETIF_PPP_STATUS, ESP_EVENT_ANY_ID, &on_ppp_changed, NULL));

    /* Configure the PPP netif */
    esp_modem_dce_config_t dce_config = ESP_MODEM_DCE_DEFAULT_CONFIG(CONFIG_MODEM_PPP_APN);
    esp_netif_config_t netif_ppp_config = ESP_NETIF_DEFAULT_PPP();
    esp_netif_t *esp_netif = esp_netif_new(&netif_ppp_config);
    assert(esp_netif);

    event_group = xEventGroupCreate();

    /* Configure the DTE */

    esp_modem_dte_config_t dte_config = ESP_MODEM_DTE_DEFAULT_CONFIG();
    /* setup UART specific configuration based on kconfig options */
    dte_config.uart_config.tx_io_num = MODEM_UART_TX_PIN;
    dte_config.uart_config.rx_io_num = MODEM_UART_RX_PIN;
    dte_config.uart_config.rts_io_num = CONFIG_EXAMPLE_MODEM_UART_RTS_PIN;
    dte_config.uart_config.cts_io_num = CONFIG_EXAMPLE_MODEM_UART_CTS_PIN;
    dte_config.uart_config.flow_control = EXAMPLE_FLOW_CONTROL;
    dte_config.uart_config.rx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE;
    dte_config.uart_config.tx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_TX_BUFFER_SIZE;
    dte_config.uart_config.event_queue_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_QUEUE_SIZE;
    dte_config.task_stack_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_STACK_SIZE;
    dte_config.task_priority = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_PRIORITY;
    dte_config.dte_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE / 2;

    ESP_LOGI(TAG, "Initializing esp_modem for the SIM7070 module...");
    esp_modem_dce_t *dce = esp_modem_new_dev(ESP_MODEM_DCE_SIM7070, &dte_config, &dce_config, esp_netif);

    assert(dce);
    if (dte_config.uart_config.flow_control == ESP_MODEM_FLOW_CONTROL_HW) {
        esp_err_t err = esp_modem_set_flow_control(dce, 2, 2);  //2/2 means HW Flow Control.
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "Failed to set the set_flow_control mode");
            return;
        }
        ESP_LOGI(TAG, "HW set_flow_control OK");
    }

    xEventGroupClearBits(event_group, CONNECT_BIT | GOT_DATA_BIT);

    /* Run the modem demo app */
#if CONFIG_EXAMPLE_NEED_SIM_PIN == 1
    // check if PIN needed
    bool pin_ok = false;
    if (esp_modem_read_pin(dce, &pin_ok) == ESP_OK && pin_ok == false) {
        if (esp_modem_set_pin(dce, CONFIG_EXAMPLE_SIM_PIN) == ESP_OK) {
            vTaskDelay(pdMS_TO_TICKS(1000));
        } else {
            abort();
        }
    }
#endif

    esp_err_t err;

    while(true){
        while (true)
        {
            err = esp_modem_set_mode(dce, ESP_MODEM_MODE_COMMAND);
            if (err != ESP_OK) {
                ESP_LOGW(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with %d", err);
                vTaskDelay(pdMS_TO_TICKS(500));
            }
            else{
                ESP_LOGD(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) success");
                break;
            }
        }

        while (true)
        {
            err = esp_modem_set_mode(dce, ESP_MODEM_MODE_DATA);
            if (err != ESP_OK) {
                ESP_LOGW(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with %d", err);
                vTaskDelay(pdMS_TO_TICKS(500));
            }
            else{
                ESP_LOGD(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_DATA) success");
                break;
            }
        }
    }

UART output:

D (07:10:29.142) Modem: Modem SIMCOM_PWR_KEY = 0 I (07:10:39.144) Modem: Initializing esp_modem for the SIM7070 module... I (07:10:39.144) uart: ESP_INTR_FLAG_IRAM flag not set while CONFIG_UART_ISR_IN_IRAM is enabled, flag updated I (07:10:39.151) uart: queue free spaces: 30 I (07:10:39.157) esp-netif_lwip-ppp: User interrupt I (07:10:39.162) Modem: PPP state changed event 5 I (07:10:39.167) Modem: User interrupted event from netif:0x3fcbc5b4 I (07:10:39.174) esp_modem_netif: PPP state changed event 5 W (07:11:04.680) Modem: esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with -1 I (07:11:05.180) esp-netif_lwip-ppp: User interrupt I (07:11:05.180) Modem: PPP state changed event 5 I (07:11:05.181) Modem: User interrupted event from netif:0x3fcbc5b4 I (07:11:05.187) esp_modem_netif: PPP state changed event 5 W (07:11:30.693) Modem: esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with -1 I (07:11:31.193) esp-netif_lwip-ppp: User interrupt I (07:11:31.193) Modem: PPP state changed event 5 I (07:11:31.194) Modem: User interrupted event from netif:0x3fcbc64c I (07:11:31.200) esp_modem_netif: PPP state changed event 5 W (07:11:56.706) Modem: esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with -1 I (07:11:57.206) esp-netif_lwip-ppp: User interrupt I (07:11:57.207) Modem: PPP state changed event 5 I (07:11:57.207) Modem: User interrupted event from netif:0x3fcbc64c I (07:11:57.213) esp_modem_netif: PPP state changed event 5 W (07:12:22.719) Modem: esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with -1 I (07:12:23.219) esp-netif_lwip-ppp: User interrupt I (07:12:23.220) Modem: PPP state changed event 5 I (07:12:23.220) Modem: User interrupted event from netif:0x3fcbc64c I (07:12:23.226) esp_modem_netif: PPP state changed event 5 W (07:12:48.732) Modem: esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with -1 I (07:12:49.232) esp-netif_lwip-ppp: User interrupt I (07:12:49.233) Modem: PPP state changed event 5 I (07:12:49.233) Modem: User interrupted event from netif:0x3fcbc64c I (07:12:49.239) esp_modem_netif: PPP state changed event 5

Using logic analyzer:

It seems that at some point it works, but it takes forever:

W (07:23:39.057) Modem: esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with -1 I (07:23:39.557) esp-netif_lwip-ppp: User interrupt I (07:23:39.558) Modem: PPP state changed event 5 I (07:23:39.558) Modem: User interrupted event from netif:0x3fcbc740 I (07:23:39.564) esp_modem_netif: PPP state changed event 5 W (07:24:05.070) Modem: esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with -1 I (07:24:05.570) esp-netif_lwip-ppp: User interrupt I (07:24:05.571) Modem: PPP state changed event 5 I (07:24:05.571) Modem: User interrupted event from netif:0x3fcbc740 I (07:24:05.577) esp_modem_netif: PPP state changed event 5 W (07:24:31.083) Modem: esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with -1 I (07:24:31.583) esp-netif_lwip-ppp: User interrupt I (07:24:31.584) Modem: PPP state changed event 5 I (07:24:31.584) Modem: User interrupted event from netif:0x3fcbc740 I (07:24:31.590) esp_modem_netif: PPP state changed event 5 D (07:24:55.698) Modem: esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) success W (07:24:56.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:24:57.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:24:58.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:24:59.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:00.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:01.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:02.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:03.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:04.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:05.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:06.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:07.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:08.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:09.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:10.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1 W (07:25:11.298) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with -1

Okay, thanks for testing. It seems the mode switching doesn't really work for SIM7080. I'll buy the device and fix the issue, but that will take some time.

In the meantime (if you like), you can experiment with the current code yourself: The retry mechanism is implemented here:

https://github.com/espressif/esp-protocols/blob/3bf0511938df49b739407c6575adf49990583b40/components/esp_modem/include/cxx_include/esp_modem_dce_module.hpp#L74-L84

Have checked the spec of SIM7080 and the data exit shall be the same as for other devices:

To prevent the +++ escape sequence from being misinterpreted as data, it should comply to following sequence:
1) No characters entered for T1 time (1 second)
2) "+++" characters entered with no characters in between (1 second)
3) No characters entered for T1 timer (1 second)
Switch to Command mode, otherwise go to step 1.

Also, it might be possible that this device exits the PPP mode seamlessly, but the AT needs to be established (again) by means of the abovementioned sequence. To check that, you can apply the following patch to see if it helps.

diff --git a/components/esp_modem/src/esp_modem_dce.cpp b/components/esp_modem/src/esp_modem_dce.cpp
index afd41ff..eab35c5 100644
--- a/components/esp_modem/src/esp_modem_dce.cpp
+++ b/components/esp_modem/src/esp_modem_dce.cpp
@@ -43,6 +43,9 @@ static bool exit_data(DTE &dte, ModuleIf &device, Netif &netif)
             return false;
         }
     }
+    if (!device.set_mode(modem_mode::COMMAND_MODE)) {
+        return false;
+    }
     dte.set_read_cb(nullptr);
     if (!dte.set_mode(modem_mode::COMMAND_MODE)) {

PS: Switching between data and command modes has never been very robust (also by definition, just looking at the specification of different modems), that's why some people prefer using CMUX mode.

Okay, thanks for testing. It seems the mode switching doesn't really work for SIM7080. I'll buy the device and fix the issue, but that will take some time.

In the meantime (if you like), you can experiment with the current code yourself: The retry mechanism is implemented here:

https://github.com/espressif/esp-protocols/blob/3bf0511938df49b739407c6575adf49990583b40/components/esp_modem/include/cxx_include/esp_modem_dce_module.hpp#L74-L84

Have checked the spec of SIM7080 and the data exit shall be the same as for other devices:
To prevent the +++ escape sequence from being misinterpreted as data, it should comply to following sequence:
1) No characters entered for T1 time (1 second)
2) "+++" characters entered with no characters in between (1 second)
3) No characters entered for T1 timer (1 second)
Switch to Command mode, otherwise go to step 1.
Also, it might be possible that this device exits the PPP mode seamlessly, but the AT needs to be established (again) by means of the abovementioned sequence. To check that, you can apply the following patch to see if it helps.
diff --git a/components/esp_modem/src/esp_modem_dce.cpp b/components/esp_modem/src/esp_modem_dce.cpp
index afd41ff..eab35c5 100644
--- a/components/esp_modem/src/esp_modem_dce.cpp
+++ b/components/esp_modem/src/esp_modem_dce.cpp
@@ -43,6 +43,9 @@ static bool exit_data(DTE &dte, ModuleIf &device, Netif &netif)
             return false;
         }
     }
+    if (!device.set_mode(modem_mode::COMMAND_MODE)) {
+        return false;
+    }
     dte.set_read_cb(nullptr);
     if (!dte.set_mode(modem_mode::COMMAND_MODE)) {
PS: Switching between data and command modes has never been very robust (also by definition, just looking at the specification of different modems), that's why some people prefer using CMUX mode.

Thank you, we really apreciate it. If I can do anything to speed up the process don't hesitate to ask.

I have tried the quick fix you have mentioned and it doesn't seem to be improving (with ESP_MODEM_MODE_DATA).

I have also tried setting up CMUX mode with the same result, it seems like the modem doesn't listen to the commands being sent by the ESP32.

However, it is curious how if you leave it for a long time and retry a little at some point it works:

I (09:00:40.177) esp-netif_lwip-ppp: Connected I (09:00:40.177) esp-netif_lwip-ppp: Name Server1: 85.62.229.135 I (09:00:40.178) esp-netif_lwip-ppp: Name Server2: 85.62.229.136 D (09:00:40.185) Modem: IP event! 6 I (09:00:40.188) Modem: Modem Connect to PPP Server D (09:00:40.194) Modem: ~~~~~~ D (09:00:40.197) Modem: IP : 10.3.177.121 D (09:00:40.202) Modem: Netmask : 255.255.255.255 D (09:00:40.207) Modem: Gateway : 10.64.64.64 D (09:00:40.212) Modem: Name Server1: 85.62.229.135 D (09:00:40.217) Modem: Name Server2: 85.62.229.136 D (09:00:40.222) Modem: ~~~~~~ D (09:00:40.226) Modem: GOT ip event!!! I (09:00:40.226) Modem: Connected!

But it's not very reasuring taking into account that we are planing on producing 5000 devices with this technology.

However, I still don't understand how the example works decent enough and when I integrate it in my project it doesn't work at all (even if I disable everything, leaving it essentially as the example project).

@david-cermak sorry for the bombarding but I've found something new:

As I've said the example works fine (I have to retry on getting the signal quality but we will call it good enough):

I (786) Modem: Modem Init I (31796) Modem: Initializing esp_modem for the SIM7070 module... I (31796) uart: queue free spaces: 30 W (32296) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (32796) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (33296) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (33796) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (34296) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT I (34296) Modem: Signal quality: rssi=99, ber=99 I (34696) Modem: Waiting for IP address I (40736) esp-netif_lwip-ppp: Connected I (40736) esp-netif_lwip-ppp: Name Server1: 85.62.229.135 I (40736) esp-netif_lwip-ppp: Name Server2: 85.62.229.136 I (40746) Modem: Modem Connect to PPP Server I (40746) Modem: Connected!

This got me wondering on what's the difference between my project and the example code. So I copied the sdkconfig.defaults file from my project into the example project (which we have already established that "works"). And wouldn't you know it, it doesn't work :)

And here I come to my beloved sdkconfig.defaults. This is the one from the example:

Override some defaults to enable PPP

CONFIG_LWIP_PPP_SUPPORT=y CONFIG_LWIP_PPP_NOTIFY_PHASE_SUPPORT=y CONFIG_LWIP_PPP_PAP_SUPPORT=y CONFIG_LWIP_TCPIP_TASK_STACK_SIZE=4096 CONFIG_LWIP_PPP_ENABLE_IPV6=n

This is the one from my project (where I'm trying to integrate the code from the modem example):

CONFIG_BOOTLOADER_SKIP_VALIDATE_IN_DEEP_SLEEP=y CONFIG_ESPTOOLPY_FLASHMODE_QIO=y CONFIG_ESPTOOLPY_FLASHSIZE_16MB=y CONFIG_PARTITION_TABLE_CUSTOM=y CONFIG_PARTITION_TABLE_CUSTOM_FILENAME="partition_table/partition_table.csv" CONFIG_BT_ENABLED=y CONFIG_BT_CTRL_MODEM_SLEEP=y CONFIG_BT_CTRL_LPCLK_SEL_EXT_32K_XTAL=y CONFIG_BT_ALLOCATION_FROM_SPIRAM_FIRST=y CONFIG_BT_BLE_42_FEATURES_SUPPORTED=y CONFIG_UART_ISR_IN_IRAM=y CONFIG_ESP32S3_SPIRAM_SUPPORT=y CONFIG_SPIRAM_TRY_ALLOCATE_WIFI_LWIP=y CONFIG_ESP32S3_RTC_CLK_SRC_EXT_CRYS=y CONFIG_ESP32S3_RTC_CLK_CAL_CYCLES=1024 CONFIG_PM_ENABLE=y CONFIG_PM_DFS_INIT_AUTO=y CONFIG_PM_PROFILING=y CONFIG_ESP_SYSTEM_EVENT_TASK_STACK_SIZE=4096 CONFIG_ESP32_WIFI_STATIC_RX_BUFFER_NUM=10 CONFIG_ESP32_WIFI_DYNAMIC_RX_BUFFER_NUM=64 CONFIG_ESP32_WIFI_TX_BA_WIN=32 CONFIG_ESP32_WIFI_RX_BA_WIN=6 CONFIG_FREERTOS_HZ=1000 CONFIG_FREERTOS_USE_TICKLESS_IDLE=y CONFIG_LOG_MAXIMUM_LEVEL_VERBOSE=y CONFIG_LOG_TIMESTAMP_SOURCE_SYSTEM=y CONFIG_LWIP_IRAM_OPTIMIZATION=y CONFIG_LWIP_TCPIP_RECVMBOX_SIZE=64 CONFIG_LWIP_TCP_SND_BUF_DEFAULT=2880 CONFIG_LWIP_TCP_WND_DEFAULT=65534 CONFIG_LWIP_TCP_RECVMBOX_SIZE=64 CONFIG_LWIP_UDP_RECVMBOX_SIZE=64 CONFIG_LWIP_PPP_ENABLE_IPV6=n > CONFIG_LWIP_TCPIP_TASK_STACK_SIZE=4096 > CONFIG_LWIP_PPP_SUPPORT=y > CONFIG_LWIP_PPP_NOTIFY_PHASE_SUPPORT=y > CONFIG_LWIP_PPP_PAP_SUPPORT=y CONFIG_MBEDTLS_CUSTOM_CERTIFICATE_BUNDLE=y CONFIG_MBEDTLS_CUSTOM_CERTIFICATE_BUNDLE_PATH="server_certs" CONFIG_WIFI_PROV_BLE_FORCE_ENCRYPTION=y CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_PRIORITY=22 CONFIG_PN7150_IRQ_PIN=5 CONFIG_PN7150_RESET_PIN=38 CONFIG_REED_OPEN_LOCK_PIN=6 CONFIG_REED_CLOSE_LOCK_PIN=7 CONFIG_REED_DOOR_OPEN_PIN=8 CONFIG_I2CDEV_SDA_PIN=14 CONFIG_I2CDEV_SCL_PIN=21 CONFIG_BUZZER_GPIO_NUMBER=19 CONFIG_CAP_INT_GPIO_NUMBER=10 CONFIG_RTC_INT_GPIO_NUMBER=2 CONFIG_DRV8833_ENABLE_PIN=46 CONFIG_DRV8833_IN1=47 CONFIG_DRV8833_IN2=48 CONFIG_LSM6DSO32_INT_PIN=17 CONFIG_ESP_INTERNET_CONNECTION_METHOD_LTE=y CONFIG_ESP_WIFI_SSID="dxfgxdfg" CONFIG_ESP_WIFI_PASSWORD="adeaer" CONFIG_ESP_MAXIMUM_RETRY=3

As you can see the parameters in the example are also defined in my project. So the only thing left is that there is some configuration that is causing trouble on the modem. Can you see any parameter that could cause trouble?

So know with the "defualt" sdkconfig.defaults file the example works and with my (the one just above) sdkconfig.defaults file it doesn't. So I'm starting to thing the base issue is not where we think it was.

And with that I finish for today, have a good weekend :)

Thanks for the additional pointers! It seems like these two configs may cause the UART layers not to respond properly.

CONFIG_PM_ENABLE=y
CONFIG_PM_DFS_INIT_AUTO=y

Could you please check if disabling the DFS feature fixes the issue?

I'm not sure at this moment, what could be the exact problem. I recall we had some trouble with REF_TICK clock source in the past, but need to look at it again.

Would this change fix the issue for you?

diff --git a/components/esp_modem/examples/pppos_client/main/pppos_client_main.c b/components/esp_modem/examples/pppos_client/main/pppos_client_main.c
index b073847..93dcaaf 100644
--- a/components/esp_modem/examples/pppos_client/main/pppos_client_main.c
+++ b/components/esp_modem/examples/pppos_client/main/pppos_client_main.c
@@ -173,6 +173,7 @@ void app_main(void)
     dte_config.uart_config.rx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE;
     dte_config.uart_config.tx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_TX_BUFFER_SIZE;
     dte_config.uart_config.event_queue_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_QUEUE_SIZE;
+    dte_config.uart_config.source_clk = UART_SCLK_REF_TICK;
     dte_config.task_stack_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_STACK_SIZE;
     dte_config.task_priority = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_PRIORITY;
     dte_config.dte_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE / 2;

Would this change fix the issue for you?

diff --git a/components/esp_modem/examples/pppos_client/main/pppos_client_main.c b/components/esp_modem/examples/pppos_client/main/pppos_client_main.c
index b073847..93dcaaf 100644
--- a/components/esp_modem/examples/pppos_client/main/pppos_client_main.c
+++ b/components/esp_modem/examples/pppos_client/main/pppos_client_main.c
@@ -173,6 +173,7 @@ void app_main(void)
     dte_config.uart_config.rx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE;
     dte_config.uart_config.tx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_TX_BUFFER_SIZE;
     dte_config.uart_config.event_queue_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_QUEUE_SIZE;
+    dte_config.uart_config.source_clk = UART_SCLK_REF_TICK;
     dte_config.task_stack_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_STACK_SIZE;
     dte_config.task_priority = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_PRIORITY;
     dte_config.dte_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE / 2;

Hi, UART_SCLK_REF_TICK is not supported (I'm using an ESP32-S3 with SPIRAM) I have changed this option by UART_SCLK_XTAL and I have disabled PM altogether, AND IT WORKS! I would have prefered to use UART_SCLK_RTC since it is a light-sleep compatible clock source but I guess life is hard.

After this I have reenabled PM and it seems to work too. I will keep trying but I would recommend adding the line: dte_config.uart_config.source_clk = UART_SCLK_XTAL; to the example 😄

@david-cermak one last question: Is this LTE implementation thread safe?

I know http_client (which is what I'm ultimately using) is indeed thread-safe. But I don't know if using this extra layer (the LTE) changes this.

Yes, this library is thread safe (so you can send AT commands from multiple threads), and the network implementation of PPPoS is thread safe too (this library just sets the input and output packet paths to lwIP which handles the thread safety)

Yes, this library is thread safe (so you can send AT commands from multiple threads), and the network implementation of PPPoS is thread safe too (this library just sets the input and output packet paths to lwIP which handles the thread safety)

Then this means I can call on several http calls from diffrent threads, great!

I don'know if you want me to close the issue, but it should be noted that there's probably some testing to do. While the set mode method works correctly the esp_modem_get_signal_quality() requires several iterations to get the signal:

W (08:39:34.988) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:35.588) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:36.188) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:36.788) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:37.388) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT I (08:39:37.492) Modem: Signal quality: rssi=99, ber=99

Moreover, you can see that the data returned doesn't really make sense.

But if I call again the method after setting the mode I get, after many retries:

W (08:39:38.502) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:39.102) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:39.702) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:40.302) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:40.902) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:41.502) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:42.102) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:42.702) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:43.302) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:43.902) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:44.412) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:44.916) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:45.512) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:46.112) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:46.712) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:47.312) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:47.912) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:48.512) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:49.112) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:49.712) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:50.312) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:50.816) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:51.412) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:52.012) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:52.612) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:53.212) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:53.812) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:54.412) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:55.012) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:55.612) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:56.212) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:56.716) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:57.316) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:57.912) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:58.413) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:59.012) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:39:59.612) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:40:00.212) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:40:00.812) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:40:01.412) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:40:01.913) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:40:02.416) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:40:03.016) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:40:03.613) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT W (08:40:04.213) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT I (08:40:04.313) Modem: Signal quality: rssi=24, ber=99

At least the rssi seems like it is correct.

Feel free to close the issue if you want to.

Hi @david-cermak,

We are currently facing issues regarding the reliability of the internet connection process.

Initially we were using a carrier (Orange) which we knew had poor internet signal. At the start it seemed to work fine. But one day all of a sudden it stopped working. No matter how many times we tried it would always fail on the "Waiting for IP" part.

However, as we knew that we had poor signal we didn't give too much thought to this sudden problem and we changed carriers (know we are using Movistar/O2). Immediately everything started working fine. The internet connection was established on the first try (or at most at the second). So at this point we focused on developing everything with the new carrier which worked fine.

Fast-forward to yesterday at some point there was no way to established an internet connectión. We tried 10 times and all of them ended up failing. It wasn't cell reception because we had tried 2 hours before and it worked. At that time I couldn't connect to the board to debug what was happening.

I have tried again today and "luckily" it has failed:

V (06:07:57.594) command_lib: get_signal_quality V (06:07:57.596) command_lib: generic_get_string V (06:07:57.700) command_lib: Token: {AT+CSQ}

V (06:07:57.701) command_lib: Token: {+CSQ: 99,99}

} (06:07:57.701) command_lib: Token: {

V (06:07:57.703) command_lib: Token: {OK}

I (06:07:57.708) Modem: Signal quality: rssi=99, ber=99 V (06:07:57.714) command_lib: set_echo V (06:07:57.717) command_lib: generic_command_common V (06:07:57.722) command_lib: generic_command D (06:07:57.727) command_lib: generic_command command ATE0

D (06:07:57.810) command_lib: Response: ATE0 OK

V (06:07:57.811) command_lib: set_pdp_context V (06:07:57.811) command_lib: generic_command_common V (06:07:57.814) command_lib: generic_command D (06:07:57.818) command_lib: generic_command command AT+CGDCONT=1,"IP","m2m.movistar.es"

D (06:07:57.918) command_lib: Response: OK

V (06:07:57.919) command_lib: set_data_mode V (06:07:57.919) command_lib: generic_command D (06:07:57.921) command_lib: generic_command command ATD*99##

D (06:07:58.027) command_lib: Response: CONNECT 150000000

D (06:07:58.127) esp_netif_handlers: esp_netif action has started with netif0x3fcc2190 from event_id=0 D (06:07:58.127) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fcc4b4c D (06:07:58.134) esp-netif_lwip-ppp: Phase Start D (06:07:58.139) esp-netif_lwip-ppp: Phase Establish D (06:07:58.144) esp_netif_lwip: check: remote, if=0x3fcc2190 fn=0x42096f60 0x42096f60: esp_netif_update_default_netif_lwip at C:/Users/Marti/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (06:07:58.151) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcc2190 V (06:07:58.159) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcc2190 D (06:07:58.166) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (06:07:58.172) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) success I (06:07:58.179) Modem: Waiting for IP address D (06:08:04.165) esp-netif_lwip-ppp: Phase Authenticate D (06:08:04.165) esp-netif_lwip-ppp: Phase Network D (06:08:04.177) esp-netif_lwip-ppp: Phase Establish D (06:08:10.177) esp-netif_lwip-ppp: Phase Disconnect D (06:08:10.177) esp-netif_lwip-ppp: Phase Dead I (06:08:10.178) esp-netif_lwip-ppp: Connection lost D (06:08:10.182) event: running post IP_EVENT:7 with handler 0x4201adf0 and context 0x3fcc213c on loop 0x3fce9acc 0x4201adf0: on_ip_event at C:/Users/Marti/Documents/Repos/hmi-fw-esp32/components/Lte_Modem/modem.c:53

D (06:08:10.192) Modem: IP event! 7 W (06:08:10.195) Modem: Modem Disconnect from PPP Server D (06:08:10.201) event: running post IP_EVENT:7 with handler 0x42095ab8 and context 0x3fcc2db4 on loop 0x3fce9acc 0x42095ab8: esp_netif_action_disconnected at C:/Users/Marti/esp/esp-idf/components/esp_netif/esp_netif_handlers.c:91

D (06:08:10.212) esp_netif_handlers: esp_netif action disconnected with netif0x3fcc2190 from event_id=7 D (06:08:10.221) esp_netif_lwip: check: remote, if=0x3fcc2190 fn=0x420967cc 0x420967cc: esp_netif_down_api at C:/Users/Marti/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1279

D (06:08:10.228) esp_netif_lwip: esp_netif_down_api esp_netif:0x3fcc2190 D (06:08:10.235) esp_netif_lwip: check: local, if=0x3fcc2190 fn=0x42096f60 0x42096f60: esp_netif_update_default_netif_lwip at C:/Users/Marti/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (06:08:10.242) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcc2190 V (06:08:10.250) esp_netif_objects: esp_netif_next_unsafe 0x0 V (06:08:10.255) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcc2190 V (06:08:10.262) esp_netif_objects: esp_netif_next_unsafe 0x3fcc2190 D (06:08:10.269) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (06:08:28.184) event: running post GENERAL_EVENTS:5 with handler 0x4200efc8 and context 0x3fcbbb9c on loop 0x3fce9acc 0x4200efc8: connectionUnsuccessCallback(void, char const, int, void*) at C:/Users/Marti/Documents/Repos/hmi-fw-esp32/components/ServiceTask/ServiceTask.cpp:134

E (06:08:28.184) Modem: Timeout!

The debug output doesn't seem to be very explanatory. Do you have any ideas on what I could try?

To add more info. The connection usually establishes on the second try (or at the first). When it doesn't connect on the second try it usually doesn't connect: you have to wait a lot until it works again. However, I don't understand this since I reset the modem each time I start the initilization.

The only thing I have found diffrent between when it works and when it doesn't is that usually when it fails the signal quality returns: I (09:48:03.099) Modem: Signal quality: rssi=99, ber=99

D (09:47:50.000) Modem: Modem SIMCOM_PWR_KEY = 0 D (09:48:00.000) esp_netif_lwip: LwIP stack has been initialized D (09:48:00.001) esp_netif_lwip: esp-netif has been successfully initialized D (09:48:00.003) esp_netif_objects: esp_netif_add_to_list 0x3fcc1140 D (09:48:00.009) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1) D (09:48:00.019) esp-netif_lwip-ppp: esp_netif_new_ppp: PPP connection created: 0x3fcc3aa4 D (09:48:00.027) esp-netif_lwip-ppp: Phase Dead I (09:48:00.032) Modem: Initializing esp_modem for the SIM7070 module... I (09:48:00.039) uart: ESP_INTR_FLAG_IRAM flag not set while CONFIG_UART_ISR_IN_IRAM is enabled, flag updated I (09:48:00.050) uart: queue free spaces: 30 V (37942) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args V (37949) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E D (37957) intr_alloc: Connected src 28 to int 17 (cpu 0) V (09:48:00.075) command_lib: get_signal_quality V (09:48:00.079) command_lib: generic_get_string W (09:48:00.584) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:48:00.585) command_lib: get_signal_quality V (09:48:00.586) command_lib: generic_get_string W (09:48:01.175) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:48:01.176) command_lib: get_signal_quality V (09:48:01.177) command_lib: generic_get_string W (09:48:01.775) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:48:01.775) command_lib: get_signal_quality V (09:48:01.777) command_lib: generic_get_string W (09:48:02.375) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:48:02.376) command_lib: get_signal_quality V (09:48:02.377) command_lib: generic_get_string

W (09:48:02.975) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:48:02.978) command_lib: get_signal_quality V (09:48:02.982) command_lib: generic_get_string

V (09:48:03.079) command_lib: Token: {AT+CSQ}

V (09:48:03.085) command_lib: Token: {+CSQ: 99,99}

} (09:48:03.090) command_lib: Token: {

V (09:48:03.094) command_lib: Token: {OK}

I (09:48:03.099) Modem: Signal quality: rssi=99, ber=99 D (09:48:03.099) i2cdev: Timeout: ticks = 0 (0 usec) on port 0 V (09:48:03.104) command_lib: set_echo V (09:48:03.114) command_lib: generic_command_common V (09:48:03.119) command_lib: generic_command D (09:48:03.124) command_lib: generic_command command ATE0 D (09:48:03.200) command_lib: Response: ATE0 OK

V (09:48:03.209) command_lib: set_pdp_context V (09:48:03.214) command_lib: generic_command_common V (09:48:03.219) command_lib: generic_command D (09:48:03.223) command_lib: generic_command command AT+CGDCONT=1,"IP","m2m.movistar.es"

D (09:48:03.426) command_lib: Response: CONNECT 150000000

D (09:48:03.526) esp_netif_handlers: esp_netif action has started with netif0x3fcc1140 from event_id=0 D (09:48:03.543) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fcc3aa4 D (09:48:03.551) esp-netif_lwip-ppp: Phase Start D (09:48:03.556) esp-netif_lwip-ppp: Phase Establish D (09:48:03.562) esp_netif_lwip: check: remote, if=0x3fcc1140 fn=0x42097064 0x42097064: esp_netif_update_default_netif_lwip at C:/Users/Marti/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (09:48:03.568) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcc1140 V (09:48:03.587) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcc1140 D (09:48:03.601) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (09:48:03.612) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) success

I (09:48:03.626) Modem: Waiting for IP address

D (09:48:09.580) esp-netif_lwip-ppp: Phase Authenticate D (09:48:09.580) esp-netif_lwip-ppp: Phase Network D (09:48:09.591) esp-netif_lwip-ppp: Phase Establish I (09:48:12.845) APP_Identification_HL: APP ID timeout 0 D (09:48:15.592) esp-netif_lwip-ppp: Phase Disconnect D (09:48:15.592) esp-netif_lwip-ppp: Phase Dead I (09:48:15.593) esp-netif_lwip-ppp: Connection lost D (09:48:15.597) event: running post IP_EVENT:7 with handler 0x4201adf0 and context 0x3fcc10ec on loop 0x3fce9acc 0x4201adf0: on_ip_event at C:/Users/Marti/Documents/Repos/hmi-fw-esp32/components/Lte_Modem/modem.c:53

D (09:48:15.607) Modem: IP event! 7 W (09:48:15.610) Modem: Modem Disconnect from PPP Server D (09:48:15.616) event: running post IP_EVENT:7 with handler 0x42095bbc and context 0x3fcc675c on loop 0x3fce9acc 0x42095bbc: esp_netif_action_disconnected at C:/Users/Marti/esp/esp-idf/components/esp_netif/esp_netif_handlers.c:91

D (09:48:15.627) esp_netif_handlers: esp_netif action disconnected with netif0x3fcc1140 from event_id=7 D (09:48:15.636) esp_netif_lwip: check: remote, if=0x3fcc1140 fn=0x420968d0 0x420968d0: esp_netif_down_api at C:/Users/Marti/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1279

D (09:48:15.643) esp_netif_lwip: esp_netif_down_api esp_netif:0x3fcc1140 D (09:48:15.650) esp_netif_lwip: check: local, if=0x3fcc1140 fn=0x42097064 0x42097064: esp_netif_update_default_netif_lwip at C:/Users/Marti/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (09:48:15.657) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcc1140 V (09:48:15.665) esp_netif_objects: esp_netif_next_unsafe 0x0 V (09:48:15.670) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcc1140 V (09:48:15.678) esp_netif_objects: esp_netif_next_unsafe 0x3fcc1140 D (09:48:15.684) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (09:48:33.642) event: running post GENERAL_EVENTS:5 with handler 0x4200efc8 and context 0x3fcbbb1c on loop 0x3fce9acc 0x4200efc8: connectionUnsuccessCallback(void, char const, int, void*) at C:/Users/Marti/Documents/Repos/hmi-fw-esp32/components/ServiceTask/ServiceTask.cpp:134

And when it works it returns something coherent: I (09:33:16.600) Modem: Signal quality: rssi=19, ber=99 (At least on the RSSI)

D (09:33:03.514) Modem: Modem SIMCOM_PWR_KEY = 0 D (09:33:13.514) esp_netif_lwip: LwIP stack has been initialized D (09:33:13.515) esp_netif_lwip: esp-netif has been successfully initialized D (09:33:13.517) esp_netif_objects: esp_netif_add_to_list 0x3fcc1140 D (09:33:13.523) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1) D (09:33:13.533) esp-netif_lwip-ppp: esp_netif_new_ppp: PPP connection created: 0x3fcc3aa4 D (09:33:13.541) esp-netif_lwip-ppp: Phase Dead I (09:33:13.546) Modem: Initializing esp_modem for the SIM7070 module... I (09:33:13.553) uart: ESP_INTR_FLAG_IRAM flag not set while CONFIG_UART_ISR_IN_IRAM is enabled, flag updated I (09:33:13.564) uart: queue free spaces: 30 V (34112) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args V (34119) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E D (34127) intr_alloc: Connected src 28 to int 17 (cpu 0) V (09:33:13.589) command_lib: get_signal_quality V (09:33:13.593) command_lib: generic_get_string W (09:33:14.098) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:33:14.099) command_lib: get_signal_quality V (09:33:14.100) command_lib: generic_get_string W (09:33:14.689) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:33:14.690) command_lib: get_signal_quality V (09:33:14.691) command_lib: generic_get_string W (09:33:15.289) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:33:15.289) command_lib: get_signal_quality V (09:33:15.291) command_lib: generic_get_string W (09:33:15.889) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:33:15.890) command_lib: get_signal_quality V (09:33:15.891) command_lib: generic_get_string W (09:33:16.489) Modem: esp_modem_get_signal_quality failed with 263 ESP_ERR_TIMEOUT V (09:33:16.489) command_lib: get_signal_quality V (09:33:16.491) command_lib: generic_get_string V (09:33:16.593) command_lib: Token: {AT+CSQ}

V (09:33:16.593) command_lib: Token: {+CSQ: 19,99}

} (09:33:16.594) command_lib: Token: {

V (09:33:16.596) command_lib: Token: {OK}

I (09:33:16.600) Modem: Signal quality: rssi=19, ber=99 V (09:33:16.606) command_lib: set_echo V (09:33:16.610) command_lib: generic_command_common V (09:33:16.615) command_lib: generic_command D (09:33:16.619) command_lib: generic_command command ATE0

D (09:33:16.702) command_lib: Response: ATE0 OK

V (09:33:16.703) command_lib: set_pdp_context V (09:33:16.703) command_lib: generic_command_common V (09:33:16.706) command_lib: generic_command D (09:33:16.711) command_lib: generic_command command AT+CGDCONT=1,"IP","m2m.movistar.es"

D (09:33:16.808) command_lib: Response: OK

V (09:33:16.808) command_lib: set_data_mode V (09:33:16.809) command_lib: generic_command D (09:33:16.811) command_lib: generic_command command ATD*99##

D (09:33:16.912) command_lib: Response: CONNECT 150000000

D (09:33:17.012) esp_netif_handlers: esp_netif action has started with netif0x3fcc1140 from event_id=0 D (09:33:17.013) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fcc3aa4 D (09:33:17.019) esp-netif_lwip-ppp: Phase Start D (09:33:17.024) esp-netif_lwip-ppp: Phase Establish D (09:33:17.029) esp_netif_lwip: check: remote, if=0x3fcc1140 fn=0x42097064 0x42097064: esp_netif_update_default_netif_lwip at C:/Users/Marti/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (09:33:17.036) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcc1140 V (09:33:17.044) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcc1140 D (09:33:17.051) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (09:33:17.057) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) success I (09:33:17.064) Modem: Waiting for IP address D (09:33:23.047) esp-netif_lwip-ppp: Phase Authenticate D (09:33:23.048) esp-netif_lwip-ppp: Phase Network I (09:33:23.076) esp-netif_lwip-ppp: Connected I (09:33:23.076) esp-netif_lwip-ppp: Name Server1: 80.58.61.250 I (09:33:23.077) esp-netif_lwip-ppp: Name Server2: 80.58.61.254 D (09:33:23.084) event: running post IP_EVENT:6 with handler 0x4201adf0 and context 0x3fcc10ec on loop 0x3fce9acc 0x4201adf0: on_ip_event at C:/Users/Marti/Documents/Repos/hmi-fw-esp32/components/Lte_Modem/modem.c:53

D (09:33:23.084) esp-netif_lwip-ppp: Phase Running D (09:33:23.094) Modem: IP event! 6 I (09:33:23.102) Modem: Modem Connect to PPP Server D (09:33:23.108) Modem: ~~~~~~ D (09:33:23.111) Modem: IP : 10.152.11.139 D (09:33:23.116) Modem: Netmask : 255.255.255.255 D (09:33:23.122) Modem: Gateway : 10.64.64.64 D (09:33:23.126) Modem: Name Server1: 80.58.61.250 D (09:33:23.131) Modem: Name Server2: 80.58.61.254 D (09:33:23.136) Modem: ~~~~~~ D (09:33:23.140) Modem: GOT ip event!!! I (09:33:23.140) Modem: Connected!

Could there be an issue in the library? The device hasn't change and it is located on the same exact spot every time.

Could there be an issue in the library?

I don't think so, when the signal strength is weak, and we still try to initiate the PPP connection, we simply get disconnected gracefully. Another thing is the real rssi value from the device, you can double check with a logic analyzer, but from what I read in the logs it is really the device itself that returns these invalid/no signal rssi numbers:

V (09:48:03.079) command_lib: Token: {AT+CSQ}
V (09:48:03.085) command_lib: Token: {+CSQ: 99,99}
} (09:48:03.090) command_lib: Token: {
V (09:48:03.094) command_lib: Token: {OK}

Could there be an issue in the library?

I don't think so, when the signal strength is weak, and we still try to initiate the PPP connection, we simply get disconnected gracefully. Another thing is the real rssi value from the device, you can double check with a logic analyzer, but from what I read in the logs it is really the device itself that returns these invalid/no signal rssi numbers:
V (09:48:03.079) command_lib: Token: {AT+CSQ}
V (09:48:03.085) command_lib: Token: {+CSQ: 99,99}
} (09:48:03.090) command_lib: Token: {
V (09:48:03.094) command_lib: Token: {OK}

The problem is that with the new carrier the signal strength is excellent in the areas tested. Moreover, being in the same place sometimes I get a successful connection and others I don't.

It's not that a matter of it not working it's just that it is unreliable. If I knew that it will always work on the x try it wouldn't be a problem (I would just retry). But I have seen two times where it was impossible to get a connection in a reasonable number of retries.

How is it possible that being on the same spot I get from an RSSI of 20 (corresponds to -73dBm, which is an excellent quality) to an RSSI of 99 (not known or not detectable)?

Taking into account that I reset the modem each time I initialize it and taking into account that an RSSI of 99 corresponds to not known or not detectable could the problem be that I have to wait longer before calling esp_modem_new_dev()?

Now there's a 10s delay between the toggle of SIMCOM_PWR_KEY and the call to esp_modem_new_dev().

Another thing that comes to my mind is that when the modem fails to connect: W (09:48:15.610) Modem: Modem Disconnect from PPP Server I could retry the connection by calling esp_modem_new_dev()?. This is based on the assumption that problem of the first failed connection is due to not leaving enough time for the modem to search for a network.

I ask it simply to know if it would make sense. Because to me esp_modem_new_dev() is whitchcraft 😃: A single line does magically everything.

I insist on this theory because although the location of the test didn't change between the succesful connection and the unsuccesful one what did change was the hour. The connection was successful at 8:30h and 19:00h and it was unsuccessful at 10:30h. Taking into account the location of the test there's a high chance that at the later time of day the network was more saturated.

Another difference I have found between when the connection fails and when it doesn't:

When it fails:

V (09:48:03.209) command_lib: set_pdp_context V (09:48:03.214) command_lib: generic_command_common V (09:48:03.219) command_lib: generic_command D (09:48:03.223) command_lib: generic_command command AT+CGDCONT=1,"IP","m2m.movistar.es"

D (09:48:03.426) command_lib: Response: CONNECT 150000000

D (09:48:03.526) esp_netif_handlers: esp_netif action has started with netif0x3fcc1140 from event_id=0 D (09:48:03.543) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fcc3aa4 D (09:48:03.551) esp-netif_lwip-ppp: Phase Start D (09:48:03.556) esp-netif_lwip-ppp: Phase Establish

When it works:

V (09:33:16.703) command_lib: set_pdp_context V (09:33:16.703) command_lib: generic_command_common V (09:33:16.706) command_lib: generic_command D (09:33:16.711) command_lib: generic_command command AT+CGDCONT=1,"IP","m2m.movistar.es"

D (09:33:16.808) command_lib: Response: OK

V (09:33:16.808) command_lib: set_data_mode V (09:33:16.809) command_lib: generic_command D (09:33:16.811) command_lib: generic_command command ATD*99##

D (09:33:16.912) command_lib: Response: CONNECT 150000000

D (09:33:17.012) esp_netif_handlers: esp_netif action has started with netif0x3fcc1140 from event_id=0 D (09:33:17.013) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fcc3aa4 D (09:33:17.019) esp-netif_lwip-ppp: Phase Start

When it works the library sends a ATD*99## that was not sent when the connection failed. Is this normal? Does this happen because at this point the connection is already established and the library tries to send data?

One possible reason for skipping the dial-in command (ATD*99##) is that the device was previously in data mode, so the data mode was resumed? Not sure if this might be the case in your use-case, as you're saying that you always reset the device, correct?

If yes, then it might help to "hang-up" the connection. I've seen some devices having problems when resuming the data mode sometimes. You can try to send command ATH\r when you exit the data mode,

One possible reason for skipping the dial-in command (ATD*99##) is that the device was previously in data mode, so the data mode was resumed? Not sure if this might be the case in your use-case, as you're saying that you always reset the device, correct?

If yes, then it might help to "hang-up" the connection. I've seen some devices having problems when resuming the data mode sometimes. You can try to send command ATH\r when you exit the data mode,

Yes, the device is reset everytime I attempt a new connection:

    gpio_set_level(SIMCOM_EN_PWR, 0);
    gpio_set_level(SIMCOM_PWR_KEY, 1);
    gpio_set_level(SIMCOM_PWR_KEY, 0);

    ESP_LOGI(TAG, "Modem Init");
    ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY = 0");
    ESP_LOGD(TAG, "Modem SIMCOM_EN_PWR = 0");

    vTaskDelay(pdMS_TO_TICKS(500));
    gpio_set_level(SIMCOM_EN_PWR, 1);
    ESP_LOGD(TAG, "Modem SIMCOM_EN_PWR = 1");
    vTaskDelay(pdMS_TO_TICKS(500));

    ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY = 1");
    gpio_set_level(SIMCOM_PWR_KEY, 1);
    vTaskDelay(pdMS_TO_TICKS(20000));
    ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY = 0");
    gpio_set_level(SIMCOM_PWR_KEY, 0);

Your second part is what I don't understand. I'm using the default example where the device is set in data mode:

    while (true)
    {
        err = esp_modem_set_mode(dce, ESP_MODEM_MODE_DATA);
        if (err != ESP_OK) {
            ESP_LOGW(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with %d", err);
            vTaskDelay(pdMS_TO_TICKS(500));
        }
        else{
            ESP_LOGD(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_DATA) success");
            break;
        }
    }

So from what I understand I don't get out of data mode at any moment (maybe the library does so for me?)

You say: I've seen some devices having problems when resuming the data mode sometimes and then: You can try to send command ATH\r when you exit the data mode, But I don't exit data mode (at least voluntarily)

Another thing I have tried:

    while (true)
    {
        err = esp_modem_get_signal_quality(dce, &rssi, &ber);
        if (err != ESP_OK) {
            ESP_LOGW(TAG, "esp_modem_get_signal_quality failed with %d %s", err, esp_err_to_name(err));
            vTaskDelay(pdMS_TO_TICKS(500));
        }
        else
        {     
            ESP_LOGI(TAG, "Signal quality: rssi=%d, ber=%d", rssi, ber);
            if(rssi==99){
                esp_modem_reset(dce);
                vTaskDelay(pdMS_TO_TICKS(1000));
            }
            else
                break;
        }
    }

Basically if the rssi returns 99 I reset the modem and retry getting a signal. The code continues ahead only if there's a valid rssi.

However, when trying the code by disconecting the antena:

V (10:44:38.899) command_lib: get_signal_quality V (10:44:38.899) command_lib: generic_get_string V (10:44:38.904) command_lib: Token: {AT+CSQ}

V (10:44:38.904) command_lib: Token: {+CSQ: 99,99}

} (10:44:38.907) command_lib: Token: {

V (10:44:38.911) command_lib: Token: {OK}

I (10:44:38.916) Modem: Signal quality: rssi=99, ber=99 V (10:44:38.921) command_lib: reset V (10:44:38.925) command_lib: generic_command D (10:44:38.929) command_lib: generic_command command AT+CRESET

D (10:44:39.018) command_lib: Response: AT+CRESET ERROR

Moreover, if I reconnect the antena the conection doesn't recover. Meaning that, once the rssi has returned 99 once, it always returns 99. No matter if I connect the antena.

However, if the antena is connected from the start the connection succeeds with no problems.

I have also tried this with a different result

    while (true)
    {
        err = esp_modem_get_signal_quality(dce, &rssi, &ber);
        if (err != ESP_OK) {
            ESP_LOGW(TAG, "esp_modem_get_signal_quality failed with %d %s", err, esp_err_to_name(err));
            vTaskDelay(pdMS_TO_TICKS(500));
        }
        else
        {     
            ESP_LOGI(TAG, "Signal quality: rssi=%d, ber=%d", rssi, ber);
            if(rssi==99){
                gpio_set_level(SIMCOM_PWR_KEY, 1);
                vTaskDelay(pdMS_TO_TICKS(1000));
                ESP_LOGD(TAG, "Modem SIMCOM_PWR_KEY reset");
                gpio_set_level(SIMCOM_PWR_KEY, 0);
                vTaskDelay(pdMS_TO_TICKS(500));
            }
            else
                break;
        }
    }

You can see how the main change is that I reset the modem via SIMCOM_PWR_KEY.

I start with the antena disconnected, once the first rssi=99 messages appear I connect the antena. After some time (30-60s) the rssi finally returns something diffrent than 99:

V (14:15:17.063) command_lib: get_signal_quality V (14:15:17.063) command_lib: generic_get_string V (14:15:17.067) command_lib: Token: {AT+CSQ}

V (14:15:17.068) command_lib: Token: {+CSQ: 21,99}

} (14:15:17.071) command_lib: Token: {

V (14:15:17.075) command_lib: Token: {OK}

I (14:15:17.079) Modem: Signal quality: rssi=21, ber=99

and so the while() exits and the process is carried on. However, the IP address is never obtained:

I (14:19:43.547) Modem: Signal quality: rssi=31, ber=99 V (14:19:43.552) command_lib: set_echo V (14:19:43.556) command_lib: generic_command_common V (14:19:43.561) command_lib: generic_command D (14:19:43.566) command_lib: generic_command command ATE0

D (14:19:43.648) command_lib: Response: ATE0 OK

V (14:19:43.649) command_lib: set_pdp_context V (14:19:43.649) command_lib: generic_command_common V (14:19:43.652) command_lib: generic_command D (14:19:43.657) command_lib: generic_command command AT+CGDCONT=1,"IP","m2m.movistar.es"

D (14:19:43.754) command_lib: Response: OK

V (14:19:43.755) command_lib: set_data_mode V (14:19:43.755) command_lib: generic_command D (14:19:43.757) command_lib: generic_command command ATD*99##

D (14:19:43.860) command_lib: Response: CONNECT 150000000

D (14:19:43.960) esp_netif_handlers: esp_netif action has started with netif0x3fcc21d4 from event_id=0 D (14:19:43.960) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fcc4b90 D (14:19:43.967) esp-netif_lwip-ppp: Phase Start D (14:19:43.972) esp-netif_lwip-ppp: Phase Establish D (14:19:43.977) esp_netif_lwip: check: remote, if=0x3fcc21d4 fn=0x42097058 0x42097058: esp_netif_update_default_netif_lwip at C:/Users/Marti/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (14:19:43.984) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcc21d4 V (14:19:43.991) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3fcc21d4 D (14:19:43.998) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (14:19:44.005) Modem: esp_modem_set_mode(ESP_MODEM_MODE_DATA) success I (14:19:44.012) Modem: Waiting for IP address D (14:19:49.996) esp-netif_lwip-ppp: Phase Authenticate D (14:19:49.996) esp-netif_lwip-ppp: Phase Network D (14:19:50.007) esp-netif_lwip-ppp: Phase Establish D (14:19:56.008) esp-netif_lwip-ppp: Phase Disconnect D (14:19:56.008) esp-netif_lwip-ppp: Phase Dead I (14:19:56.009) esp-netif_lwip-ppp: Connection lost

However, if I connect the antena from the start the connection succeeds (the rssi returns a value different from 99 from the start). So I don't think it's an issue with signal strength. This can also be confirmed through the RSSI, a value returned of 21 corresponds to -71dBm, which is considered excellent.

You can see how now the ATD*99## command is performed.

I'm afraid we cannot help here. I see that it is a very weird behavior, but unrelated to this library, esp_modem only sends commands and switches modes (only on demand).

So from what I understand I don't get out of data mode at any moment (maybe the library does so for me?)

No, the library doesn't automatically exit data mode. I mentioned the hang-up command as It seemed related to me (per issues with some devices in the past ), but if you don't exit the data mode it is not the case.

D (10:44:39.018) command_lib: Response: AT+CRESET ERROR

Skimmed through the datasheet and you should probably use something like ATZ or AT&F0 instead. The device doesn't support AT+CRESET command.

Okay, thanks for testing. It seems the mode switching doesn't really work for SIM7080. I'll buy the device and fix the issue, but that will take some time.

Hi @david-cermak where you able to test this module?

Even after all the tweeks I made to the example code I still can't obtain a connection reliabily.

Sorry, I still haven't tested it with SIM7080.

espressif / esp-protocols

Strange behaviour when integrating pppos example into bigger project (IDFGH-9470) #232

Override some defaults to enable PPP