ESP32-S3 esp_modem ppp_os mqtt MUX and other questions

lebies
Posts: 7
Joined: Wed Nov 24, 2021 5:45 am

ESP32-S3 esp_modem ppp_os mqtt MUX and other questions

Postby lebies » Mon Oct 02, 2023 2:43 pm

Hi,
I'm hoping @David_Cermac or someone like you will be able to help me here please.

We've implemented the Quectel EG915N LTE Cat1 chip on a custom ESP32-S3 board. So far everything hardware-wise comes up as expected and seems to be working (PWRKEY, RSTKEY, and general GPIO required to make it work).
I'm using the pppos-client example to get things working and to better understand the esp_modem component.

I am NOT a C++ officiando and am really struggling to get going! I am used to the 'official' espidf way of thinking (ie events, tasks, callbacks and so on) and am confused as all hell by what to me feels like a very convoluted implementation of this component! Let me be quick to add that that's because of my lack of understanding of C++ - NOT the team, whom have done a sterling job of the espidf api!

I have managed thus far to add EG915-specific AT modem commands and get LTE and GPS running and connected over PPPOS.
Here are a few 'issues' I have so far:
1. I do not get DNS Name server addresses automatically, so I set them in code.
2. I cannot connect to an MQTT broker (tried a few different public test ones that I know are up and running).

These are things I can drill down into (and spend a lot of time on) and potentially solve. I'm sure though that someone here will be far better equipped to quickly identify the problem(s). Help VERY much appreciated!!!

Now for my bigger ask!
The EG915 exposes 5 interfaces and 11 endpoints as follows:
  • 0 - ECM -> config management (CDC-CTRL)
    1 - ECM -> data comms (CDC-DATA)
    2 - DM -> diagnostic port
    3 - AT int -> AT commands
    4 - MODEM -> PPP connection
Each Interface with 1 or more Endpoints, eg
  • IF_3 -> 0x89, IN, ID=9, MaxPkt 64
    -> 0x86, IN, ID=6, MaxPkt 512
    -> 0x0F, OUT, ID=15, MaxPkt 512 -> some IN/OUT are BULK and some INT
    ...
So now I want to implement what I think should be MUXes to connect the various interfaces up to independent ports/terminals and have each run in it's own "espidf-traditional" context, ie. events, tasks and callbacks, etc).

And I'm totally stumped! (and very frustrated feeling like I'm running up my own you-know-what!

Questions:
Is there an example somewhere that actually properly/completely sets up an LTE modem like this somewhere to use as a reference?
If not, I'm willing to get this one setup and running to make available to others potentially struggling - with the help of an expert here. I will do all the code slog work, I just need to get a better understanding of this group of components.

The code:

Code: Select all

/*
 * 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 <string.h>
#include "freertos/FreeRTOS.h"
#include "freertos/event_groups.h"
#include "esp_netif.h"
#include "esp_netif_ppp.h"
#include "esp_netif_ip_addr.h"
#include "lwip/ip4_addr.h"
#include "lwip/sockets.h"
#include "lwip/dns.h"
#include "esp_netif_net_stack.h"
#include "lwip/netif.h"

#include "mqtt_client.h"
#include "esp_modem_api.h"
#include "esp_log.h"
#include "driver/gpio.h"
#include "esp_intr_alloc.h"
#include "sdkconfig.h"

#define CONFIG_FREERTOS_HZ 100
// #define CONFIG_PPP_SUPPORT

#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

static const char *TAG = "pppos_example";
static EventGroupHandle_t event_group = NULL;
static const int CONNECT_BIT = BIT0;
static const int GOT_DATA_BIT = BIT2;
static const int USB_DISCONNECTED_BIT = BIT3; // Used only with USB DTE but we define it unconditionally, to avoid too many #ifdefs in the code

#include "esp_modem_usb_c_api.h"
#include "esp_modem_usb_config.h"
#include "freertos/task.h"

// outputs
const gpio_num_t VBAT = GPIO_NUM_12;
const gpio_num_t VBUS = GPIO_NUM_16;
const gpio_num_t PWRKEY = GPIO_NUM_14;
const gpio_num_t RSTKEY = GPIO_NUM_13;
// inputs
const gpio_num_t STAT = GPIO_NUM_8;
const gpio_num_t NET_STAT = GPIO_NUM_7;
const gpio_num_t SIM_DET = GPIO_NUM_48;

static void usb_terminal_error_handler(esp_modem_terminal_error_t err)
{
    if (err == ESP_MODEM_TERMINAL_DEVICE_GONE) {
        ESP_LOGI(TAG, "USB modem disconnected");
        assert(event_group);
        xEventGroupSetBits(event_group, USB_DISCONNECTED_BIT);
    }
}

#define CHECK_USB_DISCONNECTION(event_group) \
if ((xEventGroupGetBits(event_group) & USB_DISCONNECTED_BIT) == USB_DISCONNECTED_BIT) { \
    esp_modem_destroy(dce); \
    continue; \
}

static void mqtt_event_handler(void *handler_args, esp_event_base_t base, int32_t event_id, void *event_data)
{
    ESP_LOGD(TAG, "Event dispatched from event loop base=%s, event_id=%d", base, event_id);
    esp_mqtt_event_handle_t event = (esp_mqtt_event_handle_t)event_data;
    esp_mqtt_client_handle_t client = event->client;
    int msg_id;
    switch ((esp_mqtt_event_id_t)event_id) {
    case MQTT_EVENT_CONNECTED:
        ESP_LOGI(TAG, "MQTT_EVENT_CONNECTED");
        // msg_id = esp_mqtt_client_subscribe(client, CONFIG_EXAMPLE_MQTT_TEST_TOPIC, 0);
        msg_id = esp_mqtt_client_subscribe(client, "/topic/esp-pppos", 0);
        ESP_LOGI(TAG, "sent subscribe successful, msg_id=%d", msg_id);
        break;
    case MQTT_EVENT_DISCONNECTED:
        ESP_LOGI(TAG, "MQTT_EVENT_DISCONNECTED");
        break;
    case MQTT_EVENT_SUBSCRIBED:
        ESP_LOGI(TAG, "MQTT_EVENT_SUBSCRIBED, msg_id=%d", event->msg_id);
        // msg_id = esp_mqtt_client_publish(client, CONFIG_EXAMPLE_MQTT_TEST_TOPIC, CONFIG_EXAMPLE_MQTT_TEST_DATA, 0, 0, 0);
        msg_id = esp_mqtt_client_publish(client, "/topic/esp-pppos", "esp32-pppos", 0, 0, 0);
        ESP_LOGI(TAG, "sent publish successful, msg_id=%d", msg_id);
        break;
    case MQTT_EVENT_UNSUBSCRIBED:
        ESP_LOGI(TAG, "MQTT_EVENT_UNSUBSCRIBED, msg_id=%d", event->msg_id);
        break;
    case MQTT_EVENT_PUBLISHED:
        ESP_LOGI(TAG, "MQTT_EVENT_PUBLISHED, msg_id=%d", event->msg_id);
        break;
    case MQTT_EVENT_DATA:
        ESP_LOGI(TAG, "MQTT_EVENT_DATA");
        printf("TOPIC=%.*s\r\n", event->topic_len, event->topic);
        printf("DATA=%.*s\r\n", event->data_len, event->data);
        xEventGroupSetBits(event_group, GOT_DATA_BIT);
        break;
    case MQTT_EVENT_ERROR:
        ESP_LOGI(TAG, "MQTT_EVENT_ERROR");
        break;
    default:
        ESP_LOGI(TAG, "MQTT other event id: %d", event->event_id);
        break;
    }
}

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 = (esp_netif_t *)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 Connected to PPP Server");
        ESP_LOGI(TAG, "~~~~~~~~~~~~~~");
        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));

        // esp_netif_dhcp_status_t dhcp_status;
        // esp_netif_dhcpc_get_status(netif, &dhcp_status);
        // ESP_LOGI(TAG, "DHCP Status: %d", (int)dhcp_status);
        char buf[32] = {0};
        esp_ip4_addr_t tdnsip;
        esp_netif_dhcpc_option(netif, ESP_NETIF_OP_GET, ESP_NETIF_DOMAIN_NAME_SERVER, &tdnsip, 4);
        sprintf(buf, IPSTR, IP2STR(&tdnsip));
        ESP_LOGI(TAG, "DNS ns: %s", buf);
        
        ip_addr_t dnsip0 = IPADDR4_INIT_BYTES(8,8,8,8);
        dns_setserver(0, &dnsip0);
        ip_addr_t dnsip1 = IPADDR4_INIT_BYTES(8,8,4,4);
        dns_setserver(1, &dnsip1);

        esp_netif_get_dns_info(netif, (esp_netif_dns_type_t)0, &dns_info);
        ESP_LOGI(TAG, "Name Server1: " IPSTR, IP2STR(&dns_info.ip.u_addr.ip4));
        esp_netif_get_dns_info(netif, (esp_netif_dns_type_t)1, &dns_info);
        ESP_LOGI(TAG, "Name Server2: " IPSTR, IP2STR(&dns_info.ip.u_addr.ip4));
        ESP_LOGI(TAG, "~~~~~~~~~~~~~~");
        xEventGroupSetBits(event_group, CONNECT_BIT);

        ESP_LOGI(TAG, "GOT ip event!!!");
    
    } else if (event_id == IP_EVENT_PPP_LOST_IP) {
        ESP_LOGI(TAG, "Modem Disconnected 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));
    }
}

esp_err_t config_lte_pins()
{
    // inputs
    esp_rom_gpio_pad_select_gpio(STAT);
    gpio_set_direction(STAT, GPIO_MODE_INPUT);
    gpio_pullup_en(STAT);
    esp_rom_gpio_pad_select_gpio(SIM_DET);
    gpio_set_direction(SIM_DET, GPIO_MODE_INPUT);
    esp_rom_gpio_pad_select_gpio(NET_STAT);
    gpio_set_direction(NET_STAT, GPIO_MODE_INPUT);
    esp_rom_gpio_pad_select_gpio(SIM_DET);
    gpio_set_direction(SIM_DET, GPIO_MODE_INPUT);

    // outputs
    esp_rom_gpio_pad_select_gpio(VBAT);
    gpio_set_direction(VBAT, GPIO_MODE_OUTPUT);
    esp_rom_gpio_pad_select_gpio(VBUS);
    gpio_set_direction(VBUS, GPIO_MODE_OUTPUT);
    esp_rom_gpio_pad_select_gpio(PWRKEY);
    gpio_set_direction(PWRKEY, GPIO_MODE_OUTPUT);
    esp_rom_gpio_pad_select_gpio(RSTKEY);
    gpio_set_direction(RSTKEY, GPIO_MODE_OUTPUT);

    return ESP_OK;
}

void app_main(void)
{
    esp_err_t err;

    config_lte_pins();

    /* 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 */
    char buf[30];
    memset(buf, 0, 30);
    sprintf(buf, "\"internet\",\"0.0.0.0\",0,0");
    esp_modem_dce_config_t dce_config = ESP_MODEM_DCE_DEFAULT_CONFIG(buf); //1,"IP","internet","0.0.0.0",0,0
    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 DTE */
    while (1) 
    {
        ESP_LOGI(TAG, "Initializing esp_modem (GENERIC module)...");

        struct esp_modem_usb_term_config usb_config = ESP_MODEM_DEFAULT_USB_CONFIG(0x2C7C, 0x6002, 3);
        usb_config.timeout_ms = 30000;
        esp_modem_dce_device_t usb_dev_type = ESP_MODEM_DCE_GENETIC;
        const esp_modem_dte_config_t dte_config = ESP_MODEM_DTE_DEFAULT_USB_CONFIG(usb_config);

        ESP_LOGW(TAG, "POWER CYCLE MODEM...");
        // precondition signals
        gpio_set_level(PWRKEY, 0);      // HI
        gpio_set_level(RSTKEY, 1);      // LO
        gpio_set_level(VBAT, 1);     // power up LTE chip
        gpio_set_level(VBUS, 1);        // power up VBUS ref
        vTaskDelay(50 / portTICK_PERIOD_MS);    // 50ms wait VBAT stable
        
        //RESET LTE chip
        gpio_set_level(PWRKEY, 1);      // LO
        vTaskDelay(30 / portTICK_PERIOD_MS);    // 30ms then RESET HI
        gpio_set_level(RSTKEY, 0);      // HI

        vTaskDelay(470 / portTICK_PERIOD_MS);   // 500ms total
        gpio_set_level(PWRKEY, 0);      // HI

        ESP_LOGW(TAG, "wait STATUS loop...");
        ESP_LOGI(TAG, "level: %d", gpio_get_level(STAT));
        do
        {
            vTaskDelay(10 / portTICK_PERIOD_MS);
        } while ( 1 == gpio_get_level(STAT) );              // this should occur at around 7.5 secs
        ESP_LOGI(TAG, "level: %d", gpio_get_level(STAT));
        ESP_LOGW(TAG, "SIM_DETECT => %d", gpio_get_level(SIM_DET));

        ESP_LOGW(TAG, "MODEM BOOTED");
        ESP_LOGI(TAG, "Setup USB device connection...");
        esp_modem_dce_t *dce = esp_modem_new_dev_usb(usb_dev_type, &dte_config, &dce_config, esp_netif);
        assert(dce);
        esp_modem_set_error_cb(dce, usb_terminal_error_handler);

        xEventGroupClearBits(event_group, CONNECT_BIT | GOT_DATA_BIT | USB_DISCONNECTED_BIT);
        vTaskDelay(5000 / portTICK_PERIOD_MS);  //mandatory no_comms delay

        /* modem commands */
        /* kickstart at cmd uart interface */
        err = esp_modem_sync(dce);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_sync failed with %d %s", err, esp_err_to_name(err));
            return;
        }

        // echo OFF
        err = esp_modem_set_echo(dce, false);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_sync failed with %d %s", err, esp_err_to_name(err));
            return;
        }

        // set CREG to register network
        err = esp_modem_set_creg_status_eg915(dce, 1);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_set_creg_status_eg915(1) failed with %d %s", err, esp_err_to_name(err));
            return;
        }
        ESP_LOGI(TAG, "CREG_set: 1");

        vTaskDelay(1000 / portTICK_PERIOD_MS);  // wait for register
        
        // get CREG status
        int typ = 0;
        int stat = 0;
        err = esp_modem_get_creg_status_eg915(dce, &typ, &stat);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_get_creg_status_eg915 failed with %d %s", err, esp_err_to_name(err));
            return;
        }
        ESP_LOGI(TAG, "CREG_stat: %d,%d", typ, stat);

        // set CFUN to fully functional
        err = esp_modem_set_radio_state(dce, 1);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_set_radio_state(1) failed with %d %s", err, esp_err_to_name(err));
            return;
        }
        ESP_LOGI(TAG, "CFUN_set: 1");

        // get CFUN
        int cfun = -1;
        err = esp_modem_get_radio_state(dce, &cfun);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_get_creg_status_eg915 failed with %d %s", err, esp_err_to_name(err));
            return;
        }
        ESP_LOGI(TAG, "CFUN_stat: %d", cfun);

        // setup GNSS nmea sentences
        err = esp_modem_set_gnss_nmea_rmc_eg915(dce, 2);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_set_gnss_nmea_rmc_eg915(2) failed with %d %s", err, esp_err_to_name(err));
            return;
        }

        // setup GNSS nmea source
        err = esp_modem_set_gnss_nmea_src_eg915(dce, 1);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_set_gnss_nmea_src_eg915(1) failed with %d %s", err, esp_err_to_name(err));
            return;
        }

        // setup GNSS nmea sentence outport
        // defaults to "usbnmea" port
        // char buf[10];
        // memset(buf, 0, 10);
        // sprintf(buf, "\"usbnmea\"");
        // err = esp_modem_set_gnss_outport_eg915(dce, buf);
        // if (err != ESP_OK) {
        //     ESP_LOGE(TAG, "esp_modem_set_gnss_outport_eg915(usbnmea) failed with %d %s", err, esp_err_to_name(err));
        //     return;
        // }

        char operator_name[30] = {0};
        int act = 0;
        err = esp_modem_get_operator_name(dce, &operator_name[0], &act);
        ESP_LOGW(TAG, "operator: %s", operator_name);

        // Powerup GNSS
        err = esp_modem_set_gnss_power_mode_eg915(dce, 1);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_set_gnss_power_mode(1) failed with %d %s", err, esp_err_to_name(err));
            return;
        }

        // get a reading with AT+QGPSLOC
        // char buf[256];  // = {0};
        // memset(buf, 0, 256);
        // err = esp_modem_get_gnss_location_eg915(dce, &buf[0]);
        // if (err != ESP_OK) {
        //     ESP_LOGE(TAG, "esp_modem_set_gnss_power_mode(1) failed with %d %s", err, esp_err_to_name(err));
        //     return;
        // }
        // ESP_LOGW(TAG, "GNSS_loc: %s", buf);

        vTaskDelay(5000 / portTICK_PERIOD_MS);  //let's see what comes in and when...
     
        // ESP_LOGI(TAG, "modem_set_data_mode()");
        err = esp_modem_set_mode(dce, ESP_MODEM_MODE_DATA);
        if (err != ESP_OK) {
            ESP_LOGE(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_DATA) failed with %d", err);
            return;
        }
        ESP_LOGI(TAG, "modem_set_mode(ESP_MODEM_MODE_DATA)");

        /* Wait for IP address */
        ESP_LOGI(TAG, "Waiting for IP address");
        xEventGroupWaitBits(event_group, CONNECT_BIT | USB_DISCONNECTED_BIT, pdFALSE, pdFALSE, portMAX_DELAY);
        CHECK_USB_DISCONNECTION(event_group);

        /* Config MQTT */
        esp_mqtt_client_config_t mqtt_config = {
            // .broker.address.uri = "mqtt://test.mosquitto.org",
            .broker.address = {
                // .uri = "mqtt://test.mosquitto.org",	<- DNS lookup fails!
                .hostname = "91.121.93.94",
                // .uri = "mqtt://mqtt.eclipseprojects.io",
                // .hostname = "137.135.83.217",
                .transport = MQTT_TRANSPORT_OVER_TCP,
                .port = 1883,
            }
        };
        esp_mqtt_client_handle_t mqtt_client = esp_mqtt_client_init(&mqtt_config);
        esp_mqtt_client_register_event(mqtt_client, (esp_mqtt_event_id_t)ESP_EVENT_ANY_ID, mqtt_event_handler, NULL);
        esp_mqtt_client_start(mqtt_client);

        ESP_LOGI(TAG, "Waiting for MQTT data");
        xEventGroupWaitBits(event_group, GOT_DATA_BIT | USB_DISCONNECTED_BIT, pdFALSE, pdFALSE, portMAX_DELAY);
        CHECK_USB_DISCONNECTION(event_group);

        esp_mqtt_client_destroy(mqtt_client);
        // err = esp_modem_set_mode(dce, ESP_MODEM_MODE_COMMAND);
        // if (err != ESP_OK) {
        //     ESP_LOGE(TAG, "esp_modem_set_mode(ESP_MODEM_MODE_COMMAND) failed with %d", err);
        //     return;
        // }
        // char imsi[32];
        // imsi.;
        // err = esp_modem_get_imsi(dce, imsi);
        // if (err != ESP_OK) {
        //     ESP_LOGE(TAG, "esp_modem_get_imsi failed with %d", err);
        //     return;
        // }
        // ESP_LOGI(TAG, "IMSI=%s", imsi);

    // #if defined(CONFIG_EXAMPLE_SERIAL_CONFIG_USB)
        // USB example runs in a loop to demonstrate hot-plugging and sudden disconnection features.
        ESP_LOGI(TAG, "USB demo finished. Disconnect and connect the modem to run it again");
        xEventGroupWaitBits(event_group, USB_DISCONNECTED_BIT, pdFALSE, pdFALSE, portMAX_DELAY);
        CHECK_USB_DISCONNECTION(event_group); // dce will be destroyed here
    } // while (1)

// #else
//     // UART DTE clean-up
//     esp_modem_destroy(dce);
//     esp_netif_destroy(esp_netif);
// #endif
}
And the debug log:

Code: Select all

PS P:\projects\io\airkey\dev\ak-idf-lte> set IDF_PATH=C:\Espressif\frameworks\esp-idf-v5.1
PS P:\projects\io\airkey\dev\ak-idf-lte> C:\Espressif\python_env\idf5.1_py3.11_env\Scripts\python.exe C:\Espressif\frameworks\esp-idf-v5.1\tools\idf_monitor.py -p COM3 -b 115200 --toolchain-prefix xtensa-esp32s3-elf- --target esp32s3 p:\projects\io\airkey\dev\ak-idf-lte\build\ak-idf-lte.elf
--- WARNING: GDB cannot open serial ports accessed as COMx
--- Using \\.\COM3 instead...
--- idf_monitor on \\.\COM3 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x2b (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3818,len:0x16e4
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (27) boot: ESP-IDF v5.1-dirty 2nd stage bootloader
I (27) boot: compile time Sep 28 2023 06:53:26
I (27) boot: Multicore bootloader
I (30) boot: chip revision: v0.1
I (34) boot.esp32s3: Boot SPI Speed : 80MHz   
I (39) boot.esp32s3: SPI Mode       : DIO
I (44) boot.esp32s3: SPI Flash Size : 8MB
I (48) boot: Enabling RNG early entropy source...
I (54) boot: Partition Table:
I (57) boot: ## Label            Usage          Type ST Offset   Length
I (65) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (72) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (80) boot:  2 factory          factory app      00 00 00010000 00100000
I (87) boot: End of partition table
I (91) esp_image: segment 0: paddr=00010020 vaddr=3c080020 size=2f160h (192864) map
I (134) esp_image: segment 1: paddr=0003f188 vaddr=3fc92900 size=00e90h (  3728) load
I (136) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=76ae0h (486112) map
I (227) esp_image: segment 3: paddr=000b6b08 vaddr=3fc93790 size=01c34h (  7220) load
I (229) esp_image: segment 4: paddr=000b8744 vaddr=40374000 size=0e81ch ( 59420) load
I (252) boot: Loaded app from partition at offset 0x10000
I (252) boot: Disabling RNG early entropy source...      
I (264) cpu_start: Multicore app
D (264) flash HPM: HPM with dummy, status is 3
I (264) cpu_start: Pro cpu up.
I (265) cpu_start: Starting app cpu, entry point is 0x40375438
0x40375438: call_start_cpu1 at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_system/port/cpu_start.c:154

I (0) cpu_start: App cpu up.
D (280) clk: RTC_SLOW_CLK calibration value: 3521306
I (292) cpu_start: Pro cpu start user code
I (292) cpu_start: cpu freq: 240000000 Hz
I (292) cpu_start: Application information:
I (295) cpu_start: Project name:     ak-idf-lte
I (300) cpu_start: App version:      1
I (305) cpu_start: Compile time:     Sep 30 2023 11:12:13
I (311) cpu_start: ELF file SHA256:  0e7f3968c9b41dda...
I (317) cpu_start: ESP-IDF:          v5.1-dirty
I (322) cpu_start: Min chip rev:     v0.0
I (327) cpu_start: Max chip rev:     v0.99 
I (331) cpu_start: Chip rev:         v0.1
D (336) memory_layout: Checking 5 reserved memory ranges:
D (342) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc92900
D (348) memory_layout: Reserved memory range 0x3fc92900 - 0x3fc96d90
D (354) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (361) memory_layout: Reserved memory range 0x40374000 - 0x40382900
0x40374000: _WindowOverflow4 at C:/Espressif/frameworks/esp-idf-v5.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:2013

D (367) memory_layout: Reserved memory range 0x600fe000 - 0x600fe010  
D (374) memory_layout: Building list of available memory regions:     
D (380) memory_layout: Available memory region 0x3fc96d90 - 0x3fca0000
D (386) memory_layout: Available memory region 0x3fca0000 - 0x3fcb0000
D (393) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
D (400) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
D (406) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
D (413) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710
D (419) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34
D (426) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
D (433) memory_layout: Available memory region 0x600fe010 - 0x60100000
I (439) heap_init: Initializing. RAM available for dynamic allocation:
D (447) heap_init: New heap initialised at 0x3fc96d90
I (452) heap_init: At 3FC96D90 len 00052980 (330 KiB): DRAM
I (458) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
D (465) heap_init: New heap initialised at 0x3fcf0000
I (470) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (476) heap_init: New heap initialised at 0x600fe010
I (481) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM
D (487) intr_alloc: Connected src 39 to int 2 (cpu 0)
D (493) spi_flash: trying chip: issi
D (496) spi_flash: trying chip: gd
I (499) spi_flash: detected chip: gd
I (504) spi_flash: flash io: dio
D (508) cpu_start: calling init function: 0x42062158
0x42062158: _GLOBAL__sub_I__ZN17__eh_globals_init7_S_initE at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32s3-elf/src/gcc/libstdc++-v3/libsupc++/eh_globals.cc:168

D (513) cpu_start: calling init function: 0x42061fa8
0x42061fa8: _GLOBAL__sub_I__ZN9__gnu_cxx9__freeresEv at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32s3-elf/src/gcc/libstdc++-v3/libsupc++/eh_alloc.cc:342

D (518) cpu_start: calling init function: 0x42056aac
0x42056aac: esp_ds_conn_lock at C:/Espressif/frameworks/esp-idf-v5.1/components/mbedtls/port/esp_ds/esp_rsa_sign_alt.c:49

D (523) cpu_start: calling init function: 0x4201ef88
0x4201ef88: esp_ipc_init at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_system/esp_ipc.c:114

D (528) cpu_start: calling init function: 0x42002fd4
0x42002fd4: esp_init_app_elf_sha256 at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_app_format/esp_app_desc.c:69

D (533) cpu_start: calling init function: 0x420080a4 on core: 0
0x420080a4: __esp_system_init_fn_esp_timer_startup_init at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_timer/src/esp_timer.c:575

D (539) intr_alloc: Connected src 59 to int 3 (cpu 0)
D (544) cpu_start: calling init function: 0x42005b64 on core: 0
0x42005b64: __esp_system_init_fn_esp_sleep_startup_init at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_hw_support/sleep_gpio.c:188

I (550) sleep: Configure to isolate all GPIO pins in sleep state
I (557) sleep: Enable automatic switching of GPIO sleep configuration
D (564) cpu_start: calling init function: 0x4200410c on core: 0
0x4200410c: __esp_system_init_fn_init_components0 at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_system/startup.c:486

D (570) intr_alloc: Connected src 79 to int 9 (cpu 0)
I (575) app_start: Starting scheduler on CPU0
D (580) intr_alloc: Connected src 57 to int 12 (cpu 0)
D (580) intr_alloc: Connected src 80 to int 2 (cpu 1)
I (590) app_start: Starting scheduler on CPU1
D (590) intr_alloc: Connected src 58 to int 3 (cpu 1)
I (580) main_task: Started on CPU0
D (600) heap_init: New heap initialised at 0x3fce9710
D (600) intr_alloc: Connected src 52 to int 13 (cpu 0)
I (610) main_task: Calling app_main()
D (620) esp_netif_lwip: LwIP stack has been initialized
D (620) esp_netif_lwip: check: remote, if=0x0 fn=0x4203f4b4
0x4203f4b4: alloc_client_data_id at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_netif/lwip/esp_netif_lwip.c:166

D (630) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (630) esp_netif_lwip: esp-netif has been successfully initialized
D (640) event: running task for loop 0x3fc9cf98
D (640) event: created task for loop 0x3fc9cf98
D (650) event: created event loop 0x3fc9cf98
D (650) esp_netif_objects: esp_netif_add_to_list 0x3fc9df38
D (660) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (670) esp-netif_lwip-ppp: esp_netif_new_ppp: PPP connection created: 0x3fc9e24c
D (670) esp_netif_lwip: check: remote, if=0x0 fn=0x4203f4c4
0x4203f4c4: set_lwip_netif_callback at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_netif/lwip/esp_netif_lwip.c:174

D (680) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (680) pppos_example: Initializing esp_modem (BG96 module)...
W (690) pppos_example: POWER CYCLE MODEM...
W (1250) pppos_example: wait STATUS loop...
I (1250) pppos_example: level: 1
I (8320) pppos_example: level: 0
W (8320) pppos_example: SIM_DETECT => 0
W (8320) pppos_example: MODEM BOOTED
I (8320) pppos_example: Setup USB device connection...
D (8320) intr_alloc: Connected src 38 to int 17 (cpu 0)
D (8360) usb_terminal: USB Host installed
D (8360) cdc_acm: Checking list of opened USB devices
D (8360) cdc_acm: Checking list of connected USB devices
D (8410) cdc_acm: Checking list of connected USB devices
D (8460) cdc_acm: Checking list of connected USB devices
D (8510) cdc_acm: Checking list of connected USB devices
D (8560) cdc_acm: Checking list of connected USB devices
D (8610) cdc_acm: Checking list of connected USB devices
D (8660) cdc_acm: Checking list of connected USB devices
D (8670) HUB: Root port reset
D (8670) HUB: Stage done: START
D (8670) HUB: Stage done: GET_SHORT_DEV_DESC
D (8670) HUB: Stage done: CHECK_SHORT_DEV_DESC
D (8710) cdc_acm: Checking list of connected USB devices
D (8730) HUB: Stage done: SECOND_RESET
D (8730) HUB: Stage done: SET_ADDR
D (8730) HUB: Stage done: CHECK_ADDR
D (8740) HUB: Stage done: SET_ADDR_RECOVERY
D (8740) HUB: Stage done: GET_FULL_DEV_DESC
D (8740) HUB: Stage done: CHECK_FULL_DEV_DESC
D (8740) HUB: Stage done: GET_SHORT_CONFIG_DESC
D (8740) HUB: Stage done: CHECK_SHORT_CONFIG_DESC
D (8750) HUB: Stage done: GET_FULL_CONFIG_DESC
D (8750) HUB: Stage done: CHECK_FULL_CONFIG_DESC
D (8760) HUB: Stage done: SET_CONFIG
D (8760) HUB: Stage done: CHECK_CONFIG
D (8760) HUB: Stage done: GET_SHORT_LANGID_TABLE
D (8770) HUB: Stage done: CHECK_SHORT_LANGID_TABLE
D (8770) HUB: Stage done: GET_FULL_LANGID_TABLE
D (8780) HUB: Stage done: CHECK_FULL_LANGID_TABLE
D (8780) HUB: Stage done: GET_SHORT_MANU_STR_DESC
D (8790) HUB: Stage done: CHECK_SHORT_MANU_STR_DESC
D (8790) HUB: Stage done: GET_FULL_MANU_STR_DESC
D (8800) HUB: Stage done: CHECK_FULL_MANU_STR_DESC
D (8800) HUB: Stage done: GET_SHORT_PROD_STR_DESC
D (8810) HUB: Stage done: CHECK_SHORT_PROD_STR_DESC
D (8810) HUB: Stage done: GET_FULL_PROD_STR_DESC
D (8820) HUB: Stage done: CHECK_FULL_PROD_STR_DESC
D (8820) HUB: Stage done: GET_SHORT_SER_STR_DESC
D (8830) HUB: Stage done: CHECK_SHORT_SER_STR_DESC
D (8830) HUB: Stage done: GET_FULL_SER_STR_DESC
D (8840) HUB: Stage done: CHECK_FULL_SER_STR_DESC
D (8840) HUB: Stage done: CLEANUP
D (8840) USBH: Processing actions 0x100
D (8850) USBH: New device 1
D (8850) cdc_acm: New device connected
D (8850) cdc_acm: Checking list of connected USB devices
W (8860) cdc_acm: idVid / idPid: 2c7c / 6002
D (8870) CDC_ACM: Submitting poll for BULK IN transfer
D (8870) CDC_ACM: Submitting poll for INTR IN transfer
D (13880) command_lib: generic_command command AT

D (13880) usb_terminal: 0x3fc9a7fc   41 54 0d                                          |AT.|
D (13880) CDC_ACM: Submitting BULK OUT transfer
D (13880) CDC_ACM: out/ctrl xfer cb
D (13890) CDC_ACM: in xfer cb
D (13890) usb_terminal: 0x3fca261c   41 54 0d 0d 0a 4f 4b 0d  0a                       |AT...OK..|
D (13900) command_lib: Response: AT
OK

D (13900) CDC_ACM: Submitting poll for BULK IN transfer
D (13910) command_lib: generic_command command ATE0

D (13910) usb_terminal: 0x3fc9a7dc   41 54 45 30 0d                                    |ATE0.|
D (13920) CDC_ACM: Submitting BULK OUT transfer
D (13930) CDC_ACM: out/ctrl xfer cb
D (13930) CDC_ACM: in xfer cb
D (13930) usb_terminal: 0x3fca261c   41 54 45 30 0d 0d 0a 4f  4b 0d 0a                 |ATE0...OK..|
D (13940) command_lib: Response: ATE0
OK

D (13950) CDC_ACM: Submitting poll for BULK IN transfer
D (13950) command_lib: generic_command command AT+CREG=1

D (13960) usb_terminal: 0x3fc9a7f8   41 54 2b 43 52 45 47 3d  31 0d                    |AT+CREG=1.|
D (13970) CDC_ACM: Submitting BULK OUT transfer
D (13970) CDC_ACM: out/ctrl xfer cb
D (13980) CDC_ACM: in xfer cb
D (13980) usb_terminal: 0x3fca261c   0d 0a 4f 4b 0d 0a                                 |..OK..|
D (13990) command_lib: Response:
OK

D (13990) CDC_ACM: Submitting poll for BULK IN transfer
I (14000) pppos_example: CREG_set: 1
D (15000) usb_terminal: 0x3fc9a7cc   41 54 2b 43 52 45 47 3f  0d                       |AT+CREG?.|
D (15000) CDC_ACM: Submitting BULK OUT transfer
D (15000) CDC_ACM: out/ctrl xfer cb
D (15000) CDC_ACM: in xfer cb
D (15000) usb_terminal: 0x3fca261c   0d 0a 2b 43 52 45 47 3a  20 31 2c 31 0d 0a 0d 0a  |..+CREG: 1,1....|
D (15010) usb_terminal: 0x3fca262c   4f 4b 0d 0a                                       |OK..|
D (15020) CDC_ACM: Submitting poll for BULK IN transfer
I (15030) pppos_example: CREG_stat: 1,1
D (15030) command_lib: generic_command command AT+CFUN=1

D (15040) usb_terminal: 0x3fc9a7f8   41 54 2b 43 46 55 4e 3d  31 0d                    |AT+CFUN=1.|
D (15050) CDC_ACM: Submitting BULK OUT transfer
D (15050) CDC_ACM: out/ctrl xfer cb
D (15060) CDC_ACM: in xfer cb
D (15060) usb_terminal: 0x3fca261c   0d 0a 4f 4b 0d 0a                                 |..OK..|
D (15070) command_lib: Response:
OK

D (15070) CDC_ACM: Submitting poll for BULK IN transfer
I (15080) pppos_example: CFUN_set: 1
D (15080) usb_terminal: 0x3fc9a7d4   41 54 2b 43 46 55 4e 3f  0d                       |AT+CFUN?.|
D (15090) CDC_ACM: Submitting BULK OUT transfer
D (15100) CDC_ACM: out/ctrl xfer cb
D (15100) CDC_ACM: in xfer cb
D (15100) usb_terminal: 0x3fca261c   0d 0a 2b 43 46 55 4e 3a  20 31 0d 0a 0d 0a 4f 4b  |..+CFUN: 1....OK|
D (15110) usb_terminal: 0x3fca262c   0d 0a                                             |..|
D (15120) CDC_ACM: Submitting poll for BULK IN transfer
I (15120) pppos_example: CFUN_stat: 1
D (15130) command_lib: generic_command command AT+QGPSCFG="gpsnmeatype",2

D (15140) usb_terminal: 0x3fca3588   41 54 2b 51 47 50 53 43  46 47 3d 22 67 70 73 6e  |AT+QGPSCFG="gpsn|
D (15150) usb_terminal: 0x3fca3598   6d 65 61 74 79 70 65 22  2c 32 0d                 |meatype",2.|
D (15160) CDC_ACM: Submitting BULK OUT transfer
D (15160) CDC_ACM: out/ctrl xfer cb
D (15160) CDC_ACM: in xfer cb
D (15170) usb_terminal: 0x3fca261c   0d 0a 4f 4b 0d 0a                                 |..OK..|
D (15180) command_lib: Response:
OK


D (15180) CDC_ACM: Submitting poll for BULK IN transfer
D (15180) command_lib: generic_command command AT+QGPSCFG="nmeasrc",1

D (15190) usb_terminal: 0x3fca3588   41 54 2b 51 47 50 53 43  46 47 3d 22 6e 6d 65 61  |AT+QGPSCFG="nmea|
D (15200) usb_terminal: 0x3fca3598   73 72 63 22 2c 31 0d                              |src",1.|
D (15210) CDC_ACM: Submitting BULK OUT transfer
D (15210) CDC_ACM: out/ctrl xfer cb
D (15220) CDC_ACM: in xfer cb
D (15220) usb_terminal: 0x3fca261c   0d 0a 4f 4b 0d 0a                                 |..OK..|
D (15230) command_lib: Response:
OK

D (15230) CDC_ACM: Submitting poll for BULK IN transfer
D (15240) command_lib: generic_command command AT+QGPS=1

D (15250) usb_terminal: 0x3fc9a7f8   41 54 2b 51 47 50 53 3d  31 0d                    |AT+QGPS=1.|
D (15250) CDC_ACM: Submitting BULK OUT transfer
D (15260) CDC_ACM: out/ctrl xfer cb
D (15260) CDC_ACM: in xfer cb
D (15270) usb_terminal: 0x3fca261c   0d 0a 4f 4b 0d 0a                                 |..OK..|
D (15270) command_lib: Response:
OK

D (15280) CDC_ACM: Submitting poll for BULK IN transfer
D (17280) usb_terminal: 0x3fc9a7cc   41 54 2b 43 4f 50 53 3f  0d                       |AT+COPS?.|
D (17280) CDC_ACM: Submitting BULK OUT transfer
D (17280) CDC_ACM: out/ctrl xfer cb
D (17280) CDC_ACM: in xfer cb
D (17280) usb_terminal: 0x3fca261c   0d 0a 2b 43 4f 50 53 3a  20 30 2c 30 2c 22 4d 54  |..+COPS: 0,0,"MT|
D (17290) usb_terminal: 0x3fca262c   4e 53 41 20 49 74 73 41  6c 6c 41 62 6f 75 74 59  |NSA ItsAllAboutY|
D (17300) usb_terminal: 0x3fca263c   6f 75 22 2c 37 0d 0a 0d  0a 4f 4b 0d 0a           |ou",7....OK..|
D (17310) CDC_ACM: Submitting poll for BULK IN transfer
W (17320) pppos_example: operator: MTNSA ItsAllAboutYou
D (17430) CDC_ACM: in xfer cb
D (17430) usb_terminal: 0x3fca261c   0d 0a 2b 51 49 4e 44 3a  20 50 42 20 44 4f 4e 45  |..+QIND: PB DONE|
D (17430) usb_terminal: 0x3fca262c   0d 0a                                             |..|
D (17440) usb_terminal: Unhandled RX data
D (17440) CDC_ACM: Submitting poll for BULK IN transfer
D (17450) CDC_ACM: notif xfer cb
D (17450) usb_terminal: Ignored USB event 1
D (17460) CDC_ACM: Submitting poll for INTR IN transfer
D (17550) CDC_ACM: notif xfer cb
D (17550) usb_terminal: Ignored USB event 1
D (17550) CDC_ACM: Submitting poll for INTR IN transfer
D (19880) CDC_ACM: in xfer cb
D (19880) usb_terminal: 0x3fca261c   0d 0a 47 4e 53 53 20 55  70 64 61 74 65 20 73 75  |..GNSS Update su|
D (19880) usb_terminal: 0x3fca262c   63 63 65 73 73 65 64 21  21 21 21 0d 0a           |ccessed!!!!..|
D (19890) usb_terminal: Unhandled RX data
D (19890) CDC_ACM: Submitting poll for BULK IN transfer
D (19900) CDC_ACM: notif xfer cb
D (19900) usb_terminal: Ignored USB event 1
D (19910) CDC_ACM: Submitting poll for INTR IN transfer
D (20010) CDC_ACM: notif xfer cb
D (20010) usb_terminal: Ignored USB event 1
D (20010) CDC_ACM: Submitting poll for INTR IN transfer
D (34860) CDC_ACM: in xfer cb
D (34860) usb_terminal: 0x3fca261c   0d 0a 2b 43 52 45 47 3a  20 31 0d 0a              |..+CREG: 1..|
D (34860) usb_terminal: Unhandled RX data
D (34870) CDC_ACM: Submitting poll for BULK IN transfer
D (34870) CDC_ACM: notif xfer cb
D (34880) usb_terminal: Ignored USB event 1
D (34880) CDC_ACM: Submitting poll for INTR IN transfer
D (34990) CDC_ACM: notif xfer cb
D (34990) usb_terminal: Ignored USB event 1
D (34990) CDC_ACM: Submitting poll for INTR IN transfer
D (77320) command_lib: generic_command command ATE0

D (77320) usb_terminal: 0x3fc9a72c   41 54 45 30 0d                                    |ATE0.|
D (77320) CDC_ACM: Submitting BULK OUT transfer
D (77320) CDC_ACM: out/ctrl xfer cb
D (77330) CDC_ACM: in xfer cb
D (77330) usb_terminal: 0x3fca261c   0d 0a 4f 4b 0d 0a                                 |..OK..|
D (77340) command_lib: Response:
OK

D (77340) CDC_ACM: Submitting poll for BULK IN transfer
D (77350) command_lib: generic_command command AT+CGDCONT=1,"IP",""internet","0.0.0.0",0,0"

D (77360) usb_terminal: 0x3fca35ac   41 54 2b 43 47 44 43 4f  4e 54 3d 31 2c 22 49 50  |AT+CGDCONT=1,"IP|
D (77370) usb_terminal: 0x3fca35bc   22 2c 22 22 69 6e 74 65  72 6e 65 74 22 2c 22 30  |",""internet","0|
D (77380) usb_terminal: 0x3fca35cc   2e 30 2e 30 2e 30 22 2c  30 2c 30 22 0d           |.0.0.0",0,0".|
D (77380) CDC_ACM: Submitting BULK OUT transfer
D (77390) CDC_ACM: out/ctrl xfer cb
D (77450) CDC_ACM: in xfer cb
D (77450) usb_terminal: 0x3fca261c   0d 0a 4f 4b 0d 0a                                 |..OK..|
D (77450) command_lib: Response:
OK

D (77450) CDC_ACM: Submitting poll for BULK IN transfer
D (77460) command_lib: generic_command command ATD*99#

D (77460) usb_terminal: 0x3fc9a744   41 54 44 2a 39 39 23 0d                           |ATD*99#.|
D (77470) CDC_ACM: Submitting BULK OUT transfer
D (77470) CDC_ACM: out/ctrl xfer cb
D (77480) CDC_ACM: in xfer cb
D (77480) usb_terminal: 0x3fca261c   0d 0a 43 4f 4e 4e 45 43  54 0d 0a                 |..CONNECT..|
D (77490) command_lib: Response:
CONNECT

D (77500) CDC_ACM: Submitting poll for BULK IN transfer
D (77500) CDC_ACM: notif xfer cb
D (77500) usb_terminal: Ignored USB event 1
D (77510) CDC_ACM: Submitting poll for INTR IN transfer
D (77510) esp_netif_handlers: esp_netif action has started with netif0x3fc9df38 from event_id=0
D (77520) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fc9e24c
D (77530) esp_netif_lwip: check: remote, if=0x3fc9df38 fn=0x420422d8
0x420422d8: esp_netif_update_default_netif_lwip at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_netif/lwip/esp_netif_lwip.c:327

D (77540) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fc9df38
D (77540) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (77550) pppos_example: modem_set_mode(ESP_MODEM_MODE_DATA)
I (77560) pppos_example: Waiting for IP address
D (83530) usb_terminal: 0x3fca3e28   7e ff 7d 23 c0 21 7d 21  7d 21 7d 20 7d 34 7d 22  |~.}#.!}!}!} }4}"|
D (83530) usb_terminal: 0x3fca3e38   7d 26 7d 20 7d 20 7d 20  7d 20 7d 25 7d 26 8a e2  |}&} } } } }%}&..|
D (83530) usb_terminal: 0x3fca3e48   7d 2f f0 7d 27 7d 22 7d  28 7d 22 7d 32 4b 7e     |}/.}'}"}(}"}2K~|
D (83540) CDC_ACM: Submitting BULK OUT transfer
D (83550) CDC_ACM: out/ctrl xfer cb
D (83550) CDC_ACM: in xfer cb
D (83550) usb_terminal: 0x3fca261c   7e ff 7d 23 c0 21 7d 21  7d 21 7d 20 7d 38 7d 22  |~.}#.!}!}!} }8}"|
D (83560) usb_terminal: 0x3fca262c   7d 26 7d 20 7d 20 7d 20  7d 20 7d 23 7d 24 c0 23  |}&} } } } }#}$.#|
D (83570) usb_terminal: 0x3fca263c   7d 25 7d 26 67 e0 7d 3d  66 7d 27 7d 22 7d 28 7d  |}%}&g.}=f}'}"}(}|
D (83580) usb_terminal: 0x3fca264c   22 7d 2b bb 7e                                    |"}+.~|
D (83590) usb_terminal: 0x3fca4a28   7e ff 7d 23 c0 21 7d 24  7d 21 7d 20 7d 28 7d 23  |~.}#.!}$}!} }(}#|
D (83600) usb_terminal: 0x3fca4a38   7d 24 c0 23 2c d4 7e                              |}$.#,.~|
D (83610) CDC_ACM: Submitting BULK OUT transfer
D (83620) CDC_ACM: Submitting poll for BULK IN transfer
D (83620) CDC_ACM: out/ctrl xfer cb
D (83620) CDC_ACM: in xfer cb
D (83630) usb_terminal: 0x3fca261c   7e ff 7d 23 c0 21 7d 22  7d 21 7d 20 7d 34 7d 22  |~.}#.!}"}!} }4}"|
D (83640) usb_terminal: 0x3fca262c   7d 26 7d 20 7d 20 7d 20  7d 20 7d 25 7d 26 8a e2  |}&} } } } }%}&..|
D (83650) usb_terminal: 0x3fca263c   7d 2f f0 7d 27 7d 22 7d  28 7d 22 f9 22 7e        |}/.}'}"}(}"."~|
D (83660) CDC_ACM: Submitting poll for BULK IN transfer
D (83660) CDC_ACM: in xfer cb
D (83660) usb_terminal: 0x3fca261c   7e ff 7d 23 c0 21 7d 21  7d 22 7d 20 7d 34 7d 22  |~.}#.!}!}"} }4}"|
D (83670) usb_terminal: 0x3fca262c   7d 26 7d 20 7d 20 7d 20  7d 20 7d 25 7d 26 67 e0  |}&} } } } }%}&g.|
D (83680) usb_terminal: 0x3fca263c   7d 3d 66 7d 27 7d 22 7d  28 7d 22 36 2c 7e        |}=f}'}"}(}"6,~|
D (83690) usb_terminal: 0x3fca4a28   7e ff 7d 23 c0 21 7d 22  7d 22 7d 20 7d 34 7d 22  |~.}#.!}"}"} }4}"|
D (83700) usb_terminal: 0x3fca4a38   7d 26 7d 20 7d 20 7d 20  7d 20 7d 25 7d 26 67 e0  |}&} } } } }%}&g.|
D (83710) usb_terminal: 0x3fca4a48   7d 3d 66 7d 27 7d 22 7d  28 7d 22 dd 45 7e        |}=f}'}"}(}".E~|
D (83720) CDC_ACM: Submitting BULK OUT transfer
D (83730) CDC_ACM: Submitting poll for BULK IN transfer
D (83730) CDC_ACM: out/ctrl xfer cb
D (83740) usb_terminal: 0x3fca4a28   7e ff 03 80 21 01 01 00  1c 02 06 00 2d 0f 01 03  |~...!.......-...|
D (83750) usb_terminal: 0x3fca4a38   06 00 00 00 00 81 06 00  00 00 00 83 06 00 00 00  |................|
D (83750) usb_terminal: 0x3fca4a48   00 55 15 7e                                       |.U.~|
D (83760) CDC_ACM: Submitting BULK OUT transfer
D (83770) CDC_ACM: out/ctrl xfer cb
D (83770) usb_terminal: 0x3fca4a28   7e ff 03 80 57 01 01 00  0e 01 0a 38 d8 ae 14 f6  |~...W......8....|
D (83780) usb_terminal: 0x3fca4a38   70 ef 99 57 40 7e                                 |p..W@~|
D (83790) CDC_ACM: Submitting BULK OUT transfer
D (83790) CDC_ACM: in xfer cb
D (83800) usb_terminal: 0x3fca261c   7e 80 21 01 00 00 04 67  c3 7e                    |~.!....g.~|
D (83810) CDC_ACM: Submitting poll for BULK IN transfer
D (83810) CDC_ACM: out/ctrl xfer cb
D (83820) usb_terminal: 0x3fca4428   7e ff 03 80 21 03 00 00  0a 03 06 00 00 00 00 a0  |~...!...........|
D (83830) usb_terminal: 0x3fca4438   3d 7e                                             |=~|
D (83830) CDC_ACM: Submitting BULK OUT transfer
D (83840) CDC_ACM: out/ctrl xfer cb
D (83840) CDC_ACM: in xfer cb
D (83840) usb_terminal: 0x3fca261c   7e 80 21 04 01 00 16 02  06 00 2d 0f 01 81 06 00  |~.!.......-.....|
D (83850) usb_terminal: 0x3fca262c   00 00 00 83 06 00 00 00  00 93 49 7e              |..........I~|
D (83860) usb_terminal: 0x3fca4a28   7e ff 03 80 21 01 02 00  0a 03 06 00 00 00 00 14  |~...!...........|
D (83870) usb_terminal: 0x3fca4a38   fe 7e                                             |.~|
D (83880) CDC_ACM: Submitting BULK OUT transfer
D (83890) CDC_ACM: Submitting poll for BULK IN transfer
D (83890) CDC_ACM: out/ctrl xfer cb
D (83900) CDC_ACM: in xfer cb
D (83900) usb_terminal: 0x3fca261c   7e 80 57 04 01 00 0e 01  0a 38 d8 ae 14 f6 70 ef  |~.W......8....p.|
D (83910) usb_terminal: 0x3fca262c   99 b9 20 7e                                       |.. ~|
D (83920) usb_terminal: 0x3fca4a28   7e ff 03 80 57 01 02 00  04 0f 76 7e              |~...W.....v~|
D (83930) CDC_ACM: Submitting BULK OUT transfer
D (83930) CDC_ACM: Submitting poll for BULK IN transfer
D (83940) CDC_ACM: out/ctrl xfer cb
D (83940) CDC_ACM: in xfer cb
D (83940) usb_terminal: 0x3fca261c   7e 80 21 01 01 00 04 bb  99 7e                    |~.!......~|
D (83950) usb_terminal: 0x3fca4a28   7e ff 03 80 21 02 01 00  04 cd 92 7e              |~...!......~|
D (83960) CDC_ACM: Submitting BULK OUT transfer
D (83970) CDC_ACM: Submitting poll for BULK IN transfer
D (83970) CDC_ACM: out/ctrl xfer cb
D (83970) CDC_ACM: in xfer cb
D (83980) usb_terminal: 0x3fca261c   7e 80 21 03 02 00 0a 03  06 0a 01 92 cf 40 da 7e  |~.!..........@.~|
D (83990) usb_terminal: 0x3fca4a28   7e ff 03 80 21 01 03 00  0a 03 06 0a 01 92 cf 8d  |~...!...........|
D (84000) usb_terminal: 0x3fca4a38   21 7e                                             |!~|
D (84000) CDC_ACM: Submitting BULK OUT transfer
D (84010) CDC_ACM: Submitting poll for BULK IN transfer
D (84010) CDC_ACM: out/ctrl xfer cb
D (84020) CDC_ACM: in xfer cb
D (84020) usb_terminal: 0x3fca261c   7e 80 21 02 03 00 0a 03  06 0a 01 92 cf 9a bb 7e  |~.!............~|
D (84030) esp_netif_lwip: esp_netif_internal_dhcpc_cb lwip-netif:0x3fc9dfbc
D (84040) esp_netif_lwip: if0x3fc9df38 ip changed=1
D (84040) event: running post IP_EVENT:6 with handler 0x4200a6ec and context 0x3fc9dee4 on loop 0x3fc9cf98        
0x4200a6ec: on_ip_event at P:/projects/io/airkey/dev/ak-idf-lte/main/ppos_main.c:139

I (84050) esp-netif_lwip-ppp: Connected
D (84050) pppos_example: IP event! 6
I (84060) pppos_example: Modem Connected to PPP Server
I (84070) pppos_example: ~~~~~~~~~~~~~~
I (84070) pppos_example: IP          : 10.1.146.207
I (84080) pppos_example: Netmask     : 255.255.255.255
I (84080) pppos_example: Gateway     : 10.64.64.64
D (84090) esp_netif_lwip: check: remote, if=0x3fc9df38 fn=0x4203f254
0x4203f254: esp_netif_dhcpc_option_api at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_netif/lwip/esp_netif_lwip.c:2302

D (84050) CDC_ACM: Submitting poll for BULK IN transfer
D (84090) esp_netif_lwip: call api in lwip: ret=0x5001, give sem
I (84110) pppos_example: DNS ns: 180.207.201.63
D (84110) esp_netif_lwip: check: remote, if=0x3fc9df38 fn=0x42041d7c
0x42041d7c: esp_netif_get_dns_info_api at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_netif/lwip/esp_netif_lwip.c:1909

D (84120) esp_netif_lwip: esp_netif_get_dns_info: esp_netif=0x3fc9df38 type=0
D (84120) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (84130) pppos_example: Name Server1: 8.8.8.8
D (84140) esp_netif_lwip: check: remote, if=0x3fc9df38 fn=0x42041d7c
0x42041d7c: esp_netif_get_dns_info_api at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_netif/lwip/esp_netif_lwip.c:1909

D (84140) esp_netif_lwip: esp_netif_get_dns_info: esp_netif=0x3fc9df38 type=1
D (84150) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (84160) pppos_example: Name Server2: 8.8.4.4
I (84160) pppos_example: ~~~~~~~~~~~~~~
I (84160) pppos_example: GOT ip event!!!
D (84170) event: running post IP_EVENT:6 with handler 0x4203ee54 and context 0x3fca3538 on loop 0x3fc9cf98        
0x4203ee54: esp_netif_action_connected at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_netif/esp_netif_handlers.c:36

D (84180) esp_netif_handlers: esp_netif action connected with netif0x3fc9df38 from event_id=6
D (84190) esp_netif_lwip: check: remote, if=0x3fc9df38 fn=0x4203ff38
0x4203ff38: esp_netif_up_api at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_netif/lwip/esp_netif_lwip.c:1608

D (D (84190) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (84200) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (84210) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (84220) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (84220) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (84230) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
84190) esp_netif_lwip: esp_netif_up_api esp_netif:0x3fc9df38
D (84240) mqtt_client: MQTT client_id=ESP32_8a509C
D (84240) esp_netif_lwip: check: local, if=0x3fc9df38 fn=0x420422d8
0x420422d8: esp_netif_update_default_netif_lwip at C:/Espressif/frameworks/esp-idf-v5.1/components/esp_netif/lwip/esp_netif_lwip.c:327

D (84250) event: created event loop 0x3fca35e0
D (84250) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fc9df38
D (84270) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (84270) event: running post NETIF_PPP_STATUS:0 with handler 0x4200a4b8 and context 0x3fc9df18 on loop 0x3fc9cf980x4200a4b8: on_ppp_changed at P:/projects/io/airkey/dev/ak-idf-lte/main/ppos_main.c:128

I (84280) pppos_example: PPP state changed event 0
D (84290) event: running post NETIF_PPP_STATUS:0 with handler 0x420105e0 and context 0x3fca3508 on loop 0x3fc9cf980x420105e0: esp_modem::Netif::on_ppp_changed(void*, char const*, long, void*) at P:/projects/io/airkey/dev/ak-idf-lte/components/espressif__esp_modem/src/esp_modem_netif.cpp:22

D (84300) mqtt_client: Core selection disabled
D (84300) event: running post MQTT_EVENTS:7 with handler 0x4200a4f4 and context 0x3fca3134 on loop 0x3fca35e0     
0x4200a4f4: mqtt_event_handler at P:/projects/io/airkey/dev/ak-idf-lte/main/ppos_main.c:85

D (84310) pppos_example: Event dispatched from event loop base=MQTT_EVENTS, event_id=7
I (84320) pppos_example: MQTT other event id: 7
D (84330) esp-tls: host:91.121.93.94: strlen 12
D (84330) esp-tls: [sock=54] Resolved IPv4 address: 91.121.93.94
D (84340) esp-tls: [sock=54] Connecting to server. HOST: 91.121.93.94, Port: 1883
D (84340) usb_terminal: 0x3fca5d2c   7e 21 45 00 00 2c 00 00  00 00 ff 06 66 24 0a 01  |~!E..,......f$..|
D (84350) usb_terminal: 0x3fca5d3c   92 cf 5b 79 5d 5e fd e6  07 5b 8b 89 19 ab 00 00  |..[y]^...[......|
D (84360) usb_terminal: 0x3fca5d4c   00 00 60 02 16 70 81 ac  00 00 02 04 05 a0 fc 6c  |..`..p.........l|
D (84370) usb_terminal: 0x3fca5d5c   7e                                                |~|
D (84380) CDC_ACM: Submitting BULK OUT transfer
I (84390) pppos_example: Waiting for MQTT data
D (84390) CDC_ACM: out/ctrl xfer cb
D (85590) usb_terminal: 0x3fca5d2c   7e 21 45 00 00 2c 00 01  00 00 ff 06 66 23 0a 01  |~!E..,......f#..|
D (85590) usb_terminal: 0x3fca5d3c   92 cf 5b 79 5d 5e fd e6  07 5b 8b 89 19 ab 00 00  |..[y]^...[......|
D (85590) usb_terminal: 0x3fca5d4c   00 00 60 02 16 70 81 ac  00 00 02 04 05 a0 2a ef  |..`..p........*.|
D (85600) usb_terminal: 0x3fca5d5c   7e                                                |~|
D (85610) CDC_ACM: Submitting BULK OUT transfer
D (85620) CDC_ACM: out/ctrl xfer cb
D (87120) usb_terminal: 0x3fca5d2c   7e 21 45 00 00 2c 00 02  00 00 ff 06 66 22 0a 01  |~!E..,......f"..|
D (87120) usb_terminal: 0x3fca5d3c   92 cf 5b 79 5d 5e fd e6  07 5b 8b 89 19 ab 00 00  |..[y]^...[......|
D (87120) usb_terminal: 0x3fca5d4c   00 00 60 02 16 70 81 ac  00 00 02 04 05 a0 7b 70  |..`..p........{p|
D (87130) usb_terminal: 0x3fca5d5c   7e                                                |~|
D (87140) CDC_ACM: Submitting BULK OUT transfer
D (87150) CDC_ACM: out/ctrl xfer cb
D (88650) usb_terminal: 0x3fca5d2c   7e 21 45 00 00 2c 00 03  00 00 ff 06 66 21 0a 01  |~!E..,......f!..|
D (88650) usb_terminal: 0x3fca5d3c   92 cf 5b 79 5d 5e fd e6  07 5b 8b 89 19 ab 00 00  |..[y]^...[......|
D (88650) usb_terminal: 0x3fca5d4c   00 00 60 02 16 70 81 ac  00 00 02 04 05 a0 30 fa  |..`..p........0.|
D (88660) usb_terminal: 0x3fca5d5c   7e                                                |~|
D (88670) CDC_ACM: Submitting BULK OUT transfer
D (88680) CDC_ACM: out/ctrl xfer cb
D (89940) usb_terminal: 0x3fca632c   7e ff 03 80 57 01 02 00  04 0f 76 7e              |~...W.....v~|
D (89940) CDC_ACM: Submitting BULK OUT transfer
D (89940) CDC_ACM: out/ctrl xfer cb
D (90180) usb_terminal: 0x3fca5d2c   7e 21 45 00 00 2c 00 04  00 00 ff 06 66 20 0a 01  |~!E..,......f ..|
D (90180) usb_terminal: 0x3fca5d3c   92 cf 5b 79 5d 5e fd e6  07 5b 8b 89 19 ab 00 00  |..[y]^...[......|
D (90180) usb_terminal: 0x3fca5d4c   00 00 60 02 16 70 81 ac  00 00 02 04 05 a0 c8 46  |..`..p.........F|
D (90190) usb_terminal: 0x3fca5d5c   7e                                                |~|
D (90200) CDC_ACM: Submitting BULK OUT transfer
D (90210) CDC_ACM: out/ctrl xfer cb
D (91710) usb_terminal: 0x3fca5d2c   7e 21 45 00 00 2c 00 05  00 00 ff 06 66 1f 0a 01  |~!E..,......f...|
D (91710) usb_terminal: 0x3fca5d3c   92 cf 5b 79 5d 5e fd e6  07 5b 8b 89 19 ab 00 00  |..[y]^...[......|
D (91710) usb_terminal: 0x3fca5d4c   00 00 60 02 16 70 81 ac  00 00 02 04 05 a0 b8 bc  |..`..p..........|
D (91720) usb_terminal: 0x3fca5d5c   7e                                                |~|
D (91730) CDC_ACM: Submitting BULK OUT transfer
D (91740) CDC_ACM: out/ctrl xfer cb
D (93240) usb_terminal: 0x3fca5d2c   7e 21 45 00 00 2c 00 06  00 00 ff 06 66 1e 0a 01  |~!E..,......f...|
D (93240) usb_terminal: 0x3fca5d3c   92 cf 5b 79 5d 5e fd e6  07 5b 8b 89 19 ab 00 00  |..[y]^...[......|
D (93240) usb_terminal: 0x3fca5d4c   00 00 60 02 16 70 81 ac  00 00 02 04 05 a0 e9 23  |..`..p.........#|
D (93250) usb_terminal: 0x3fca5d5c   7e                                                |~|
D (93260) CDC_ACM: Submitting BULK OUT transfer
D (93270) CDC_ACM: out/ctrl xfer cb
E (94410) esp-tls: [sock=54] select() timeout
E (94410) transport_base: Failed to open a new connection: 32774
E (94410) mqtt_client: Error transport connect
D (94410) event: running post MQTT_EVENTS:0 with handler 0x4200a4f4 and context 0x3fca3134 on loop 0x3fca35e0     
0x4200a4f4: mqtt_event_handler at P:/projects/io/airkey/dev/ak-idf-lte/main/ppos_main.c:85

D (94420) pppos_example: Event dispatched from event loop base=MQTT_EVENTS, event_id=0
I (94430) pppos_example: MQTT_EVENT_ERROR
D (94430) mqtt_client: Reconnect after 10000 ms
D (94440) event: running post MQTT_EVENTS:2 with handler 0x4200a4f4 and context 0x3fca3134 on loop 0x3fca35e0     
0x4200a4f4: mqtt_event_handler at P:/projects/io/airkey/dev/ak-idf-lte/main/ppos_main.c:85

D (94450) pppos_example: Event dispatched from event loop base=MQTT_EVENTS, event_id=2
I (94460) pppos_example: MQTT_EVENT_DISCONNECTED
D (95940) usb_terminal: 0x3fca606c   7e ff 03 80 57 01 02 00  04 0f 76 7e              |~...W.....v~|
D (95940) CDC_ACM: Submitting BULK OUT transfer
D (95940) CDC_ACM: out/ctrl xfer cb

Who is online

Users browsing this forum: No registered users and 63 guests