PPPoS example problem: AT mode and Data mode switching not working
Posted: Fri Feb 19, 2021 9:22 pm
Hi,
I'm trying to run the PPPoS example but I'm trying to implement "data_mode <=> command_mode" switching.
I'm using an ESP-WROVER-B (16MB version) and a BG96 modem.
I modified the code like this:
I added a couple lines to the modem library so I could get the next log output:
and then it keeps rebooting because the modem doesn't respond to the AT sync command.
Any idea of what could be the problem?
I'm trying to run the PPPoS example but I'm trying to implement "data_mode <=> command_mode" switching.
I'm using an ESP-WROVER-B (16MB version) and a BG96 modem.
I modified the code like this:
Code: Select all
/* 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 "mqtt_client.h"
#include "esp_modem.h"
#include "esp_modem_netif.h"
#include "esp_log.h"
#include "sim800.h"
#include "bg96.h"
#include "sim7600.h"
#define BROKER_URL "mqtt://broker.hivemq.com:1883"
static const char *TAG = "pppos_example";
static EventGroupHandle_t event_group = NULL;
static const int CONNECT_BIT = BIT0;
static const int STOP_BIT = BIT1;
static const int GOT_DATA_BIT = BIT2;
#if CONFIG_EXAMPLE_SEND_MSG
/**
* @brief This example will also show how to send short message using the infrastructure provided by esp modem library.
* @note Not all modem support SMG.
*
*/
static esp_err_t example_default_handle(modem_dce_t *dce, const char *line)
{
esp_err_t err = ESP_FAIL;
if (strstr(line, MODEM_RESULT_CODE_SUCCESS)) {
err = esp_modem_process_command_done(dce, MODEM_STATE_SUCCESS);
} else if (strstr(line, MODEM_RESULT_CODE_ERROR)) {
err = esp_modem_process_command_done(dce, MODEM_STATE_FAIL);
}
return err;
}
static esp_err_t example_handle_cmgs(modem_dce_t *dce, const char *line)
{
esp_err_t err = ESP_FAIL;
if (strstr(line, MODEM_RESULT_CODE_SUCCESS)) {
err = esp_modem_process_command_done(dce, MODEM_STATE_SUCCESS);
} else if (strstr(line, MODEM_RESULT_CODE_ERROR)) {
err = esp_modem_process_command_done(dce, MODEM_STATE_FAIL);
} else if (!strncmp(line, "+CMGS", strlen("+CMGS"))) {
err = ESP_OK;
}
return err;
}
#define MODEM_SMS_MAX_LENGTH (128)
#define MODEM_COMMAND_TIMEOUT_SMS_MS (120000)
#define MODEM_PROMPT_TIMEOUT_MS (10)
static esp_err_t example_send_message_text(modem_dce_t *dce, const char *phone_num, const char *text)
{
modem_dte_t *dte = dce->dte;
dce->handle_line = example_default_handle;
/* Set text mode */
if (dte->send_cmd(dte, "AT+CMGF=1\r", MODEM_COMMAND_TIMEOUT_DEFAULT) != ESP_OK) {
ESP_LOGE(TAG, "send command failed");
goto err;
}
if (dce->state != MODEM_STATE_SUCCESS) {
ESP_LOGE(TAG, "set message format failed");
goto err;
}
ESP_LOGD(TAG, "set message format ok");
/* Specify character set */
dce->handle_line = example_default_handle;
if (dte->send_cmd(dte, "AT+CSCS=\"GSM\"\r", MODEM_COMMAND_TIMEOUT_DEFAULT) != ESP_OK) {
ESP_LOGE(TAG, "send command failed");
goto err;
}
if (dce->state != MODEM_STATE_SUCCESS) {
ESP_LOGE(TAG, "set character set failed");
goto err;
}
ESP_LOGD(TAG, "set character set ok");
/* send message */
char command[MODEM_SMS_MAX_LENGTH] = {0};
int length = snprintf(command, MODEM_SMS_MAX_LENGTH, "AT+CMGS=\"%s\"\r", phone_num);
/* set phone number and wait for "> " */
dte->send_wait(dte, command, length, "\r\n> ", MODEM_PROMPT_TIMEOUT_MS);
/* end with CTRL+Z */
snprintf(command, MODEM_SMS_MAX_LENGTH, "%s\x1A", text);
dce->handle_line = example_handle_cmgs;
if (dte->send_cmd(dte, command, MODEM_COMMAND_TIMEOUT_SMS_MS) != ESP_OK) {
ESP_LOGE(TAG, "send command failed");
goto err;
}
if (dce->state != MODEM_STATE_SUCCESS) {
ESP_LOGE(TAG, "send message failed");
goto err;
}
ESP_LOGD(TAG, "send message ok");
return ESP_OK;
err:
return ESP_FAIL;
}
#endif
static void modem_event_handler(void *event_handler_arg, esp_event_base_t event_base, int32_t event_id, void *event_data)
{
switch (event_id) {
case ESP_MODEM_EVENT_PPP_START:
ESP_LOGI(TAG, "Modem PPP Started");
break;
case ESP_MODEM_EVENT_PPP_STOP:
ESP_LOGI(TAG, "Modem PPP Stopped");
xEventGroupSetBits(event_group, STOP_BIT);
break;
case ESP_MODEM_EVENT_UNKNOWN:
ESP_LOGW(TAG, "Unknow line received: %s", (char *)event_data);
break;
default:
break;
}
}
static esp_err_t mqtt_event_handler(esp_mqtt_event_handle_t event)
{
esp_mqtt_client_handle_t client = event->client;
int msg_id;
switch (event->event_id) {
case MQTT_EVENT_CONNECTED:
ESP_LOGI(TAG, "MQTT_EVENT_CONNECTED");
msg_id = esp_mqtt_client_subscribe(client, "tretre", 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, "tretre", "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;
}
return ESP_OK;
}
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 Connect 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_get_dns_info(netif, 0, &dns_info);
ESP_LOGI(TAG, "Name Server1: " IPSTR, IP2STR(&dns_info.ip.u_addr.ip4));
esp_netif_get_dns_info(netif, 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 Disconnect from PPP Server");
} else if (event_id == IP_EVENT_GOT_IP6) {
ESP_LOGI(TAG, "GOT IPv6 event!");
ip_event_got_ip6_t *event = (ip_event_got_ip6_t *)event_data;
ESP_LOGI(TAG, "Got IPv6 address " IPV6STR, IPV62STR(event->ip6_info.ip));
}
}
void app_main(void)
{
#if CONFIG_LWIP_PPP_PAP_SUPPORT
esp_netif_auth_type_t auth_type = NETIF_PPP_AUTHTYPE_PAP;
#elif CONFIG_LWIP_PPP_CHAP_SUPPORT
esp_netif_auth_type_t auth_type = NETIF_PPP_AUTHTYPE_CHAP;
#elif !defined(CONFIG_EXAMPLE_MODEM_PPP_AUTH_NONE)
#error "Unsupported AUTH Negotiation"
#endif
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));
event_group = xEventGroupCreate();
/* create dte object */
esp_modem_dte_config_t config = ESP_MODEM_DTE_DEFAULT_CONFIG();
/* setup UART specific configuration based on kconfig options */
config.tx_io_num = CONFIG_EXAMPLE_MODEM_UART_TX_PIN;
config.rx_io_num = CONFIG_EXAMPLE_MODEM_UART_RX_PIN;
config.rts_io_num = CONFIG_EXAMPLE_MODEM_UART_RTS_PIN;
config.cts_io_num = CONFIG_EXAMPLE_MODEM_UART_CTS_PIN;
config.rx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE;
config.tx_buffer_size = CONFIG_EXAMPLE_MODEM_UART_TX_BUFFER_SIZE;
config.pattern_queue_size = CONFIG_EXAMPLE_MODEM_UART_PATTERN_QUEUE_SIZE;
config.event_queue_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_QUEUE_SIZE;
config.event_task_stack_size = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_STACK_SIZE;
config.event_task_priority = CONFIG_EXAMPLE_MODEM_UART_EVENT_TASK_PRIORITY;
config.line_buffer_size = CONFIG_EXAMPLE_MODEM_UART_RX_BUFFER_SIZE / 2;
modem_dte_t *dte = esp_modem_dte_init(&config);
/* Register event handler */
ESP_ERROR_CHECK(esp_modem_set_event_handler(dte, modem_event_handler, ESP_EVENT_ANY_ID, NULL));
// Init netif object
esp_netif_config_t cfg = ESP_NETIF_DEFAULT_PPP();
esp_netif_t *esp_netif = esp_netif_new(&cfg);
assert(esp_netif);
void *modem_netif_adapter;
// void *modem_netif_adapter = esp_modem_netif_setup(dte);
// esp_modem_netif_set_default_handlers(modem_netif_adapter, esp_netif);
while (1) {
modem_netif_adapter = esp_modem_netif_setup(dte);
esp_modem_netif_set_default_handlers(modem_netif_adapter, esp_netif);
modem_dce_t *dce = NULL;
/* create dce object */
dce = bg96_init(dte);
assert(dce != NULL);
ESP_ERROR_CHECK(dce->set_flow_ctrl(dce, MODEM_FLOW_CONTROL_NONE));
ESP_ERROR_CHECK(dce->store_profile(dce));
/* Print Module ID, Operator, IMEI, IMSI */
ESP_LOGI(TAG, "Module: %s", dce->name);
ESP_LOGI(TAG, "Operator: %s", dce->oper);
ESP_LOGI(TAG, "IMEI: %s", dce->imei);
ESP_LOGI(TAG, "IMSI: %s", dce->imsi);
/* Get signal quality */
uint32_t rssi = 0, ber = 0;
ESP_ERROR_CHECK(dce->get_signal_quality(dce, &rssi, &ber));
ESP_LOGI(TAG, "rssi: %d, ber: %d", rssi, ber);
/* Get battery voltage */
uint32_t voltage = 0, bcs = 0, bcl = 0;
ESP_ERROR_CHECK(dce->get_battery_status(dce, &bcs, &bcl, &voltage));
ESP_LOGI(TAG, "Battery voltage: %d mV", voltage);
/* setup PPPoS network parameters */
// #if !defined(CONFIG_EXAMPLE_MODEM_PPP_AUTH_NONE) && (defined(CONFIG_LWIP_PPP_PAP_SUPPORT) || defined(CONFIG_LWIP_PPP_CHAP_SUPPORT))
// esp_netif_ppp_set_auth(esp_netif, auth_type, CONFIG_EXAMPLE_MODEM_PPP_AUTH_USERNAME, CONFIG_EXAMPLE_MODEM_PPP_AUTH_PASSWORD);
// #endif
/* attach the modem to the network interface */
esp_netif_attach(esp_netif, modem_netif_adapter);
/* Wait for IP address */
xEventGroupWaitBits(event_group, CONNECT_BIT, pdTRUE, pdTRUE, portMAX_DELAY);
/* Config MQTT */
esp_mqtt_client_config_t mqtt_config = {
.uri = BROKER_URL,
.event_handle = mqtt_event_handler,
};
esp_mqtt_client_handle_t mqtt_client = esp_mqtt_client_init(&mqtt_config);
esp_mqtt_client_start(mqtt_client);
xEventGroupWaitBits(event_group, GOT_DATA_BIT, pdTRUE, pdTRUE, portMAX_DELAY);
esp_mqtt_client_destroy(mqtt_client);
/* Exit PPP mode */
ESP_ERROR_CHECK(esp_modem_stop_ppp(dte));
xEventGroupWaitBits(event_group, STOP_BIT, pdTRUE, pdTRUE, portMAX_DELAY);
#if CONFIG_EXAMPLE_SEND_MSG
const char *message = "Welcome to ESP32!";
ESP_ERROR_CHECK(example_send_message_text(dce, CONFIG_EXAMPLE_SEND_MSG_PEER_PHONE_NUMBER, message));
ESP_LOGI(TAG, "Send send message [%s] ok", message);
#endif
/* Power down module */
// ESP_ERROR_CHECK(dce->power_down(dce));
// ESP_LOGI(TAG, "Power down");
// ESP_ERROR_CHECK(dce->deinit(dce));
ESP_LOGI(TAG, "Restart after 5 seconds");
vTaskDelay(pdMS_TO_TICKS(5000));
}
/* Unregister events, destroy the netif adapter and destroy its esp-netif instance */
esp_modem_netif_clear_default_handlers(modem_netif_adapter);
esp_modem_netif_teardown(modem_netif_adapter);
esp_netif_destroy(esp_netif);
ESP_ERROR_CHECK(dte->deinit(dte));
}
Code: Select all
I (29) boot: ESP-IDF v4.2-dirty 2nd stage bootloader
I (29) boot: compile time 16:47:51
I (29) boot: chip revision: 1
I (32) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (39) boot.esp32: SPI Speed : 40MHz
I (44) boot.esp32: SPI Mode : DIO
I (49) boot.esp32: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label Usage Type ST Offset Length
I (69) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (77) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (84) boot: 2 factory factory app 00 00 00010000 00100000
I (92) boot: End of partition table
I (96) boot_comm: chip revision: 1, min. application chip revision: 0
I (103) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1874c (100172) map
I (150) esp_image: segment 1: paddr=0x00028774 vaddr=0x3ffb0000 size=0x02164 ( 8548) load
I (154) esp_image: segment 2: paddr=0x0002a8e0 vaddr=0x40080000 size=0x00404 ( 1028) load
0x40080000: _WindowOverflow4 at /home/pablo/esp/esp-idf/components/freertos/xtensa/xtensa_vectors.S:1730
I (157) esp_image: segment 3: paddr=0x0002acec vaddr=0x40080404 size=0x0532c ( 21292) load
I (175) esp_image: segment 4: paddr=0x00030020 vaddr=0x400d0020 size=0x6355c (406876) map
0x400d0020: _stext at ??:?
I (331) esp_image: segment 5: paddr=0x00093584 vaddr=0x40085730 size=0x06014 ( 24596) load
0x40085730: pxPortInitialiseStack at /home/pablo/esp/esp-idf/components/freertos/xtensa/port.c:218
I (348) boot: Loaded app from partition at offset 0x10000
I (348) boot: Disabling RNG early entropy source...
I (348) cpu_start: Pro cpu up.
I (352) cpu_start: Application information:
I (357) cpu_start: Project name: pppos_client
I (362) cpu_start: App version: 1
I (367) cpu_start: Compile time: Feb 19 2021 16:47:45
I (373) cpu_start: ELF file SHA256: 58b6b4143284fd79...
I (379) cpu_start: ESP-IDF: v4.2-dirty
I (384) cpu_start: Starting app cpu, entry point is 0x400818e4
0x400818e4: call_start_cpu1 at /home/pablo/esp/esp-idf/components/esp32/cpu_start.c:287
I (0) cpu_start: App cpu up.
I (394) heap_init: Initializing. RAM available for dynamic allocation:
I (401) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (407) heap_init: At 3FFB39F0 len 0002C610 (177 KiB): DRAM
I (414) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (420) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (426) heap_init: At 4008B744 len 000148BC (82 KiB): IRAM
I (433) cpu_start: Pro cpu start user code
I (451) spi_flash: detected chip: gd
I (452) spi_flash: flash io: dio
W (452) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (462) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (475) uart: queue free spaces: 30
W (485) esp_modem_dte_send_cmd: AT --> AT
W (485) esp_handle_uart_pattern: AT <--
W (485) esp_handle_uart_pattern: AT <-- OK
W (495) esp_modem_dte_send_cmd: AT --> ATE0
W (505) esp_handle_uart_pattern: AT <--
W (505) esp_handle_uart_pattern: AT <-- OK
W (505) esp_modem_dte_send_cmd: AT --> AT+CGMM
W (515) esp_handle_uart_pattern: AT <--
W (515) esp_handle_uart_pattern: AT <-- BG96
W (525) esp_handle_uart_pattern: AT <--
W (525) esp_handle_uart_pattern: AT <-- OK
W (535) esp_modem_dte_send_cmd: AT --> AT+CGSN
W (545) esp_handle_uart_pattern: AT <--
W (545) esp_handle_uart_pattern: AT <-- 867035049868472
W (555) esp_handle_uart_pattern: AT <--
W (555) esp_handle_uart_pattern: AT <-- OK
W (565) esp_modem_dte_send_cmd: AT --> AT+CIMI
W (565) esp_handle_uart_pattern: AT <--
W (575) esp_handle_uart_pattern: AT <-- 748070102245966
W (575) esp_handle_uart_pattern: AT <--
W (585) esp_handle_uart_pattern: AT <-- OK
W (585) esp_modem_dte_send_cmd: AT --> AT+COPS?
W (595) esp_handle_uart_pattern: AT <--
W (595) esp_handle_uart_pattern: AT <-- +COPS: 0,0,"Movistar movistar",0
W (605) esp_handle_uart_pattern: AT <--
W (605) esp_handle_uart_pattern: AT <-- OK
W (615) esp_modem_dte_send_cmd: AT --> AT+IFC=0,0
W (625) esp_handle_uart_pattern: AT <--
W (625) esp_handle_uart_pattern: AT <-- OK
W (625) esp_modem_dte_send_cmd: AT --> AT&W
W (635) esp_handle_uart_pattern: AT <--
W (635) esp_handle_uart_pattern: AT <-- OK
I (645) pppos_example: Module: BG96
I (645) pppos_example: Operator: "Movistar movistar"
I (655) pppos_example: IMEI: 867035049868472
I (655) pppos_example: IMSI: 748070102245966
W (665) esp_modem_dte_send_cmd: AT --> AT+CSQ
W (675) esp_handle_uart_pattern: AT <--
W (675) esp_handle_uart_pattern: AT <-- +CSQ: 27,99
W (675) esp_handle_uart_pattern: AT <--
W (685) esp_handle_uart_pattern: AT <-- OK
I (685) pppos_example: rssi: 27, ber: 99
W (695) esp_modem_dte_send_cmd: AT --> AT+CBC
W (705) esp_handle_uart_pattern: AT <--
W (705) esp_handle_uart_pattern: AT <-- +CBC: 0,74,3993
W (715) esp_handle_uart_pattern: AT <--
W (715) esp_handle_uart_pattern: AT <-- OK
I (725) pppos_example: Battery voltage: 3993 mV
W (725) esp_modem_dte_send_cmd: AT --> AT+CGDCONT=1,"IP","webapn.movistar.com.uy"
W (765) esp_handle_uart_pattern: AT <--
W (765) esp_handle_uart_pattern: AT <-- OK
W (765) esp_modem_dte_send_cmd: AT --> ATD*99***1#
W (775) esp_handle_uart_pattern: AT <--
W (775) esp_handle_uart_pattern: AT <-- CONNECT 150000000
I (875) pppos_example: Modem PPP Started
I (875) pppos_example: PPP state changed event 259
I (875) pppos_example: PPP state changed event 262
I (895) pppos_example: PPP state changed event 263
I (895) pppos_example: PPP state changed event 265
I (1575) esp-netif_lwip-ppp: Connected
I (1575) esp-netif_lwip-ppp: Name Server1: 200.58.141.163
I (1575) esp-netif_lwip-ppp: Name Server2: 200.58.157.11
I (1575) pppos_example: Modem Connect to PPP Server
I (1585) pppos_example: ~~~~~~~~~~~~~~
I (1585) pppos_example: IP : 10.155.119.219
I (1595) pppos_example: Netmask : 255.255.255.255
I (1605) pppos_example: Gateway : 10.64.64.64
I (1605) pppos_example: Name Server1: 200.58.141.163
I (1615) pppos_example: Name Server2: 200.58.157.11
I (1615) pppos_example: ~~~~~~~~~~~~~~
I (1625) pppos_example: GOT ip event!!!
I (1625) pppos_example: PPP state changed event 266
I (1635) system_api: Base MAC address is not set
I (1635) system_api: read default base MAC address from EFUSE
I (1645) pppos_example: MQTT other event id: 7
I (3655) pppos_example: MQTT_EVENT_CONNECTED
I (3655) pppos_example: sent subscribe successful, msg_id=60072
I (4135) pppos_example: MQTT_EVENT_SUBSCRIBED, msg_id=60072
I (4135) pppos_example: sent publish successful, msg_id=0
I (4615) pppos_example: MQTT_EVENT_DATA
TOPIC=tretre
DATA=esp32-pppos
W (5575) esp_handle_uart_data: AT <-- ~!E
W (6095) esp_modem_dte_send_cmd: AT --> +++
W (6995) esp_handle_uart_data: AT <--
OK
W (6995) esp_modem_dte_send_cmd: AT --> ATH
W (6995) esp_handle_uart_pattern: AT <--
I (6995) pppos_example: Modem PPP Stopped
I (7005) pppos_example: PPP state changed event 267
W (7005) esp_handle_uart_pattern: AT <-- OK
I (7005) pppos_example: PPP state changed event 265
I (7015) pppos_example: PPP state changed event 262
I (19005) pppos_example: PPP state changed event 268
I (19005) pppos_example: PPP state changed event 256
I (19005) esp-netif_lwip-ppp: User interrupt
I (19005) pppos_example: PPP state changed event 5
I (19015) pppos_example: User interrupted event from netif:0x0
I (19015) esp-modem-netif: PPP state changed event 5
I (19025) pppos_example: Restart after 5 seconds
W (24025) event: handler already registered, overwriting
W (24025) event: handler already registered, overwriting
W (24025) event: handler already registered, overwriting
W (24025) event: handler already registered, overwriting
W (24035) esp_modem_dte_send_cmd: AT --> AT
W (24035) esp_handle_uart_pattern: AT <--
W (24045) esp_handle_uart_pattern: AT <-- OK
W (24045) esp_modem_dte_send_cmd: AT --> ATE0
W (24055) esp_handle_uart_pattern: AT <--
W (24055) esp_handle_uart_pattern: AT <-- OK
W (24065) esp_modem_dte_send_cmd: AT --> AT+CGMM
W (24075) esp_handle_uart_pattern: AT <--
W (24075) esp_handle_uart_pattern: AT <-- BG96
W (24075) esp_handle_uart_pattern: AT <--
W (24085) esp_handle_uart_pattern: AT <-- OK
W (24085) esp_modem_dte_send_cmd: AT --> AT+CGSN
W (24095) esp_handle_uart_pattern: AT <--
W (24105) esp_handle_uart_pattern: AT <-- 867035049868472
W (24105) esp_handle_uart_pattern: AT <--
W (24115) esp_handle_uart_pattern: AT <-- OK
W (24115) esp_modem_dte_send_cmd: AT --> AT+CIMI
W (24125) esp_handle_uart_pattern: AT <--
W (24125) esp_handle_uart_pattern: AT <-- 748070102245966
W (24135) esp_handle_uart_pattern: AT <--
W (24135) esp_handle_uart_pattern: AT <-- OK
W (24145) esp_modem_dte_send_cmd: AT --> AT+COPS?
W (24155) esp_handle_uart_pattern: AT <--
W (24155) esp_handle_uart_pattern: AT <-- +COPS: 0,0,"Movistar movistar",0
W (24165) esp_handle_uart_pattern: AT <--
W (24165) esp_handle_uart_pattern: AT <-- OK
W (24175) esp_modem_dte_send_cmd: AT --> AT+IFC=0,0
W (24175) esp_handle_uart_pattern: AT <--
W (24185) esp_handle_uart_pattern: AT <-- OK
W (24185) esp_modem_dte_send_cmd: AT --> AT&W
W (24195) esp_handle_uart_pattern: AT <--
W (24195) esp_handle_uart_pattern: AT <-- OK
I (24205) pppos_example: Module: BG96
I (24205) pppos_example: Operator: "Movistar movistar"
I (24215) pppos_example: IMEI: 867035049868472
I (24215) pppos_example: IMSI: 748070102245966
W (24225) esp_modem_dte_send_cmd: AT --> AT+CSQ
W (24235) esp_handle_uart_pattern: AT <--
W (24235) esp_handle_uart_pattern: AT <-- +CSQ: 27,99
W (24245) esp_handle_uart_pattern: AT <--
W (24245) esp_handle_uart_pattern: AT <-- OK
I (24255) pppos_example: rssi: 27, ber: 99
W (24255) esp_modem_dte_send_cmd: AT --> AT+CBC
W (24265) esp_handle_uart_pattern: AT <--
W (24265) esp_handle_uart_pattern: AT <-- +CBC: 0,74,3993
W (24275) esp_handle_uart_pattern: AT <--
W (24275) esp_handle_uart_pattern: AT <-- OK
I (24285) pppos_example: Battery voltage: 3993 mV
W (24285) event: handler already registered, overwriting
W (24295) esp_modem_dte_send_cmd: AT --> AT+CGDCONT=1,"IP","webapn.movistar.com.uy"
W (24325) esp_handle_uart_pattern: AT <--
W (24325) esp_handle_uart_pattern: AT <-- OK
W (24325) esp_modem_dte_send_cmd: AT --> ATD*99***1#
W (24335) esp_handle_uart_pattern: AT <--
W (24335) esp_handle_uart_pattern: AT <-- NO CARRIER
W (24345) esp_modem_dte_send_cmd: AT --> ATO0
W (24355) esp_handle_uart_pattern: AT <--
W (24355) esp_handle_uart_pattern: AT <-- CONNECT 150000000
I (24465) pppos_example: Modem PPP Started
I (24465) pppos_example: PPP state changed event 259
I (24465) pppos_example: PPP state changed event 262
I (25105) pppos_example: PPP state changed event 263
I (25105) pppos_example: PPP state changed event 265
I (25135) esp-netif_lwip-ppp: Connected
I (25135) esp-netif_lwip-ppp: Name Server1: 200.58.141.163
I (25135) esp-netif_lwip-ppp: Name Server2: 200.58.157.11
I (25135) pppos_example: Modem Connect to PPP Server
I (25145) pppos_example: ~~~~~~~~~~~~~~
I (25145) pppos_example: IP : 10.155.119.219
I (25155) pppos_example: Netmask : 255.255.255.255
I (25155) pppos_example: Gateway : 10.64.64.64
I (25165) pppos_example: Name Server1: 200.58.141.163
I (25175) pppos_example: Name Server2: 200.58.157.11
I (25175) pppos_example: ~~~~~~~~~~~~~~
I (25185) pppos_example: GOT ip event!!!
I (25185) pppos_example: PPP state changed event 266
I (25195) pppos_example: MQTT other event id: 7
I (26735) pppos_example: MQTT_EVENT_CONNECTED
I (26735) pppos_example: sent subscribe successful, msg_id=7131
I (27215) pppos_example: MQTT_EVENT_SUBSCRIBED, msg_id=7131
I (27215) pppos_example: sent publish successful, msg_id=0
I (27695) pppos_example: MQTT_EVENT_DATA
TOPIC=tretre
DATA=esp32-pppos
W (28895) esp_handle_uart_data: AT <-- ~!E
W (29415) esp_modem_dte_send_cmd: AT --> +++
E (34415) esp-modem: esp_modem_dte_send_cmd(308): process command timeout
I (34415) bg96: Sending "+++" command failed
W (34415) esp_modem_dte_send_cmd: AT --> AT
E (34915) esp-modem: esp_modem_dte_send_cmd(308): process command timeout
E (34915) bg96: bg96_set_working_mode(302): send command failed
E (34915) esp-modem: esp_modem_dte_change_mode(401): set new working mode:0 failed
E (34925) esp-modem: esp_modem_stop_ppp(597): enter command mode failed
ESP_ERROR_CHECK failed: esp_err_t 0xffffffff (ESP_FAIL) at 0x40083ecc
0x40083ecc: _esp_error_check_failed at /home/pablo/esp/esp-idf/components/esp_common/src/esp_err.c:45
file: "../main/pppos_client_main.c" line 303
func: app_main
expression: esp_modem_stop_ppp(dte)
abort() was called at PC 0x40083ecf on core 0
0x40083ecf: _esp_error_check_failed at /home/pablo/esp/esp-idf/components/esp_common/src/esp_err.c:46
Backtrace:0x4008501f:0x3ffb56b0 0x400856bd:0x3ffb56d0 0x4008938a:0x3ffb56f0 0x40083ecf:0x3ffb5760 0x400d599e:0x3ffb5780 0x400d3f0e:0x3ffb58b0 0x400856c5:0x3ffb58e0
0x4008501f: panic_abort at /home/pablo/esp/esp-idf/components/esp_system/panic.c:330
0x400856bd: esp_system_abort at /home/pablo/esp/esp-idf/components/esp_system/system_api.c:106
0x4008938a: abort at /home/pablo/esp/esp-idf/components/newlib/abort.c:46
0x40083ecf: _esp_error_check_failed at /home/pablo/esp/esp-idf/components/esp_common/src/esp_err.c:46
0x400d599e: app_main at /home/pablo/esp_example_code/pppos_client/build/../main/pppos_client_main.c:303 (discriminator 1)
0x400d3f0e: main_task at /home/pablo/esp/esp-idf/components/esp32/cpu_start.c:600 (discriminator 2)
0x400856c5: vPortTaskWrapper at /home/pablo/esp/esp-idf/components/freertos/xtensa/port.c:143
ELF file SHA256: 58b6b4143284fd79
Rebooting...
Any idea of what could be the problem?