LwIP PPP connection close and no authentication (IDFGH-12720)

dmitrij9992905 commented 5 months ago

Answers checklist.

[X] I have read the documentation for esp-protocols components and the issue is not addressed there.
[X] I have updated my esp-protocols branch (master or release) to the latest version and checked that the issue is present there.
[X] I have searched the issue tracker for a similar issue and not found a similar issue.

General issue report

For now, I need to connect to Internet from ESP32 using SIM800C again, using LilyGO T-Call based on AXP192 PMIC. I use ESP-IDF 5.2.1 and esp-modem v1.1.0 component, and use simple_cmux_client as a base.

But all I see that AT commands are working, PDP context is setting up, but connection to *99# establishes and interrupts even without connection to Internet. Even with setting the PAP authentication.

Now I'm using MTS sim card and I see the same effect as with Beeline.

Here is my code:

/*
 * SPDX-FileCopyrightText: 2022-2023 Espressif Systems (Shanghai) CO LTD
 *
 * SPDX-License-Identifier: Unlicense OR CC0-1.0
 */
/* PPPoS Client 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 <cstring>
#include <iostream>
#include "freertos/FreeRTOS.h"
#include "freertos/event_groups.h"
#include "esp_netif.h"
#include "esp_log.h"
#include "esp_event.h"
#include "cxx_include/esp_modem_dte.hpp"
#include "esp_modem_config.h"
#include "cxx_include/esp_modem_api.hpp"
#include "simple_mqtt_client.hpp"
#include "esp_vfs_dev.h"        // For optional VFS support
#include "esp_https_ota.h"      // For potential OTA configuration
#include "vfs_resource/vfs_create.hpp"
#include "SIM7070_gnss.hpp"
#include "driver/gpio.h"
#include "driver/i2c.h"
#include "axp20x.h"
#include "esp_netif.h"
#include "esp_netif_ppp.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 _I2C_NUMBER(num)            I2C_NUM_##num
#define I2C_NUMBER(num)             _I2C_NUMBER(num)

#define AXP_ISR_GPIO                (gpio_num_t)CONFIG_AXPxxx_INTERRUPT_PIN  /*!< axp power chip interrupt Pin*/
#define GPIO_INPUT_PIN_SEL          (1ULL<<AXP_ISR_GPIO)

#define I2C_MASTER_SCL_IO           CONFIG_I2C_MASTER_SCL                   /*!< gpio number for I2C master clock */
#define I2C_MASTER_SDA_IO           CONFIG_I2C_MASTER_SDA                   /*!< gpio number for I2C master data  */
#define I2C_MASTER_NUM              I2C_NUMBER(CONFIG_I2C_MASTER_PORT_NUM)  /*!< I2C port number for master dev */
#define I2C_MASTER_FREQ_HZ          CONFIG_I2C_MASTER_FREQUENCY             /*!< I2C master clock frequency */
#define I2C_MASTER_TX_BUF_DISABLE   0                                       /*!< I2C master doesn't need buffer */
#define I2C_MASTER_RX_BUF_DISABLE   0                                       /*!< I2C master doesn't need buffer */

#define WRITE_BIT                   I2C_MASTER_WRITE                        /*!< I2C master write */
#define READ_BIT                    I2C_MASTER_READ                         /*!< I2C master read */
#define ACK_CHECK_EN                0x1                                     /*!< I2C master will check ack from slave*/
#define ACK_CHECK_DIS               0x0                                     /*!< I2C master will not check ack from slave */
#define ACK_VAL                     (i2c_ack_type_t)0x0                     /*!< I2C ack value */
#define NACK_VAL                    (i2c_ack_type_t)0x1                     /*!< I2C nack value */

//#define MODEM_RST                   (gpio_num_t)5
#define MODEM_PWRKEY                (gpio_num_t)4
#define MODEM_POWER_ON              (gpio_num_t)25
#define MODEM_DTR                   (gpio_num_t)32
#define MODEM_RI                    (gpio_num_t)33

#define BROKER_URL CONFIG_BROKER_URI

using namespace esp_modem;

static const char *TAG = "cmux_example";

AXP20X_Class axp;

static QueueHandle_t gpio_evt_queue = NULL;

static void IRAM_ATTR axp_isr_handler(void *arg)
{
    uint32_t gpio_num = (uint32_t) arg;
    xQueueSendFromISR(gpio_evt_queue, &gpio_num, NULL);
}

static void axp_irq_init()
{

    gpio_config_t io_conf;
    //enable interrupt
    io_conf.intr_type = GPIO_INTR_NEGEDGE;
    //set as input mode
    io_conf.mode = GPIO_MODE_INPUT;
    //bit mask of the pins that you want to set
    io_conf.pin_bit_mask = GPIO_INPUT_PIN_SEL;
    //disable pull-down mode
    io_conf.pull_down_en = GPIO_PULLDOWN_DISABLE;
    //enable pull-up mode
    io_conf.pull_up_en = GPIO_PULLUP_ENABLE;
    //configure GPIO with the given settings
    gpio_config(&io_conf);
    //change gpio intrrupt type for one pin
    gpio_set_intr_type(AXP_ISR_GPIO, GPIO_INTR_NEGEDGE);
    //install gpio isr service
    gpio_install_isr_service(0);
    //hook isr handler for specific gpio pin
    gpio_isr_handler_add(AXP_ISR_GPIO, axp_isr_handler, (void *) AXP_ISR_GPIO);
    //create a queue to handle gpio event from isr
    gpio_evt_queue = xQueueCreate(10, sizeof(uint32_t));
}

/**
 * @brief i2c master initialization
 */
static esp_err_t i2c_master_init(void)
{
    i2c_port_t i2c_master_port = (i2c_port_t)I2C_MASTER_NUM;
    i2c_config_t conf;
    conf.mode = I2C_MODE_MASTER;
    conf.sda_io_num = I2C_MASTER_SDA_IO;
    conf.sda_pullup_en = GPIO_PULLUP_ENABLE;
    conf.scl_io_num = I2C_MASTER_SCL_IO;
    conf.scl_pullup_en = GPIO_PULLUP_ENABLE;
    conf.master.clk_speed = I2C_MASTER_FREQ_HZ;
    conf.clk_flags = 0;
    i2c_param_config(i2c_master_port, &conf);
    return i2c_driver_install(i2c_master_port, conf.mode, I2C_MASTER_RX_BUF_DISABLE, I2C_MASTER_TX_BUF_DISABLE, 0);
}

/**
 * @brief apx library i2c read callblack
 */
uint8_t twi_read(uint8_t dev_addr, uint8_t reg_addr, uint8_t *data, uint8_t len)
{
    if (len == 0) {
        return ESP_OK;
    }
    if (data == NULL) {
        return ESP_FAIL;
    }
    i2c_cmd_handle_t cmd;

    cmd = i2c_cmd_link_create();
    i2c_master_start(cmd);
    i2c_master_write_byte(cmd, (dev_addr << 1) | WRITE_BIT, ACK_CHECK_EN);
    i2c_master_write_byte(cmd, reg_addr, ACK_CHECK_EN);
    i2c_master_stop(cmd);
    esp_err_t ret =  i2c_master_cmd_begin(I2C_MASTER_NUM, cmd, pdMS_TO_TICKS(1000));
    i2c_cmd_link_delete(cmd);
    if (ret != ESP_OK) {
        return ESP_FAIL;
    }
    cmd = i2c_cmd_link_create();
    i2c_master_start(cmd);
    i2c_master_write_byte(cmd, (dev_addr << 1) | READ_BIT, ACK_CHECK_EN);
    if (len > 1) {
        i2c_master_read(cmd, data, len - 1, ACK_VAL);
    }
    i2c_master_read_byte(cmd, &data[len - 1], NACK_VAL);
    i2c_master_stop(cmd);
    ret = i2c_master_cmd_begin(I2C_MASTER_NUM, cmd, pdMS_TO_TICKS(1000));
    i2c_cmd_link_delete(cmd);
    return ret;
}

/**
 * @brief apx library i2c write callblack
 */
uint8_t twi_write(uint8_t dev_addr, uint8_t reg_addr, uint8_t *data, uint8_t len)
{
    if (data == NULL) {
        return ESP_FAIL;
    }
    i2c_cmd_handle_t cmd = i2c_cmd_link_create();
    i2c_master_start(cmd);
    i2c_master_write_byte(cmd, (dev_addr << 1) | WRITE_BIT, ACK_CHECK_EN);
    i2c_master_write_byte(cmd, reg_addr, ACK_CHECK_EN);
    i2c_master_write(cmd, data, len, ACK_CHECK_EN);
    i2c_master_stop(cmd);
    esp_err_t ret = i2c_master_cmd_begin(I2C_MASTER_NUM, cmd, pdMS_TO_TICKS(1000));
    i2c_cmd_link_delete(cmd);
    return ret;
}

void setupModem()
{

    gpio_reset_pin(MODEM_PWRKEY);
    gpio_reset_pin(MODEM_POWER_ON);
#ifdef MODEM_RST
    // Keep reset high
    // pinMode(MODEM_RST, OUTPUT);
    // digitalWrite(MODEM_RST, HIGH);
    gpio_reset_pin(MODEM_RST);
    gpio_set_direction(MODEM_RST, GPIO_MODE_OUTPUT);
    gpio_set_level(MODEM_RST, 1);
#endif

    // pinMode(MODEM_PWRKEY, OUTPUT);
    // pinMode(MODEM_POWER_ON, OUTPUT);
    gpio_set_direction(MODEM_PWRKEY, GPIO_MODE_OUTPUT);
    gpio_set_direction(MODEM_POWER_ON, GPIO_MODE_OUTPUT);

    // Turn on the Modem power first
    // digitalWrite(MODEM_POWER_ON, HIGH);
    gpio_set_level(MODEM_POWER_ON, 1);

    // Pull down PWRKEY for more than 1 second according to manual requirements
    // digitalWrite(MODEM_PWRKEY, HIGH);
    // delay(100);
    // digitalWrite(MODEM_PWRKEY, LOW);
    // delay(1000);
    // digitalWrite(MODEM_PWRKEY, HIGH);
    gpio_set_level(MODEM_PWRKEY, 1);
    vTaskDelay(pdMS_TO_TICKS(100));
    gpio_set_level(MODEM_PWRKEY, 0);
    vTaskDelay(pdMS_TO_TICKS(100));
    gpio_set_level(MODEM_PWRKEY, 1);

    // Initialize the indicator as an output
    // pinMode(LED_GPIO, OUTPUT);
    // digitalWrite(LED_GPIO, LED_OFF);
    ESP_LOGI(TAG, "Modem power has been setup");
}

class StatusHandler {
public:
    static constexpr auto IP_Event      = SignalGroup::bit0;
    static constexpr auto MQTT_Connect  = SignalGroup::bit1;
    static constexpr auto MQTT_Data     = SignalGroup::bit2;

    StatusHandler()
    {
        ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, on_event, this));
    }

    ~StatusHandler()
    {
        esp_event_handler_unregister(IP_EVENT, ESP_EVENT_ANY_ID, on_event);
    }

    void handle_mqtt(MqttClient *client)
    {
        mqtt_client = client;
        client->register_handler(ESP_EVENT_ANY_ID, on_event, this);
    }

    esp_err_t wait_for(decltype(IP_Event) event, int milliseconds)
    {
        return signal.wait_any(event, milliseconds);
    }

    ip_event_t get_ip_event_type()
    {
        return ip_event_type;
    }

private:
    static void on_event(void *arg, esp_event_base_t base, int32_t event, void *data)
    {
        auto *handler = static_cast<StatusHandler *>(arg);
        if (base == IP_EVENT) {
            handler->ip_event(event, data);
        } else {
            handler->mqtt_event(event, data);
        }
    }

    void ip_event(int32_t id, void *data)
    {
        if (id == IP_EVENT_PPP_GOT_IP) {
            auto *event = (ip_event_got_ip_t *)data;
            ESP_LOGI(TAG, "IP          : " IPSTR, IP2STR(&event->ip_info.ip));
            ESP_LOGI(TAG, "Netmask     : " IPSTR, IP2STR(&event->ip_info.netmask));
            ESP_LOGI(TAG, "Gateway     : " IPSTR, IP2STR(&event->ip_info.gw));
            signal.set(IP_Event);
        } else if (id == IP_EVENT_PPP_LOST_IP) {
            signal.set(IP_Event);
        }
        ip_event_type = static_cast<ip_event_t>(id);
    }

    void mqtt_event(int32_t event, void *data)
    {
        if (mqtt_client && event == mqtt_client->get_event(MqttClient::Event::CONNECT)) {
            signal.set(MQTT_Connect);
        } else if (mqtt_client && event == mqtt_client->get_event(MqttClient::Event::DATA)) {
            ESP_LOGI(TAG, " TOPIC: %s", mqtt_client->get_topic(data).c_str());
            ESP_LOGI(TAG, " DATA: %s", mqtt_client->get_data(data).c_str());
            signal.set(MQTT_Data);
        }
    }

    esp_modem::SignalGroup signal{};
    MqttClient *mqtt_client{nullptr};
    ip_event_t ip_event_type;
};

extern "C" void app_main(void)
{
    printf("System start\n");

    vTaskDelay(500 / portTICK_PERIOD_MS);

    ESP_ERROR_CHECK(i2c_master_init());

    axp_irq_init();

    if (axp.begin((axp_com_fptr_t)twi_read, (axp_com_fptr_t)twi_write, AXP192_SLAVE_ADDRESS)) {
        ESP_LOGE(TAG, "Error init axp20x !!!");
        while (1);
    }
    ESP_LOGI(TAG, "Success init axp20x !!!");

    axp.setPowerOutPut(AXP202_DCDC3, AXP202_ON);
    axp.setPowerOutPut(AXP202_EXTEN, AXP202_ON);
    axp.setPowerOutPut(AXP202_LDO2, AXP202_ON);
    axp.setPowerOutPut(AXP202_LDO4, AXP202_ON);
    axp.setPowerOutPut(AXP202_DCDC2, AXP202_ON);
    axp.setLDO4Voltage(AXP202_LDO4_1800MV);
    axp.setLDO3Voltage(3500);
    axp.setPowerOutPut(AXP202_LDO3, AXP202_ON);

    if ( axp.isDCDC2Enable()) {
        ESP_LOGI(TAG, "DC2: %u mV", axp.getDCDC2Voltage());
    } else {
        ESP_LOGI(TAG, "DC2: DISABLE");
    }

    if (axp.isDCDC3Enable()) {
        ESP_LOGI(TAG, "DC3: %u mV", axp.getDCDC3Voltage());
    } else {
        ESP_LOGI(TAG, "DC3: DISABLE");
    }

    if (axp.isLDO2Enable()) {
        ESP_LOGI(TAG, "LDO2: %u mV", axp.getLDO2Voltage());
    } else {
        ESP_LOGI(TAG, "LDO2: DISABLE");
    }

    if (axp.isLDO3Enable()) {
        ESP_LOGI(TAG, "LDO3: %u mV", axp.getLDO3Voltage());
    } else {
        ESP_LOGI(TAG, "LDO3: DISABLE");
    }

    if (axp.isLDO4Enable()) {
        ESP_LOGI(TAG, "LDO4: %u mV", axp.getLDO4Voltage());
    } else {
        ESP_LOGI(TAG, "LDO4: DISABLE");
    }

    if (axp.isExtenEnable()) {
        ESP_LOGI(TAG, "Exten: ENABLE");
    } else {
        ESP_LOGI(TAG, "Exten: DISABLE");
    }

    //When the chip is axp192 / 173, the allowed values are 0 ~ 15,
    //corresponding to the axp1xx_charge_current_t enumeration
    // axp.setChargeControlCur(AXP1XX_CHARGE_CUR_550MA);

    //axp202 allows maximum charging current of 1800mA, minimum 300mA
    axp.setChargeControlCur(300);

    ESP_LOGI(TAG, "setChargeControlCur:%u", axp.getChargeControlCur());

    //! Enable all irq channel
    axp.enableIRQ(AXP202_ALL_IRQ, true);

    axp.clearIRQ();

    //! Turn off unused power
    // axp.setPowerOutPut(AXP192_DCDC1, AXP202_OFF);
    // axp.setPowerOutPut(AXP192_LDO2, AXP202_OFF);
    // axp.setPowerOutPut(AXP192_LDO3, AXP202_OFF);
    // axp.setPowerOutPut(AXP192_DCDC2, AXP202_OFF);
    // axp.setPowerOutPut(AXP192_EXTEN, AXP202_OFF);

    //! Do not turn off DC3, it is powered by esp32
    // axp.setPowerOutPut(AXP192_DCDC3, AXP202_ON);

    // Set the charging indicator to turn off
    // Turn it off to save current consumption
    // axp.setChgLEDMode(AXP20X_LED_OFF);

    // Set the charging indicator to flash once per second
    // axp.setChgLEDMode(AXP20X_LED_BLINK_1HZ);

    //! Use axp192 adc get voltage info
    axp.adc1Enable(AXP202_VBUS_VOL_ADC1 | AXP202_VBUS_CUR_ADC1 | AXP202_BATT_CUR_ADC1 | AXP202_BATT_VOL_ADC1, true);

    // float vbus_v = axp.getVbusVoltage();
    // float vbus_c = axp.getVbusCurrent();
    // float batt_v = axp.getBattVoltage();
    // axp.getBattPercentage();   // axp192 is not support percentage
    //Serial.printf("VBUS:%.2f mV %.2f mA ,BATTERY: %.2f\n", vbus_v, vbus_c, batt_v);
    setupModem();

    vTaskDelay(10000 / portTICK_PERIOD_MS);

    /* Init and register system/core components */
    ESP_ERROR_CHECK(esp_event_loop_create_default());
    ESP_ERROR_CHECK(esp_netif_init());

    /* Configure and create 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 = CONFIG_EXAMPLE_MODEM_UART_TX_PIN;
    dte_config.uart_config.rx_io_num = CONFIG_EXAMPLE_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;
#if CONFIG_EXAMPLE_USE_VFS_TERM == 1
    /* The VFS terminal is just a demonstration of using an abstract file descriptor
     * which implements non-block reads, writes and selects to communicate with esp-modem.
     * This configuration uses the same UART driver as the terminal created by `create_uart_dte()`,
     * so doesn't give any practical benefit besides the FD use demonstration and a placeholder
     * to use FD terminal for other devices
     */
    struct esp_modem_vfs_uart_creator uart_config = ESP_MODEM_VFS_DEFAULT_UART_CONFIG("/dev/uart/1");
    assert(vfs_create_uart(&uart_config, &dte_config.vfs_config) == true);

    auto dte = create_vfs_dte(&dte_config);
    esp_vfs_dev_uart_use_driver(uart_config.uart.port_num);
#else
    auto dte = create_uart_dte(&dte_config);
#endif // CONFIG_EXAMPLE_USE_VFS_TERM
    assert(dte);

    /* Configure the DCE */
    esp_modem_dce_config_t dce_config = ESP_MODEM_DCE_DEFAULT_CONFIG(CONFIG_EXAMPLE_MODEM_PPP_APN);

    /* Configure the PPP netif */
    esp_netif_config_t netif_ppp_config = ESP_NETIF_DEFAULT_PPP();

    /* Create the PPP and DCE objects */

    esp_netif_t *esp_netif = esp_netif_new(&netif_ppp_config);
    assert(esp_netif);

    if (esp_netif_ppp_set_auth(esp_netif, esp_netif_auth_type_t::NETIF_PPP_AUTHTYPE_PAP,
        CONFIG_EXAMPLE_MODEM_PPP_AUTH_USERNAME, CONFIG_EXAMPLE_MODEM_PPP_AUTH_PASSWORD) == ESP_OK)
        ESP_LOGI(TAG, "PPP auth set");
    else
        ESP_LOGE(TAG, "PPP auth failed");

#if CONFIG_EXAMPLE_MODEM_DEVICE_BG96 == 1
    auto dce = create_BG96_dce(&dce_config, dte, esp_netif);
#elif CONFIG_EXAMPLE_MODEM_DEVICE_SIM800 == 1
    auto dce = create_SIM800_dce(&dce_config, dte, esp_netif);
#elif CONFIG_EXAMPLE_MODEM_DEVICE_SIM7000 == 1
    auto dce = create_SIM7000_dce(&dce_config, dte, esp_netif);
#elif CONFIG_EXAMPLE_MODEM_DEVICE_SIM7070 == 1
    auto dce = create_SIM7070_dce(&dce_config, dte, esp_netif);
#elif CONFIG_EXAMPLE_MODEM_DEVICE_SIM7070_GNSS == 1
    auto dce = create_SIM7070_GNSS_dce(&dce_config, dte, esp_netif);
#elif CONFIG_EXAMPLE_MODEM_DEVICE_SIM7600 == 1
    auto dce = create_SIM7600_dce(&dce_config, dte, esp_netif);
#else
#error "Unsupported device"
#endif
    assert(dce);

    /* Try to connect to the network and publish an mqtt topic */
    StatusHandler handler;

    if (dte_config.uart_config.flow_control == ESP_MODEM_FLOW_CONTROL_HW) {
        if (command_result::OK != dce->set_flow_control(2, 2)) {
            ESP_LOGE(TAG, "Failed to set the set_flow_control mode");
            return;
        }
        ESP_LOGI(TAG, "set_flow_control OK");
    } else {
        ESP_LOGI(TAG, "not set_flow_control, because 2-wire mode active.");
    }

    /* Setup basic operation mode for the DCE (pin if used, CMUX mode) */
#if CONFIG_EXAMPLE_NEED_SIM_PIN == 1
    bool pin_ok = true;
    if (dce->read_pin(pin_ok) == command_result::OK && !pin_ok) {
        ESP_MODEM_THROW_IF_FALSE(dce->set_pin(CONFIG_EXAMPLE_SIM_PIN) == command_result::OK, "Cannot set PIN!");
        vTaskDelay(pdMS_TO_TICKS(1000)); // Need to wait for some time after unlocking the SIM
    }
#endif

    // Trigger PPP
    esp_err_t err1 = dce->set_mode(esp_modem::modem_mode::DATA_MODE);

    if (err1 != ESP_OK) {
        ESP_LOGE(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with %d", err1);
        return;
    } else
        ESP_LOGI(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_DATA) ok");

    vTaskDelay(pdMS_TO_TICKS(30000));

    if (dce->set_mode(esp_modem::modem_mode::CMUX_MODE)) {
        std::cout << "Modem has correctly entered multiplexed command/data mode" << std::endl;
    } else {
        ESP_LOGE(TAG, "Failed to configure multiplexed command mode... exiting");
        return;
    }

    //vTaskDelay(pdMS_TO_TICKS(30000));

    /* Read some data from the modem */
    std::string str;
    while (dce->get_operator_name(str) != esp_modem::command_result::OK) {
        // Getting operator name could fail... retry after 500 ms
        vTaskDelay(pdMS_TO_TICKS(500));
    }
    std::cout << "Operator name:" << str << std::endl;

#if CONFIG_EXAMPLE_MODEM_DEVICE_SIM7070_GNSS == 1
    if (dce->set_gnss_power_mode(1) == esp_modem::command_result::OK) {
        std::cout << "Modem set_gnss_power_mode: OK" << std::endl;
    }
#endif

    if (!handler.wait_for(StatusHandler::IP_Event, 60000)) {
        ESP_LOGE(TAG, "Cannot get IP within specified timeout... exiting");
        return;
    } else if (handler.get_ip_event_type() == IP_EVENT_PPP_GOT_IP) {
        std::cout << "Got IP address" << std::endl;

        /* When connected to network, subscribe and publish some MQTT data */
        MqttClient mqtt(BROKER_URL);
        handler.handle_mqtt(&mqtt);
        mqtt.connect();
        if (!handler.wait_for(StatusHandler::MQTT_Connect, 60000)) {
            ESP_LOGE(TAG, "Cannot connect to %s within specified timeout... exiting", BROKER_URL);
            return;
        }
        std::cout << "Connected" << std::endl;

        mqtt.subscribe("/topic/esp-modem");
        mqtt.publish("/topic/esp-modem", "Hello modem");
        if (!handler.wait_for(StatusHandler::MQTT_Data, 60000)) {
            ESP_LOGE(TAG, "Didn't receive published data within specified timeout... exiting");
            return;
        }
        std::cout << "Received MQTT data" << std::endl;

    } else if (handler.get_ip_event_type() == IP_EVENT_PPP_LOST_IP) {
        ESP_LOGE(TAG, "PPP client has lost connection... exiting");
        return;
    }

    /* Again reading some data from the modem */
    if (dce->get_imsi(str) == esp_modem::command_result::OK) {
        std::cout << "Modem IMSI number:" << str << std::endl;
    }

#if CONFIG_EXAMPLE_MODEM_DEVICE_SIM7070_GNSS == 1
    esp_modem_gps_t gps;

    for (int i = 0; i < 200; ++i) {
        if (dce->get_gnss_information_sim70xx(gps) == esp_modem::command_result::OK) {
            ESP_LOGI(TAG, "gps.run  %i",
                     gps.run);
            ESP_LOGI(TAG, "gps.fix  %i",
                     gps.fix);
            ESP_LOGI(TAG, "gps.date.year %i gps.date.month %i gps.date.day %i",
                     gps.date.year,   gps.date.month,   gps.date.day);
            ESP_LOGI(TAG, "gps.tim.hour %i gps.tim.minute %i   gps.tim.second %i   gps.tim.thousand %i",
                     gps.tim.hour,   gps.tim.minute,     gps.tim.second,     gps.tim.thousand);
            ESP_LOGI(TAG, "gps.latitude %f gps.longitude %f ",
                     gps.latitude,   gps.longitude );
            ESP_LOGI(TAG, "gps.altitude  %f",
                     gps.altitude);
            ESP_LOGI(TAG, "gps.speed  %f",
                     gps.speed);
            ESP_LOGI(TAG, "gps.cog  %f",
                     gps.cog);
            ESP_LOGI(TAG, "gps.fix_mode  %i",
                     gps.fix_mode);
            ESP_LOGI(TAG, "gps.dop_h %f gps.dop_p %f gps.dop_v %f ",
                     gps.dop_h,   gps.dop_p,   gps.dop_v );
            ESP_LOGI(TAG, "gps.sats_in_view  %i",
                     gps.sats_in_view);
            ESP_LOGI(TAG, "gps.hpa  %f gps.vpa  %f",
                     gps.hpa, gps.vpa);
        }
        vTaskDelay(pdMS_TO_TICKS(1000)); //Wait

    }
#endif  // CONFIG_EXAMPLE_MODEM_DEVICE_SIM7070_GNSS

#if CONFIG_EXAMPLE_PERFORM_OTA == 1
    esp_http_client_config_t config = { };
    config.skip_cert_common_name_check = true;
    config.url = CONFIG_EXAMPLE_PERFORM_OTA_URI;

    esp_err_t ret = esp_https_ota(&config);
    if (ret == ESP_OK) {
        esp_restart();
    } else {
        ESP_LOGE(TAG, "Firmware upgrade failed");
        return;
    }
#endif // CONFIG_EXAMPLE_PERFORM_OTA

    /* Close multiplexed command/data mode */
#if CONFIG_EXAMPLE_CLOSE_CMUX_AT_END == 1
    if (dce->set_mode(esp_modem::modem_mode::COMMAND_MODE)) {
        std::cout << "Modem has correctly entered command mode" << std::endl;
    } else {
        ESP_LOGE(TAG, "Failed to configure desired mode... exiting");
        return;
    }
#endif
}

And verbose connection logs:

rst:0x1 (POWERON_RESET),boot:0x13 (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:7172
load:0x40078000,len:15540
load:0x40080400,len:4
0x40080400: _init at ??:?

ho 8 tail 4 room 4
load:0x40080404,len:3904
entry 0x40080640
I (31) boot: ESP-IDF v5.2.1 2nd stage bootloader
I (31) boot: compile time Apr 28 2024 16:00:47
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v1.0
I (39) boot.esp32: SPI Speed      : 40MHz
I (43) boot.esp32: SPI Mode       : DIO
I (48) boot.esp32: SPI Flash Size : 4MB
I (52) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (61) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00010000 00006000
I (76) boot:  1 phy_init         RF data          01 01 00016000 00001000
I (83) boot:  2 factory          factory app      00 00 00020000 00100000
I (91) boot: End of partition table
I (95) esp_image: segment 0: paddr=00020020 vaddr=3f400020 size=3f9c4h (260548) map
I (157) esp_image: segment 1: paddr=0005f9ec vaddr=3ffb0000 size=0062ch (  1580) load
I (158) esp_image: segment 2: paddr=00060020 vaddr=400d0020 size=9d954h (645460) map
I (296) esp_image: segment 3: paddr=000fd97c vaddr=3ffb062c size=02148h (  8520) load
I (298) esp_image: segment 4: paddr=000ffacc vaddr=40080000 size=0f9e4h ( 63972) load
I (326) boot: Loaded app from partition at offset 0x20000
I (326) boot: Disabling RNG early entropy source...
I (337) cpu_start: Multicore app
V (338) mmap: after coalescing, 3 regions are left
D (338) cpu_start: Pro cpu up
D (338) cpu_start: Starting app cpu, entry point is 0x400812fc
0x400812fc: call_start_cpu1 at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_system/port/cpu_start.c:183

D (0) cpu_start: App cpu up
D (352) clk: RTC_SLOW_CLK calibration value: 3329344
I (364) cpu_start: Pro cpu start user code
I (364) cpu_start: cpu freq: 160000000 Hz
I (364) cpu_start: Application information:
I (368) cpu_start: Project name:     simple_cmux_client
I (374) cpu_start: App version:      1
I (379) cpu_start: Compile time:     Apr 28 2024 16:00:50
I (385) cpu_start: ELF file SHA256:  3e57be039...
I (390) cpu_start: ESP-IDF:          v5.2.1
I (395) cpu_start: Min chip rev:     v0.0
I (400) cpu_start: Max chip rev:     v3.99 
I (405) cpu_start: Chip rev:         v1.0
V (409) memory_layout: reserved range is 0x3f43f98c - 0x3f43f9d4
D (415) memory_layout: Checking 9 reserved memory ranges:
D (421) memory_layout: Reserved memory range 0x3ff82000 - 0x3ff82000
D (427) memory_layout: Reserved memory range 0x3ffae000 - 0x3ffae6e0
D (434) memory_layout: Reserved memory range 0x3ffb0000 - 0x3ffb5868
D (440) memory_layout: Reserved memory range 0x3ffe0000 - 0x3ffe0440
D (446) memory_layout: Reserved memory range 0x3ffe3f20 - 0x3ffe4350
D (453) memory_layout: Reserved memory range 0x40070000 - 0x40078000
D (459) memory_layout: Reserved memory range 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

D (466) memory_layout: Reserved memory range 0x40080000 - 0x4008f9e4
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

D (472) memory_layout: Reserved memory range 0x50001fe8 - 0x50002000
D (479) memory_layout: Building list of available memory regions:
V (485) memory_layout: Examining memory region 0x3ffae000 - 0x3ffb0000
V (491) memory_layout: Start of region 0x3ffae000 - 0x3ffb0000 overlaps reserved 0x3ffae000 - 0x3ffae6e0
D (501) memory_layout: Available memory region 0x3ffae6e0 - 0x3ffb0000
V (508) memory_layout: Examining memory region 0x3ffb0000 - 0x3ffb8000
V (514) memory_layout: Start of region 0x3ffb0000 - 0x3ffb8000 overlaps reserved 0x3ffb0000 - 0x3ffb5868
D (524) memory_layout: Available memory region 0x3ffb5868 - 0x3ffb8000
V (530) memory_layout: Examining memory region 0x3ffb8000 - 0x3ffc0000
D (537) memory_layout: Available memory region 0x3ffb8000 - 0x3ffc0000
V (543) memory_layout: Examining memory region 0x3ffc0000 - 0x3ffc2000
D (550) memory_layout: Available memory region 0x3ffc0000 - 0x3ffc2000
V (557) memory_layout: Examining memory region 0x3ffc2000 - 0x3ffc4000
D (563) memory_layout: Available memory region 0x3ffc2000 - 0x3ffc4000
V (570) memory_layout: Examining memory region 0x3ffc4000 - 0x3ffc6000
D (576) memory_layout: Available memory region 0x3ffc4000 - 0x3ffc6000
V (583) memory_layout: Examining memory region 0x3ffc6000 - 0x3ffc8000
D (590) memory_layout: Available memory region 0x3ffc6000 - 0x3ffc8000
V (596) memory_layout: Examining memory region 0x3ffc8000 - 0x3ffca000
D (603) memory_layout: Available memory region 0x3ffc8000 - 0x3ffca000
V (609) memory_layout: Examining memory region 0x3ffca000 - 0x3ffcc000
D (616) memory_layout: Available memory region 0x3ffca000 - 0x3ffcc000
V (623) memory_layout: Examining memory region 0x3ffcc000 - 0x3ffce000
D (629) memory_layout: Available memory region 0x3ffcc000 - 0x3ffce000
V (636) memory_layout: Examining memory region 0x3ffce000 - 0x3ffd0000
D (642) memory_layout: Available memory region 0x3ffce000 - 0x3ffd0000
V (649) memory_layout: Examining memory region 0x3ffd0000 - 0x3ffd2000
D (656) memory_layout: Available memory region 0x3ffd0000 - 0x3ffd2000
V (662) memory_layout: Examining memory region 0x3ffd2000 - 0x3ffd4000
D (669) memory_layout: Available memory region 0x3ffd2000 - 0x3ffd4000
V (675) memory_layout: Examining memory region 0x3ffd4000 - 0x3ffd6000
D (682) memory_layout: Available memory region 0x3ffd4000 - 0x3ffd6000
V (689) memory_layout: Examining memory region 0x3ffd6000 - 0x3ffd8000
D (695) memory_layout: Available memory region 0x3ffd6000 - 0x3ffd8000
V (702) memory_layout: Examining memory region 0x3ffd8000 - 0x3ffda000
D (708) memory_layout: Available memory region 0x3ffd8000 - 0x3ffda000
V (715) memory_layout: Examining memory region 0x3ffda000 - 0x3ffdc000
D (722) memory_layout: Available memory region 0x3ffda000 - 0x3ffdc000
V (728) memory_layout: Examining memory region 0x3ffdc000 - 0x3ffde000
D (735) memory_layout: Available memory region 0x3ffdc000 - 0x3ffde000
V (741) memory_layout: Examining memory region 0x3ffde000 - 0x3ffe0000
D (748) memory_layout: Available memory region 0x3ffde000 - 0x3ffe0000
V (755) memory_layout: Examining memory region 0x3ffe0000 - 0x3ffe4000
V (761) memory_layout: Start of region 0x3ffe0000 - 0x3ffe4000 overlaps reserved 0x3ffe0000 - 0x3ffe0440
V (771) memory_layout: End of region 0x3ffe0440 - 0x3ffe4000 overlaps reserved 0x3ffe3f20 - 0x3ffe4350
D (780) memory_layout: Available memory region 0x3ffe0440 - 0x3ffe3f20
V (787) memory_layout: Examining memory region 0x3ffe4000 - 0x3ffe8000
V (793) memory_layout: Start of region 0x3ffe4000 - 0x3ffe8000 overlaps reserved 0x3ffe3f20 - 0x3ffe4350
D (803) memory_layout: Available memory region 0x3ffe4350 - 0x3ffe8000
V (809) memory_layout: Examining memory region 0x3ffe8000 - 0x3fff0000
D (816) memory_layout: Available memory region 0x3ffe8000 - 0x3fff0000
V (823) memory_layout: Examining memory region 0x3fff0000 - 0x3fff8000
D (829) memory_layout: Available memory region 0x3fff0000 - 0x3fff8000
V (836) memory_layout: Examining memory region 0x3fff8000 - 0x3fffc000
D (842) memory_layout: Available memory region 0x3fff8000 - 0x3fffc000
V (849) memory_layout: Examining memory region 0x3fffc000 - 0x40000000
0x40000000: _WindowOverflow4 in ROM

D (856) memory_layout: Available memory region 0x3fffc000 - 0x40000000
0x40000000: _WindowOverflow4 in ROM

V (862) memory_layout: Examining memory region 0x40070000 - 0x40078000
V (869) memory_layout: Region 0x40070000 - 0x40078000 inside of reserved 0x40070000 - 0x40078000
V (878) memory_layout: Examining memory region 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

V (884) memory_layout: Region 0x40078000 - 0x40080000 inside of reserved 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

V (893) memory_layout: Examining memory region 0x40080000 - 0x40082000
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027
0x40082000: heap_caps_alloc_failed at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/heap_caps.c:89

V (900) memory_layout: Region 0x40080000 - 0x40082000 inside of reserved 0x40080000 - 0x4008f9e4
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027
0x40082000: heap_caps_alloc_failed at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/heap_caps.c:89
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

V (909) memory_layout: Examining memory region 0x40082000 - 0x40084000
0x40082000: heap_caps_alloc_failed at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/heap_caps.c:89
0x40084000: uart_rx_intr_handler_default at /home/espidf521/esp/esp-idf-v5.2.1/components/driver/uart/uart.c:972

V (915) memory_layout: Region 0x40082000 - 0x40084000 inside of reserved 0x40080000 - 0x4008f9e4
0x40082000: heap_caps_alloc_failed at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/heap_caps.c:89
0x40084000: uart_rx_intr_handler_default at /home/espidf521/esp/esp-idf-v5.2.1/components/driver/uart/uart.c:972
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

V (924) memory_layout: Examining memory region 0x40084000 - 0x40086000
0x40084000: uart_rx_intr_handler_default at /home/espidf521/esp/esp-idf-v5.2.1/components/driver/uart/uart.c:972
0x40086000: clk_ll_cpu_get_src at /home/espidf521/esp/esp-idf-v5.2.1/components/hal/esp32/include/hal/clk_tree_ll.h:569
 (inlined by) rtc_clk_cpu_freq_get_config at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_hw_support/port/esp32/rtc_clk.c:488

V (931) memory_layout: Region 0x40084000 - 0x40086000 inside of reserved 0x40080000 - 0x4008f9e4
0x40084000: uart_rx_intr_handler_default at /home/espidf521/esp/esp-idf-v5.2.1/components/driver/uart/uart.c:972
0x40086000: clk_ll_cpu_get_src at /home/espidf521/esp/esp-idf-v5.2.1/components/hal/esp32/include/hal/clk_tree_ll.h:569
 (inlined by) rtc_clk_cpu_freq_get_config at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_hw_support/port/esp32/rtc_clk.c:488
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

V (939) memory_layout: Examining memory region 0x40086000 - 0x40088000
0x40086000: clk_ll_cpu_get_src at /home/espidf521/esp/esp-idf-v5.2.1/components/hal/esp32/include/hal/clk_tree_ll.h:569
 (inlined by) rtc_clk_cpu_freq_get_config at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_hw_support/port/esp32/rtc_clk.c:488
0x40088000: prvInitialiseMutex at /home/espidf521/esp/esp-idf-v5.2.1/components/freertos/FreeRTOS-Kernel/queue.c:651

V (946) memory_layout: Region 0x40086000 - 0x40088000 inside of reserved 0x40080000 - 0x4008f9e4
0x40086000: clk_ll_cpu_get_src at /home/espidf521/esp/esp-idf-v5.2.1/components/hal/esp32/include/hal/clk_tree_ll.h:569
 (inlined by) rtc_clk_cpu_freq_get_config at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_hw_support/port/esp32/rtc_clk.c:488
0x40088000: prvInitialiseMutex at /home/espidf521/esp/esp-idf-v5.2.1/components/freertos/FreeRTOS-Kernel/queue.c:651
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

V (955) memory_layout: Examining memory region 0x40088000 - 0x4008a000
0x40088000: prvInitialiseMutex at /home/espidf521/esp/esp-idf-v5.2.1/components/freertos/FreeRTOS-Kernel/queue.c:651
0x4008a000: vTaskRemoveFromUnorderedEventList at /home/espidf521/esp/esp-idf-v5.2.1/components/freertos/FreeRTOS-Kernel/tasks.c:4000 (discriminator 3)

V (962) memory_layout: Region 0x40088000 - 0x4008a000 inside of reserved 0x40080000 - 0x4008f9e4
0x40088000: prvInitialiseMutex at /home/espidf521/esp/esp-idf-v5.2.1/components/freertos/FreeRTOS-Kernel/queue.c:651
0x4008a000: vTaskRemoveFromUnorderedEventList at /home/espidf521/esp/esp-idf-v5.2.1/components/freertos/FreeRTOS-Kernel/tasks.c:4000 (discriminator 3)
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

V (970) memory_layout: Examining memory region 0x4008a000 - 0x4008c000
0x4008a000: vTaskRemoveFromUnorderedEventList at /home/espidf521/esp/esp-idf-v5.2.1/components/freertos/FreeRTOS-Kernel/tasks.c:4000 (discriminator 3)
0x4008c000: spi_flash_encrypt_ll_plaintext_save at /home/espidf521/esp/esp-idf-v5.2.1/components/hal/esp32/include/hal/spi_flash_encrypted_ll.h:78

V (977) memory_layout: Region 0x4008a000 - 0x4008c000 inside of reserved 0x40080000 - 0x4008f9e4
0x4008a000: vTaskRemoveFromUnorderedEventList at /home/espidf521/esp/esp-idf-v5.2.1/components/freertos/FreeRTOS-Kernel/tasks.c:4000 (discriminator 3)
0x4008c000: spi_flash_encrypt_ll_plaintext_save at /home/espidf521/esp/esp-idf-v5.2.1/components/hal/esp32/include/hal/spi_flash_encrypted_ll.h:78
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

V (986) memory_layout: Examining memory region 0x4008c000 - 0x4008e000
0x4008c000: spi_flash_encrypt_ll_plaintext_save at /home/espidf521/esp/esp-idf-v5.2.1/components/hal/esp32/include/hal/spi_flash_encrypted_ll.h:78
0x4008e000: block_insert at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:389
 (inlined by) block_trim_used at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:517
 (inlined by) tlsf_realloc at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:1197

V (992) memory_layout: Region 0x4008c000 - 0x4008e000 inside of reserved 0x40080000 - 0x4008f9e4
0x4008c000: spi_flash_encrypt_ll_plaintext_save at /home/espidf521/esp/esp-idf-v5.2.1/components/hal/esp32/include/hal/spi_flash_encrypted_ll.h:78
0x4008e000: block_insert at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:389
 (inlined by) block_trim_used at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:517
 (inlined by) tlsf_realloc at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:1197
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

V (1001) memory_layout: Examining memory region 0x4008e000 - 0x40090000
0x4008e000: block_insert at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:389
 (inlined by) block_trim_used at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:517
 (inlined by) tlsf_realloc at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:1197

V (1008) memory_layout: Start of region 0x4008e000 - 0x40090000 overlaps reserved 0x40080000 - 0x4008f9e4
0x4008e000: block_insert at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:389
 (inlined by) block_trim_used at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:517
 (inlined by) tlsf_realloc at /home/espidf521/esp/esp-idf-v5.2.1/components/heap/tlsf/tlsf.c:1197
0x40080000: _WindowOverflow4 at /home/espidf521/esp/esp-idf-v5.2.1/components/xtensa/xtensa_vectors.S:2027

D (1018) memory_layout: Available memory region 0x4008f9e4 - 0x40090000
V (1024) memory_layout: Examining memory region 0x40090000 - 0x40092000
D (1031) memory_layout: Available memory region 0x40090000 - 0x40092000
V (1038) memory_layout: Examining memory region 0x40092000 - 0x40094000
D (1044) memory_layout: Available memory region 0x40092000 - 0x40094000
V (1051) memory_layout: Examining memory region 0x40094000 - 0x40096000
D (1058) memory_layout: Available memory region 0x40094000 - 0x40096000
V (1064) memory_layout: Examining memory region 0x40096000 - 0x40098000
D (1071) memory_layout: Available memory region 0x40096000 - 0x40098000
V (1078) memory_layout: Examining memory region 0x40098000 - 0x4009a000
D (1084) memory_layout: Available memory region 0x40098000 - 0x4009a000
V (1091) memory_layout: Examining memory region 0x4009a000 - 0x4009c000
D (1098) memory_layout: Available memory region 0x4009a000 - 0x4009c000
V (1104) memory_layout: Examining memory region 0x4009c000 - 0x4009e000
D (1111) memory_layout: Available memory region 0x4009c000 - 0x4009e000
V (1118) memory_layout: Examining memory region 0x4009e000 - 0x400a0000
D (1125) memory_layout: Available memory region 0x4009e000 - 0x400a0000
I (1131) heap_init: Initializing. RAM available for dynamic allocation:
D (1139) heap_init: New heap initialised at 0x3ffae6e0
I (1144) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
D (1150) heap_init: New heap initialised at 0x3ffb5868
I (1155) heap_init: At 3FFB5868 len 0002A798 (169 KiB): DRAM
I (1161) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1168) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
D (1174) heap_init: New heap initialised at 0x4008f9e4
I (1180) heap_init: At 4008F9E4 len 0001061C (65 KiB): IRAM
V (1186) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (1192) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (1201) intr_alloc: Connected src 46 to int 2 (cpu 0)
V (1207) memspi: raw_chip_id: 164020

V (1210) memspi: chip_id: 204016

V (1213) memspi: raw_chip_id: 164020

V (1217) memspi: chip_id: 204016

D (1220) spi_flash: trying chip: issi
D (1224) spi_flash: trying chip: gd
D (1228) spi_flash: trying chip: mxic
D (1231) spi_flash: trying chip: winbond
D (1235) spi_flash: trying chip: generic
I (1239) spi_flash: detected chip: generic
I (1244) spi_flash: flash io: dio
D (1248) cpu_start: calling init function: 0x40147ac0
0x40147ac0: _GLOBAL__sub_I__ZNSt12ctype_bynameIwEC2ERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEj at /builds/idf/crosstool-NG/.build/xtensa-esp-elf/src/gcc/libstdc++-v3/src/c++11/locale-inst.cc:160

D (1253) cpu_start: calling init function: 0x401430f4
0x401430f4: _GLOBAL__sub_I__ZNSt12ctype_bynameIcEC2ERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEj at /builds/idf/crosstool-NG/.build/xtensa-esp-elf/src/gcc/libstdc++-v3/src/c++11/locale-inst.cc:160

D (1258) cpu_start: calling init function: 0x4013a3a4
0x4013a3a4: _GLOBAL__sub_I__ZNSt12ctype_bynameIwEC2ERKSsj at /builds/idf/crosstool-NG/.build/xtensa-esp-elf/src/gcc/libstdc++-v3/src/c++11/locale-inst.cc:160

D (1263) cpu_start: calling init function: 0x40132c88
0x40132c88: _GLOBAL__sub_I__ZNSt12ctype_bynameIcEC2ERKSsj at /builds/idf/crosstool-NG/.build/xtensa-esp-elf/src/gcc/libstdc++-v3/src/c++11/locale-inst.cc:160

D (1268) cpu_start: calling init function: 0x4012bc94
0x4012bc94: _GLOBAL__sub_I$00090__ZSt3cin at /builds/idf/crosstool-NG/.build/xtensa-esp-elf/src/gcc/libstdc++-v3/src/c++98/globals_io.cc:109

V (1273) pthread: pthread_once: call init_routine 0x3ffb08cc
V (1279) pthread: pthread_once: call init_routine 0x3ffb08c4
D (1287) cpu_start: calling init function: 0x4012af90
0x4012af90: _GLOBAL__sub_I__ZN17__eh_globals_init7_S_initE at /builds/idf/crosstool-NG/.build/xtensa-esp-elf/src/gcc/libstdc++-v3/libsupc++/eh_globals.cc:162

D (1290) cpu_start: calling init function: 0x4012ad04
0x4012ad04: _GLOBAL__sub_I__ZN9__gnu_cxx9__freeresEv at /builds/idf/crosstool-NG/.build/xtensa-esp-elf/src/gcc/libstdc++-v3/libsupc++/eh_alloc.cc:462

D (1295) cpu_start: calling init function: 0x400e96cc
0x400e96cc: esp_ipc_init at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_system/esp_ipc.c:114

D (1300) cpu_start: calling init function: 0x400e766c
0x400e766c: check_i2c_driver_conflict at /home/espidf521/esp/esp-idf-v5.2.1/components/driver/i2c/i2c.c:1652

W (1305) i2c: This driver is an old driver, please migrate your application code to adapt `driver/i2c_master.h`
D (1315) cpu_start: calling init function: 0x400d75e8
0x400d75e8: _GLOBAL__sub_I_axp at /home/espidf521/esp32-workspace/simple_cmux_client/main/simple_cmux_client_main.cpp:623

D (1321) cpu_start: calling init function: 0x400866fc
0x400866fc: enable_timer_group0_for_calibration at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_hw_support/port/esp32/rtc_time.c:197

D (1326) cpu_start: calling init function: 0x400d2e7c
0x400d2e7c: esp_app_format_init_elf_sha256 at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_app_format/esp_app_desc.c:68

D (1331) cpu_start: calling init function: 0x400d6334 on core: 0
0x400d6334: __esp_system_init_fn_esp_timer_startup_init at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_timer/src/esp_timer.c:578

V (1337) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (1343) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC02
D (1351) intr_alloc: Connected src 17 to int 3 (cpu 0)
D (1356) cpu_start: calling init function: 0x400d3fb0 on core: 0
0x400d3fb0: __esp_system_init_fn_init_components0 at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_system/startup.c:493

D (1362) cpu_start: Setting C++ exception workarounds.
V (1368) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (1374) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (1382) intr_alloc: Connected src 24 to int 9 (cpu 0)
D (1388) app_start: Starting scheduler on CPU0
V (1392) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (1392) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x40E
 (1402) intr_alloc: Connected src 25 to int 2 (cpu 1)
D (1412) app_start: Starting scheduler on CPU1
;32mI (1392) main_task: Started on CPU0
D (1422) heap_init: New heap initialised at 0x3ffe0440
D (1422) heap_init: New heap initialised at 0x3ffe4350
V (1422) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (1432) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (1442) intr_alloc: Connected src 16 to int 12 (cpu 0)
I (1442) main_task: Calling app_main()
System start
V (1952) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (1952) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (1952) intr_alloc: Connected src 50 to int 13 (cpu 0)
I (1952) gpio: GPIO[35]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:2 
V (1962) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (1972) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (1982) intr_alloc: Connected src 22 to int 17 (cpu 0)
I (1992) cmux_example: Success init axp20x !!!
I (2002) cmux_example: DC2: 1800 mV
I (2002) cmux_example: DC3: 3300 mV
I (2002) cmux_example: LDO2: 3300 mV
I (2002) cmux_example: LDO3: 3300 mV
I (2012) cmux_example: LDO4: DISABLE
I (2012) cmux_example: Exten: ENABLE
I (2022) cmux_example: setChargeControlCur:15
I (2032) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2032) gpio: GPIO[25]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2242) cmux_example: Modem power has been setup
D (12242) event: running task for loop 0x3ffb9f44
D (12242) event: created task for loop 0x3ffb9f44
D (12242) event: created event loop 0x3ffb9f44
D (12242) esp_netif_lwip: LwIP stack has been initialized
D (12242) esp_netif_lwip: esp-netif has been successfully initialized
I (12252) uart: ESP_INTR_FLAG_IRAM flag not set while CONFIG_UART_ISR_IN_IRAM is enabled, flag updated
I (12262) uart: queue free spaces: 30
V (12262) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (12272) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (12282) intr_alloc: Connected src 35 to int 18 (cpu 0)
D (12292) esp_netif_lwip: check: remote, if=0x3ffb8c10 fn=0x400ebc0c
0x400ebc0c: esp_netif_new_api at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:690

V (12292) esp_netif_objects: esp_netif_add_to_list_unsafe 0x3ffbf388
D (12302) esp_netif_objects: esp_netif_add_to_list_unsafe netif added successfully (total netifs: 1)
D (12312) esp-netif_lwip-ppp: esp_netif_new_ppp: PPP connection created: 0x3ffbf5b8
D (12312) esp-netif_lwip-ppp: Phase Dead
D (12322) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (12322) esp_netif_lwip: check: remote, if=0x3ffbf388 fn=0x400ec360
0x400ec360: esp_netif_ppp_set_auth_api at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:2503

D (12332) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (12342) cmux_example: PPP auth set
V (12342) command_lib: set_flow_control
V (12342) command_lib: generic_command_common
V (12352) command_lib: generic_command
D (12352) command_lib: generic_command command AT+IFC=2,2

D (12362) command_lib: Response: 
OK

I (12362) cmux_example: set_flow_control OK
V (12372) command_lib: set_echo
V (12372) command_lib: generic_command_common
V (12372) command_lib: generic_command
D (12382) command_lib: generic_command command ATE0

D (12382) command_lib: Response: 
OK

V (12392) command_lib: set_pdp_context
V (12392) command_lib: generic_command_common
V (12392) command_lib: generic_command
D (12402) command_lib: generic_command command AT+CGDCONT=1,"IP","internet.mts.ru"

D (12422) command_lib: Response: 
OK

V (12422) command_lib: set_data_mode
V (12422) command_lib: generic_command
D (12422) command_lib: generic_command command ATD*99#

D (12432) command_lib: Response: 
CONNECT

D (12432) esp_netif_handlers: esp_netif action has started with netif0x3ffbf388 from event_id=0
D (12442) esp_netif_lwip: check: remote, if=0x3ffbf388 fn=0x400ebe7c
0x400ebe7c: esp_netif_start_api at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:1068

D (12442) esp_netif_lwip: esp_netif_start_api 0x3ffbf388
D (12452) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3ffbf5b8
D (12462) esp-netif_lwip-ppp: Phase Start
D (12462) esp-netif_lwip-ppp: Phase Establish
D (12472) esp_netif_lwip: check: local, if=0x3ffbf388 fn=0x400ec594
0x400ec594: esp_netif_update_default_netif_lwip at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:316

D (12472) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffbf388
V (12482) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3ffbf388
D (12482) esp_netif_lwip: call api in lwip: ret=0x0, give sem
E (12492) cmux_example: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with 1
D (12502) esp_netif_handlers: esp_netif action stopped with netif0x3ffbf388 from event_id=0
D (12502) esp-netif_lwip-ppp: Phase Authenticate
D (12512) esp_netif_lwip: check: remote, if=0x3ffbf388 fn=0x400ec064
0x400ec064: esp_netif_stop_api at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:1167

D (12522) esp-netif_lwip-ppp: Phase Network
D (12522) esp-netif_lwip-ppp: esp_netif_stop_ppp: Stopped PPP connection: 0x3ffbf5b8
D (12532) esp-netif_lwip-ppp: Phase Terminate
D (12532) esp-netif_lwip-ppp: Phase Establish
D (12542) esp_netif_lwip: check: local, if=0x3ffbf388 fn=0x400ec594
0x400ec594: esp_netif_update_default_netif_lwip at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:316

D (12542) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffbf388
V (12552) esp_netif_objects: esp_netif_next_unsafe 0x0
V (12562) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3ffbf388
V (12562) esp_netif_objects: esp_netif_next_unsafe 0x3ffbf388
D (12572) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (12572) esp-netif_lwip-ppp: Phase Disconnect
D (12582) esp-netif_lwip-ppp: Phase Dead
I (12582) esp-netif_lwip-ppp: User interrupt
D (12592) event: running post NETIF_PPP_STATUS:5 with handler 0x400dc994 and context 0x3ffc0930 on loop 0x3ffb9f44
0x400dc994: esp_modem::Netif::on_ppp_changed(void*, char const*, long, void*) at /home/espidf521/esp32-workspace/simple_cmux_client/managed_components/espressif__esp_modem/src/esp_modem_netif.cpp:22

I (12602) esp_modem_netif: PPP state changed event 5
V (12602) intr_alloc: esp_intr_free: Disabling int, killing handler
I (12612) main_task: Returned from app_main()

david-cermak commented 4 months ago

Hi @dmitrij9992905

It seems like the initial connection just cannot be established, are you sure that your SIM card is activated, you've got the correct APN and the GSM band is supported in your country (SIM800 is G2 only)?

Could you try the default pppos client example, just to rule out potential CMUX issues?

dmitrij9992905 commented 4 months ago

Hi @dmitrij9992905

It seems like the initial connection just cannot be established, are you sure that your SIM card is activated, you've got the correct APN and the GSM band is supported in your country (SIM800 is G2 only)?

Yes, 2G works in my country, and I took credentials such as APN and user/password. It seems to me that APN is OK but user and password is not being transfered at all. So, the connection closes.

Could you try the default pppos client example, just to rule out potential CMUX issues?

Although I build my project based on default example, I will try to build another one based on pppos client example and write you back

dmitrij9992905 commented 4 months ago

I've just check both pppos and cmux modes, and it appeared that after power on, I restarted SIM800C modem and waited 10 secs, and it was too small to initiate modem and its connection to network. I set it 30 secs and started working normally with pppos. In CMUX, it connected SIM800C to Internet, requested operator name, but PPP has lost connection...

Here are logs for pppos client:

I (30) boot: ESP-IDF v5.2.1 2nd stage bootloader
I (31) boot: compile time May  7 2024 22:28:27
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v1.0
I (39) boot.esp32: SPI Speed      : 40MHz
I (43) boot.esp32: SPI Mode       : DIO
I (48) boot.esp32: SPI Flash Size : 2MB
I (52) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (61) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (76) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (83) boot:  2 factory          factory app      00 00 00010000 00100000
I (91) boot: End of partition table
I (95) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=24aach (150188) map
I (155) esp_image: segment 1: paddr=00034ad4 vaddr=3ffb0000 size=023d4h (  9172) load
I (159) esp_image: segment 2: paddr=00036eb0 vaddr=40080000 size=09168h ( 37224) load
I (175) esp_image: segment 3: paddr=00040020 vaddr=400d0020 size=68260h (426592) map
I (322) esp_image: segment 4: paddr=000a8288 vaddr=40089168 size=04fe0h ( 20448) load
I (337) boot: Loaded app from partition at offset 0x10000
I (337) boot: Disabling RNG early entropy source...
I (349) cpu_start: Multicore app
I (358) cpu_start: Pro cpu start user code
I (358) cpu_start: cpu freq: 160000000 Hz
I (358) cpu_start: Application information:
I (361) cpu_start: Project name:     pppos_client
I (366) cpu_start: App version:      1
I (370) cpu_start: Compile time:     May  7 2024 22:28:19
I (377) cpu_start: ELF file SHA256:  01f9b7720...
I (382) cpu_start: ESP-IDF:          v5.2.1
I (387) cpu_start: Min chip rev:     v0.0
I (391) cpu_start: Max chip rev:     v3.99 
I (396) cpu_start: Chip rev:         v1.0
I (401) heap_init: Initializing. RAM available for dynamic allocation:
I (408) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (414) heap_init: At 3FFB3CF8 len 0002C308 (176 KiB): DRAM
I (421) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (427) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (433) heap_init: At 4008E148 len 00011EB8 (71 KiB): IRAM
I (441) spi_flash: detected chip: generic
I (444) spi_flash: flash io: dio
W (448) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (462) main_task: Started on CPU0
I (472) main_task: Calling app_main()
I (472) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (472) gpio: GPIO[25]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (682) pppos_example: Modem power has been setup
I (30682) pppos_example: Initializing esp_modem for the SIM800 module...
I (30682) uart: queue free spaces: 30
I (30692) pppos_example: HW set_flow_control OK
I (30692) pppos_example: Signal quality: rssi=19, ber=5
I (30712) pppos_example: Waiting for IP address
I (31242) pppos_example: Modem Connect to PPP Server
I (31242) esp-netif_lwip-ppp: Connected
I (31242) pppos_example: ~~~~~~~~~~~~~~
I (31242) pppos_example: IP          : 11.61.236.24
I (31252) pppos_example: Netmask     : 255.255.255.255
I (31252) pppos_example: Gateway     : 192.168.254.254
I (31262) pppos_example: Name Server1: 213.87.142.85
I (31262) pppos_example: Name Server2: 213.87.142.84
I (31272) pppos_example: ~~~~~~~~~~~~~~
I (31272) pppos_example: GOT ip event!!!
I (31282) pppos_example: PPP state changed event 0
I (31282) pppos_example: MQTT other event id: 7
I (31292) pppos_example: Waiting for MQTT data
I (32812) pppos_example: MQTT_EVENT_CONNECTED
I (32812) pppos_example: sent subscribe successful, msg_id=24787
I (33182) pppos_example: MQTT_EVENT_SUBSCRIBED, msg_id=24787
I (33192) pppos_example: sent publish successful, msg_id=0
I (33492) pppos_example: MQTT_EVENT_DATA
TOPIC=/topic/esp-pppos
DATA=esp32-pppos
I (33812) esp-netif_lwip-ppp: User interrupt
I (33812) pppos_example: PPP state changed event 5
I (33812) pppos_example: User interrupted event from netif:0x3ffb9440
I (33822) esp_modem_netif: PPP state changed event 5
I (34012) pppos_example: IMSI=250017149186727
I (34012) main_task: Returned from app_main()

Here is the log from cmux client after delay increase:

I (1442) main_task: Calling app_main()
System start
V (1952) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (1952) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (1952) intr_alloc: Connected src 50 to int 13 (cpu 0)
I (1952) gpio: GPIO[35]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:2 
V (1962) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (1972) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (1982) intr_alloc: Connected src 22 to int 17 (cpu 0)
I (1992) cmux_example: Success init axp20x !!!
I (2002) cmux_example: DC2: 1800 mV
I (2002) cmux_example: DC3: 3300 mV
I (2002) cmux_example: LDO2: 3300 mV
I (2002) cmux_example: LDO3: 3300 mV
I (2012) cmux_example: LDO4: DISABLE
I (2012) cmux_example: Exten: ENABLE
I (2022) cmux_example: setChargeControlCur:15
I (2032) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2032) gpio: GPIO[25]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2242) cmux_example: Modem power has been setup
D (62242) event: running task for loop 0x3ffb9f44
D (62242) event: created task for loop 0x3ffb9f44
D (62242) event: created event loop 0x3ffb9f44
D (62242) esp_netif_lwip: LwIP stack has been initialized
D (62242) esp_netif_lwip: esp-netif has been successfully initialized
I (62252) uart: ESP_INTR_FLAG_IRAM flag not set while CONFIG_UART_ISR_IN_IRAM is enabled, flag updated
I (62262) uart: queue free spaces: 30
V (62262) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (62272) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (62282) intr_alloc: Connected src 35 to int 18 (cpu 0)
D (62292) esp_netif_lwip: check: remote, if=0x3ffb8c10 fn=0x400ebc10
0x400ebc10: esp_netif_new_api at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:690

V (62292) esp_netif_objects: esp_netif_add_to_list_unsafe 0x3ffbf388
D (62302) esp_netif_objects: esp_netif_add_to_list_unsafe netif added successfully (total netifs: 1)
D (62312) esp-netif_lwip-ppp: esp_netif_new_ppp: PPP connection created: 0x3ffbf5b8
D (62312) esp-netif_lwip-ppp: Phase Dead
D (62322) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (62322) esp_netif_lwip: check: remote, if=0x3ffbf388 fn=0x400ec364
0x400ec364: esp_netif_ppp_set_auth_api at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:2503

D (62332) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (62342) cmux_example: PPP auth set
V (62342) command_lib: set_flow_control
V (62342) command_lib: generic_command_common
V (62352) command_lib: generic_command
D (62352) command_lib: generic_command command AT+IFC=2,2

D (62362) command_lib: Response: 
OK

I (62362) cmux_example: set_flow_control OK
V (62372) command_lib: set_echo
V (62372) command_lib: generic_command_common
V (62372) command_lib: generic_command
D (62382) command_lib: generic_command command ATE0

D (62382) command_lib: Response: 
OK

V (62392) command_lib: set_pdp_context
V (62392) command_lib: generic_command_common
V (62392) command_lib: generic_command
D (62402) command_lib: generic_command command AT+CGDCONT=1,"IP","internet.mts.ru"

D (62412) command_lib: Response: 
OK

V (62412) command_lib: set_data_mode
V (62412) command_lib: generic_command
D (62422) command_lib: generic_command command ATD*99#

D (62432) command_lib: Response: 
CONNECT

D (62432) esp_netif_handlers: esp_netif action has started with netif0x3ffbf388 from event_id=0
D (62432) esp_netif_lwip: check: remote, if=0x3ffbf388 fn=0x400ebe80
0x400ebe80: esp_netif_start_api at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:1068

D (62442) esp_netif_lwip: esp_netif_start_api 0x3ffbf388
D (62452) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3ffbf5b8
D (62452) esp-netif_lwip-ppp: Phase Start
D (62462) esp-netif_lwip-ppp: Phase Establish
D (62462) esp_netif_lwip: check: local, if=0x3ffbf388 fn=0x400ec598
0x400ec598: esp_netif_update_default_netif_lwip at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:316

D (62472) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffbf388
V (62482) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3ffbf388
D (62482) esp_netif_lwip: call api in lwip: ret=0x0, give sem
E (62492) cmux_example: esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with 1
D (62502) esp_netif_handlers: esp_netif action stopped with netif0x3ffbf388 from event_id=0
D (62502) esp-netif_lwip-ppp: Phase Authenticate
D (62512) esp_netif_lwip: check: remote, if=0x3ffbf388 fn=0x400ec068
0x400ec068: esp_netif_stop_api at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:1167

D (62512) esp-netif_lwip-ppp: Phase Network
D (62522) esp-netif_lwip-ppp: esp_netif_stop_ppp: Stopped PPP connection: 0x3ffbf5b8
D (62532) esp-netif_lwip-ppp: Phase Terminate
D (62532) esp-netif_lwip-ppp: Phase Establish
D (62542) esp_netif_lwip: check: local, if=0x3ffbf388 fn=0x400ec598
0x400ec598: esp_netif_update_default_netif_lwip at /home/espidf521/esp/esp-idf-v5.2.1/components/esp_netif/lwip/esp_netif_lwip.c:316

D (62542) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffbf388
V (62552) esp_netif_objects: esp_netif_next_unsafe 0x0
V (62552) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3ffbf388
V (62562) esp_netif_objects: esp_netif_next_unsafe 0x3ffbf388
D (62572) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (62572) esp-netif_lwip-ppp: Phase Disconnect
D (62582) esp-netif_lwip-ppp: Phase Dead
I (62582) esp-netif_lwip-ppp: User interrupt
D (62582) event: running post NETIF_PPP_STATUS:5 with handler 0x400dc998 and context 0x3ffc0930 on loop 0x3ffb9f44
0x400dc998: esp_modem::Netif::on_ppp_changed(void*, char const*, long, void*) at /home/espidf521/esp32-workspace/simple_cmux_client/managed_components/espressif__esp_modem/src/esp_modem_netif.cpp:22

I (62592) esp_modem_netif: PPP state changed event 5
V (62602) intr_alloc: esp_intr_free: Disabling int, killing handler
I (62612) main_task: Returned from app_main()

espressif / esp-protocols

LwIP PPP connection close and no authentication (IDFGH-12720) #562

Answers checklist.

General issue report