espconn_recv_hold reset the module when using TLS/SSL

vitorborgo commented 7 years ago

Basic Infos

Hardware

Hardware: ?ESP-07?

Description

When I enable SSL/TLS mode, everything works fine until the FIFO buffer reaches 2kb and my algorythm call function "espconn_recv_hold". Then the module crashes and resets. *** I tested it twice: The first one setting the recv hold trigger up than the buffer size (to never hit) and the problems desappeard, and the seccond, the trigger is set to 256b (what triggs the problem).

I'm working with ESP8266/ESP-07 with 2.1.0 NONOS SDK.
At the moment, I am developing a project using esp07 as a [TCP <-> UART0] bridge.
The ESP MCU works as client and connect to a MQTT server.
I enabled TLS comunication, and its working fine.
The free heap size is OK too.
I have implemented 2 FIFOs, one at TCP->Uart0 side (10480 bytes size), and another one at UART0->TCP (2048 bytes).
At UART0 I have implemented CTS/RTS algorythm, but at the TCP side I had to use espconn_recv_hold (that is the reason of the 10kb buffer)
I have already tested the firmware as a bridge without TLS/SSL, and works fine. Recv hold api function is triggered when TCP->uart0 FIFO reaches 2kb.
Tested using a file 44Mb size, transmitting both sides twice. [(55kb/s TCP -> uart0);(42kb/s uart0 ->TCP)] (it is perfect).

Solutions already tested: Suply voltage was already tested using 3.3V/2A power source. The reset pin is setted to high level all the time.

So I thing it is not energy problem, althought the "rst cause:2" Im really confused about this issue, and would like to know if it is a bug or I am doing something wrong.

Settings in IDE

Module: ?Generic ESP8266 Module? Flash Size: ?4Mbit? CPU Frequency: ?160Mhz? Flash Mode: ?qio? Flash Frequency: ?26Mhz? Upload Using: ?OTA / SERIAL? Reset Method: ?ck?

Sketch

Sorry for not provide all the info. The project is very long, so i will post the code that matters. I'm using last SDK 2.1.0

Here is the task I call every ms (or when data arrives to the bridge) to redirect the FIFOs data. Im using ConfigRAM.SSL.security = true to work with TLS/SSL (already correct initialized)

#define MAX_TCP_WRITE_SIZE  256
#define MAX_TCP_READ_PROCESS_AT_A_TIME 1024
static unsigned int lenghtSendTCP = 0;
void ICACHE_FLASH_ATTR tcp_task()
{
    unsigned int i;
    unsigned char data;
    static bool pendingSendTCP = false;
    static uint8 TCPOutBuffer[MAX_TCP_WRITE_SIZE];

    struct espconn* serverTCP = getServerConnTCP();

    // (TCP -> UART0) ---------------------------------------------------------
    i = 0;
    while(i < MAX_TCP_READ_PROCESS_AT_A_TIME && TCP_RX_GetUsedFIFO() && GPIO_INPUT_GET(GPIO_ID_PIN(CTS_PIN)) == false)
    {//quando tiver dado na Fifo e o pino de CTS estiver em nível lógico baixo
        if(TCP_RX_GetDataFIFO(&data) == TRUE)
        {
            uart0_write_char(data);
            i++;
        }
    }

    if(TCP_RX_GetUsedFIFO() < (RECV_HOLD_TRIGGER/2) && get_recv_hold() == true)
    {
        espconn_recv_unhold(serverTCP);
        set_recv_hold(false);
    }
    // ------------------------------------------------------------------------

    // (UART0 -> TCP) ---------------------------------------------------------
    if (serverTCP->state == ESPCONN_CONNECT ||
        serverTCP->state == ESPCONN_WRITE ||
        serverTCP->state == ESPCONN_READ)
    {
        if (RXFIFO_GetUsed() || lenghtSendTCP > 0)
        {
            if (lenghtSendTCP == 0)
            {
                while(RXFIFO_GetUsed() && lenghtSendTCP < MAX_TCP_WRITE_SIZE) //-> Dont get more data from FIFO if there is remaining data to send
                {
                    if (RXFIFO_GetData(&data))
                    {
                        TCPOutBuffer[lenghtSendTCP++] = data;
                    }
                }
            }

            if(ConfigRAM.SSL.security == false)
            {
               if(espconn_send(serverTCP, (uint8_t*)TCPOutBuffer, lenghtSendTCP) == ESPCONN_OK)
                   lenghtSendTCP = 0;
            }
            else
            {
                if (readyToSend == true)
                {
                    sint8 answ;
                    static sint8 aux;

                    answ = espconn_secure_send(serverTCP, (uint8_t*)TCPOutBuffer, lenghtSendTCP);
                    if(aux != answ)
                    {
                        aux = answ;
                        INFO("SECURE SEND %db, return code: %d\r\n",lenghtSendTCP, aux);
                    }

                    if(answ == ESPCONN_OK)
                    {
                        readyToSend = false;
                        lenghtSendTCP = 0;
                    }
                }
            }
        }
    }

    // ------------------------------------------------------------------------
}

Here is the TCP receive callback function where recv_hold is called (The RECV_HOLD_TRIGGER is 2kb size and the FIFOs buffer is 10kb size)

#define RECV_HOLD_TRIGGER 2048
static void ICACHE_FLASH_ATTR serverRecvCb(void *arg, char *data, unsigned short len)
{

    //struct espconn *conn = (struct espconn *) arg;

    blink_LED(); //sinaliza que recebeu

    if (command_mode == DISABLED_CMD_MODE && os_strncmp(data,CMD_MODE_KEY,sizeof(CMD_MODE_KEY)-1) == 0)
    {
        command_mode = TCP_CMD_MODE;
        start_cmd_mode(serverConnTCP);
    }

    //INFO("RecvCB: recvhold - %d, data len - %d\r\n", recv_holded, len);

    if (command_mode == TCP_CMD_MODE)
        config_parse(data, len);
    else
        TCP_RX_SendStringToFIFO(data,len); //TCP RX -> uart0 TX

    if(TCP_RX_GetUsedFIFO() > RECV_HOLD_TRIGGER && if(TCP_RX_GetUsedFIFO() > RECV_HOLD_TRIGGER && get_recv_hold() == false))
    {
        set_recv_hold(true);
        espconn_recv_hold(serverConnTCP);
    }

    INFO("Received Data Cb\r\n");
}

Debug Messages

When the mcu crashes the following debug message is shown:

_DEBUG SERIAL MESSAGES:_

     ets Jan  8 2013,rst cause:2, boot mode:(3,6)

    load 0x40100000, len 29964, room 16
    tail 12
    chksum 0x98
    ho 0 tail 12 room 4
    load 0x3ffe8000, len 2212, room 12
    tail 8
    chksum 0xbb
    load 0x3ffe88b0, len 8252, room 0
    tail 12
    chksum 0xdf
    csum 0xdf
    ŒãìƒìÛ{‚òn|ì
    lŒìl`c’
    ž|{ÛlÜnà
    ‚nãl`ŒârÛlŒlŒ

nemonote01 commented 7 years ago

Hi @vitorborgo ,

First In ESP8266 NONOS SDK, you should use --lmbedtls instead of -lssl.

Can you add this on your initialization code and find which function crashed on your platform:

struct rst_info *rtc_info = system_get_rst_info();

os_printf("reset reason: %x\n", rtc_info->reason);

if (rtc_info->reason == REASON_WDT_RST ||
    rtc_info->reason == REASON_EXCEPTION_RST ||
    rtc_info->reason == REASON_SOFT_WDT_RST) {
    if (rtc_info->reason == REASON_EXCEPTION_RST) {
        os_printf("Fatal exception (%d):\n", rtc_info->exccause);
    }
    os_printf("epc1=0x%08x, epc2=0x%08x, epc3=0x%08x, excvaddr=0x%08x, depc=0x%08x\n",
            rtc_info->epc1, rtc_info->epc2, rtc_info->epc3, rtc_info->excvaddr, rtc_info->depc);
}

vitorborgo commented 6 years ago

Hi @zhang-jun-hao , thanks for your assistence.

This is the debug message using your code on my inicialization when the firmware crashes. Now, how can I find which function crashed on my platform?

reset reason: 2

Fatal exception (28):
epc1=0x40240dd0, epc2=0x00000000, epc3=0x00000000, excvaddr=0x0000002c, depc=0x00000000

This is my makefile. I'm using mbedtls.

# tnx to mamalala
# Changelog
# Changed the variables to include the header file directory
# Added global var for the XTENSA tool root
#
# This make file still needs some work.
#
#
# Output directors to store intermediate compiled files
# relative to the project directory
BUILD_BASE  = build
FW_BASE     = firmware

# Base directory for the compiler
XTENSA_TOOLS_ROOT ?= c:/Espressif/xtensa-lx106-elf/bin

# base directory of the ESP8266 SDK package, absolute

SDK_BASE    ?= c:/Espressif/ESP8266_SDK_210_MOD

#Esptool.py path and port
ESPTOOL     ?= C:/Espressif/utils/esptool.exe
ESPPORT     ?= COM7
ESPBAUD     ?= 115200

# name for the target project
TARGET      = app

# which modules (subdirectories) of the project to include in compiling
MODULES     = driver flash user #mqtt
EXTRA_INCDIR    = include /opt/Espressif/include

# libraries used in this project, mainly provided by the SDK
LIBS        = c gcc hal pp phy crypto main pp net80211 lwip wpa mbedtls

# compiler flags using during compilation of source files
CFLAGS      = -Os -g -O2 -Wpointer-arith -Wundef -Werror -Wl,-EL -fno-inline-functions -nostdlib -mlongcalls -mtext-section-literals  -D__ets__ -DICACHE_FLASH

# linker flags used to generate the main object file
LDFLAGS     = -nostdlib -Wl,--no-check-sections -u call_user_start -Wl,-static

# linker script used for the above linkier step
LD_SCRIPT   = eagle.app.v6.ld

# various paths from the SDK used in this project
SDK_LIBDIR  = lib
SDK_LDDIR   = ld
SDK_INCDIR  = include include/json

# we create two different files for uploading into the flash
# these are the names and options to generate them
FW_FILE_1_ADDR = 0x00000
FW_FILE_1   = $(FW_FILE_1_ADDR)
FW_FILE_1_ARGS  = -bo $@ -bs .text -bs .data -bs .rodata -bc -ec
FW_FILE_2_ADDR = 0x10000
FW_FILE_2   = $(FW_FILE_2_ADDR)
FW_FILE_2_ARGS  = -es .irom0.text $@ -ec

# init data default needed to be uploaded into the flash
ESP_INIT_DATA_DEFAULT_ADDR = 0x7c000
ESP_BLANK_ADDR = 0x7e000

# tqtq ca certificate
ESP_CA_CERT_ADDR = 0x77000

# select which tools to use as compiler, librarian and linker
CC      := $(XTENSA_TOOLS_ROOT)/xtensa-lx106-elf-gcc
AR      := $(XTENSA_TOOLS_ROOT)/xtensa-lx106-elf-ar
LD      := $(XTENSA_TOOLS_ROOT)/xtensa-lx106-elf-gcc

########## To work with larger firmwamre setting FW_FILE_2_ADDR = 0x10000 with 4Mbit flash ESP8266 ESP07#####
###PS: Edit on file eagle.app.v6.ld
#MEMORY
#{
#  dport0_0_seg :                        org = 0x3FF00000, len = 0x10
#  dram0_0_seg :                         org = 0x3FFE8000, len = 0x14000
#  iram1_0_seg :                         org = 0x40100000, len = 0x8000
#  irom0_0_seg :                         org = 0x40210000, len = 0xEC000
#}
########################################################################################################

####
#### no user configurable options below here
####
FW_TOOL     ?= C:/Espressif/utils/esptool-ck
SRC_DIR     := $(MODULES)
BUILD_DIR   := $(addprefix $(BUILD_BASE)/,$(MODULES))

SDK_LIBDIR  := $(addprefix $(SDK_BASE)/,$(SDK_LIBDIR))
SDK_INCDIR  := $(addprefix -I$(SDK_BASE)/,$(SDK_INCDIR))

SRC     := $(foreach sdir,$(SRC_DIR),$(wildcard $(sdir)/*.c))
OBJ     := $(patsubst %.c,$(BUILD_BASE)/%.o,$(SRC))
LIBS        := $(addprefix -l,$(LIBS))
APP_AR      := $(addprefix $(BUILD_BASE)/,$(TARGET)_app.a)
TARGET_OUT  := $(addprefix $(BUILD_BASE)/,$(TARGET).out)

LD_SCRIPT   := $(addprefix -T$(SDK_BASE)/$(SDK_LDDIR)/,$(LD_SCRIPT))

INCDIR  := $(addprefix -I,$(SRC_DIR))
EXTRA_INCDIR    := $(addprefix -I,$(EXTRA_INCDIR))
MODULE_INCDIR   := $(addsuffix /include,$(INCDIR))

FW_FILE_1   := $(addprefix $(FW_BASE)/,$(FW_FILE_1).bin)
FW_FILE_2   := $(addprefix $(FW_BASE)/,$(FW_FILE_2).bin)

VERBOSE := 0

V ?= $(VERBOSE)
ifeq ("$(V)","1")
Q :=
vecho := @true
else
Q := @
vecho := @echo
endif

vpath %.c $(SRC_DIR)

define compile-objects
$1/%.o: %.c
    $(vecho) "CC $$<"
    $(Q) $(CC) $(INCDIR) $(MODULE_INCDIR) $(EXTRA_INCDIR) $(SDK_INCDIR) $(CFLAGS)  -c $$< -o $$@
endef

.PHONY: all checkdirs flash clean

all: checkdirs $(TARGET_OUT) $(FW_FILE_1) $(FW_FILE_2)

$(FW_FILE_1): $(TARGET_OUT)
    $(vecho) "FW $@"
    $(Q) $(FW_TOOL) -eo $(TARGET_OUT) $(FW_FILE_1_ARGS)

$(FW_FILE_2): $(TARGET_OUT)
    $(vecho) "FW $@"
    $(Q) $(FW_TOOL) -eo $(TARGET_OUT) $(FW_FILE_2_ARGS)

$(TARGET_OUT): $(APP_AR)
    $(vecho) "LD $@"
    $(Q) $(LD) -L$(SDK_LIBDIR) $(LD_SCRIPT) $(LDFLAGS) -Wl,--start-group $(LIBS) $(APP_AR) -Wl,--end-group -o $@

$(APP_AR): $(OBJ)
    $(vecho) "AR $@"
    $(Q) $(AR) cru $@ $^

checkdirs: $(BUILD_DIR) $(FW_BASE)

$(BUILD_DIR):
    $(Q) mkdir -p $@

firmware:
    $(Q) mkdir -p $@

flash: $(FW_FILE_1) $(FW_FILE_2)
    -$(ESPTOOL) --port $(ESPPORT) write_flash --flash_size 4m  $(FW_FILE_1_ADDR) $(FW_FILE_1) $(FW_FILE_2_ADDR) $(FW_FILE_2) $(ESP_BLANK_ADDR) $(SDK_BASE)/bin/blank.bin $(ESP_INIT_DATA_DEFAULT_ADDR) $(SDK_BASE)/bin/esp_init_data_default.bin $(ESP_CA_CERT_ADDR) $(SDK_BASE)/bin/20170803_tqtq_esp_ca_cert.bin  #$(SDK_BASE)/bin/localhost_esp_ca_cert.bin
#   -$(ESPTOOL) --port $(ESPPORT) write_flash 0x88000 blank20k.bin limpar a configuração wifi

clean:
    $(Q) rm -f $(APP_AR)
    $(Q) rm -f $(TARGET_OUT)
    $(Q) rm -rf $(BUILD_DIR)
    $(Q) rm -rf $(BUILD_BASE)

    $(Q) rm -f $(FW_FILE_1)
    $(Q) rm -f $(FW_FILE_2)
    $(Q) rm -rf $(FW_BASE)
    $(Q) rm -rf *.bak

$(foreach bdir,$(BUILD_DIR),$(eval $(call compile-objects,$(bdir))))

nemonote01 commented 6 years ago

Hi @vitorborgo ,

The crash code address is epc1=0x40240dd0. Please locate it in your app.s.

vitorborgo commented 6 years ago

Hi, @zhang-jun-hao, I found these two files ("app.out" and "app_app.a") on my project folder, but not "app.s".

build.zip

vitorborgo commented 6 years ago

Following this instructions:

If you want to find the origin of your problem, you can disassemble the .out elf file that has been produced during compilation. To do it, just type:

C:\ESP8266\ESP8266windev\xtensa-lx106-elf\bin\xtensa-lx106-elf-objdump.exe -d esp8266_at.out >disassemble.txt

I made the disassemble process for "app.out" and generate the following file (disassemble.zip/disassemble.txt):

app_out_disassemble.zip

   ...
40240dc4 <tcp_recved>:
40240dc4:   f0c112          addi    a1, a1, -16
40240dc7:   0161c2          s32i    a12, a1, 4
40240dca:   006102          s32i    a0, a1, 0
40240dcd:   20c220          or  a12, a2, a2
40240dd0:   161222          l16ui   a2, a2, 44
40240dd3:   21d9        s32i.n  a13, a1, 8
40240dd5:   223a        add.n   a2, a2, a3
40240dd7:   f42020          extui   a2, a2, 0, 16
40240dda:   165c22          s16i    a2, a12, 44
40240ddd:   8f50d1          l32r    a13, 40224b20 <flash_data_check+0xb4>
40240de0:   0020c0          memw
40240de3:   fc2d02          l32i    a0, a13, 0x3f0
40240de6:   08b027          bgeu    a0, a2, 40240df2 <tcp_recved+0x2e>
40240de9:   0020c0          memw
40240dec:   fc2d32          l32i    a3, a13, 0x3f0
40240def:   165c32          s16i    a3, a12, 44
40240df2:   0c2d        mov.n   a2, a12
40240df4:   fff885          call0   40240d80 <tcp_update_rcv_ann_wnd>
40240df7:   0020c0          memw
40240dfa:   fc2d42          l32i    a4, a13, 0x3f0
40240dfd:   21d8        l32i.n  a13, a1, 8
40240dff:   414240          srli    a4, a4, 2
40240e02:   0f3247          bltu    a2, a4, 40240e15 <tcp_recved+0x51>
40240e05:   0c2d        mov.n   a2, a12
40240e07:   240c52          l8ui    a5, a12, 36
40240e0a:   260c        movi.n  a6, 2
40240e0c:   205560          or  a5, a5, a6
40240e0f:   244c52          s8i a5, a12, 36
40240e12:   00f405          call0   40241d54 <tcp_output>
40240e15:   11c8        l32i.n  a12, a1, 4
40240e17:   0108        l32i.n  a0, a1, 0
40240e19:   10c112          addi    a1, a1, 16
40240e1c:   f00d        ret.n
   ...

What information I can interpret from disassemble? @zhang-jun-hao

nemonote01 commented 6 years ago

Hi @vitorborgo

It was crashed at tcp_recved() function in thirdparty/lwip/core/tcp.c. It is recommended that you add some log in this function, and run ./makelib.sh lwip in the thirdparty folder to regenerate a new lwip.a with your log. You can also send your code to my email zhangjunhao@espressif.com.

vitorborgo commented 6 years ago

Hi, @zhang-jun-hao

My 'TCP received callback' function, like above on my first post:

It only puts data into TCP RX FIFO, and calls recv_hold when the buffer occuped data size reaches the trigger defined by RECV_HOLD_TRIGGER.
command_mode == TCP_CMD_MODE and config_parse(data, len); are not used when the firmware crashes, it's just to access the internal commands to configure the module.
RECV_HOLD_TRIGGER is commonly set to 2048 bytes, but to trigger the problem faster, it was set to 256 bytes.
If recv_hold is not called, the problem doesnt happen.

I really could not find how to run ./makelib.sh lwip to regenerate a new lwip.a. I'll be really thankfull if you show me the way or a tutorial to do it. By the way, I'm using Windows 7, in case of this command be for Linux only.

I'm sending to you my code by email, including SDK 2.1.0 folder.

nemonote01 commented 6 years ago

Hi @vitorborgo

I revised your code, and then compiled and ran it in your SDK. No system crashes were found. I send it to your email. Could you try the code in the attachment? It is recommended that you debug with the latest ESP8266_NONOS_SDK, and the latest SDK Library of lwip is open source. There is no source code of lwip in the SDK2.1.0 version.

Thanks!

nemonote01 commented 6 years ago

Hi @vitorborgo

I'm VERY sorry to tell you that mbedtls library doesn't support espconn_recv_hold and espconn_recv_unhold. Calling function espconn_revn_unhold when use TLS/SSL(mbedtls) will crash. Please be careful with the proper use of buffer to avoid packet loss because the application is not processing received buffer in time.

Thanks!

vitorborgo commented 6 years ago

Hi @zhang-jun-hao

So, it was really a bug. Will this bug be corrected on a new NONOS SDK version or it is an incompatibility between espconn_recv_hold and TLS/SSL (mbedtls) that will never let to use both simultaneously?

Thanks!

nemonote01 commented 6 years ago

Hi @vitorborgo

We'll add this functionality to the mbedtls library in the future. Please do not use both espconn_recv_unhold and TLS/SSL in the current SDK.

Thanks!

espressif / ESP8266_NONOS_SDK