search

mobizt / Firebase-ESP32

[DEPRECATED]🔥 Firebase RTDB Arduino Library for ESP32. The complete, fast, secured and reliable Firebase Arduino client library that supports CRUD (create, read, update, delete) and Stream operations.
MIT License
415 stars 118 forks source link

Reboots using Callback example #213

Closed simondddd closed 2 years ago

simondddd commented 2 years ago

Describe the bug Reboots (when connection fails?) using Callback example. Guru Meditation Error: (LoadProhibited) and (InstrFetchProhibited)

To Reproduce Steps to reproduce the behavior:

  1. Use Callback.ino example during some hours
  2. Reboots happen

Expected behavior Stable operation

Versions:

Additional context Trying to solve stability issues in the project I am working on I have been removing code, and as it fails with the more simple version, I have tried the example, and it also fails. They are not the same errors, but as this is the use case example I expected it to be stable. I have tried different ESP32 and different wifi connections (work and home). Maybe the connection fails because of my internet, but I do not experience any glitch in other uses. The code is the example with changed wifi and firebase data and the loop from 15 to 60 seconds as our projects upload data every 60 seconds. I have tried removing "#define FIREBASE_USE_PSRAM" from FirebaseFS.h as the ESP32 I am using does not have PSRAM. ESP Exception Decoder says "Decode Failed"

CallbackSimon.txt ERROR-FIREBASE_USE_PSRAM.txt ERROR-NO_FIREBASE_USE_PSRAM-1.txt ERROR-NO_FIREBASE_USE_PSRAM-2.txt ERROR-NO_FIREBASE_USE_PSRAM-3.txt

simondddd commented 2 years ago

Maybe I am doing something wrong or reboot is expected behaviour when loosing connection and both my internet connections are not stable. What more can I test or do?

Also I think FIREBASE_CLIENT_VERSION from FirebaseESP32.h is not updated from 3.14.4 to 3.14.5 number (It says 3.14.4 version in serial output) https://github.com/mobizt/Firebase-ESP32/blob/3985dcb5c88c95a2b537bf2363425a6b157cdaa6/src/FirebaseESP32.h#L2

mobizt commented 2 years ago

The PSRAM is not the issue.

The define FIREBASE_USE_PSRAM is just to allow library to use PSRAM.

If PSRAM is never enable in IDE during build the PSRAM will never be used as we check the existence of PSRAM using ESP32 core sdk even this FIREBASE_USE_PSRAM was defined.

You should enable WiFI and SSL debug in Arduino IDE.

You should debug the stack trace and post the result here.

Please don't attach as file or image to the post because of I'm not convenient to download and open it on my PC.

With the well manage wrapper TCP client as you can use other Arduino Client with this library too, with my intensive test, this issue will not happen in all WIFI, ethernet and internet situations.

The most possible causes are in somewhere in the core libraries which fail to read/write memory due to unstable, noisy or weak supply voltage.

simondddd commented 2 years ago

Thank you for the PSRAM clarification. I have enabled: Tools -> Core Debug Level -> Verbose What more do you suggest me to do for debug? I have just bought an esp-prog jtag device. Are you suggesting to use a specific TCP library, or that the included is very good? I have reproduced the issue and this is what I see:

[V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS This reduces from ~250000 at start, to ~200000 after the first loop, and then slowly and gradually to ~128000 where it fails with: [E][ssl_client.cpp:36] _handle_error(): [start_ssl_client():254]: (-32512) SSL - Memory allocation failed.

This is the serial output near the reboot.


[21255935][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21255937][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21255938][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 131112
[21255946][V][ssl_client.cpp:67] start_ssl_client(): Starting socket
[21256005][V][ssl_client.cpp:143] start_ssl_client(): Seeding the random number generator
[21256006][V][ssl_client.cpp:152] start_ssl_client(): Setting up the SSL/TLS structure...
[21256010][I][ssl_client.cpp:173] start_ssl_client(): WARNING: Skipping SSL Verification. INSECURE!
[21256018][V][ssl_client.cpp:244] start_ssl_client(): Setting hostname for TLS session...
[21256027][V][ssl_client.cpp:259] start_ssl_client(): Performing the SSL/TLS handshake...
[21257333][V][ssl_client.cpp:280] start_ssl_client(): Verifying peer X.509 certificate...
[21257333][V][ssl_client.cpp:288] start_ssl_client(): Certificate verified.
[21257336][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 88040
[21257344][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 37 bytes...
[21257354][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 921 bytes...
[21257363][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 250 bytes...
[21257370][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 26 bytes...
Set json... ok

sream path, /test/stream/data
event path, /json
data type, json
event type, put

Pretty printed JSON data:
{
    "data": "hello",
    "num": 355
}
Iterate JSON data:

0, Type: object, Name: data, Value: "hello"
1, Type: object, Name: num, Value: 355

Received stream payload size: 69 (Max. 74)

Token info: type = id token, status = on request
[21280999][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281000][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281001][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281013][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281015][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281028][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281029][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281040][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 127720
[21281042][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281055][V][ssl_client.cpp:67] start_ssl_client(): Starting socket
[21281057][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281070][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281077][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281084][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281091][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281098][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281104][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281111][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281116][V][ssl_client.cpp:143] start_ssl_client(): Seeding the random number generator
[21281118][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281131][V][ssl_client.cpp:152] start_ssl_client(): Setting up the SSL/TLS structure...
[21281133][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281145][I][ssl_client.cpp:173] start_ssl_client(): WARNING: Skipping SSL Verification. INSECURE!
[21281148][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281161][V][ssl_client.cpp:244] start_ssl_client(): Setting hostname for TLS session...
[21281163][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281176][E][ssl_client.cpp:36] _handle_error(): [start_ssl_client():254]: (-32512) SSL - Memory allocation failed
[21281178][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281193][E][WiFiClientSecure.cpp:135] connect(): start_ssl_client: -32512
[21281195][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281208][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281209][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281220][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281222][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
Token info: type = id token, status = error
Token info: type = id token, status = on request
[21281244][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281248][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281255][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281263][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281269][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 124012
[21281277][V][ssl_client.cpp:67] start_ssl_client(): Starting socket
Token error: code: -4, message: connection lost
[21281294][E][ssl_client.cpp:135] start_ssl_client(): LWIP Socket config of SO_RCVTIMEO failed.
[21281296][E][WiFiClientSecure.cpp:135] connect(): start_ssl_client: -1
[21281302][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281309][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
Token info: type = id token, status = error
Token error: code: -4, message: connection lost
[21281326][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281330][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281337][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[21281294][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
CORRUPT HEAP: Bad head at 0x3ffdbb20. Expected 0xabba1234 got 0x3ffc7c3c

assert failed: multi_heap_free multi_heap_poisoning.c:253 (head != NULL)

Backtrace:0x400835f1:0x3ffb23f00x4008c901:0x3ffb2410 0x40091b29:0x3ffb2430 0x4009176f:0x3ffb2560 0x40083aa5:0x3ffb2580 0x40091b59:0x3ffb25a0 0x40168971:0x3ffb25c0 0x400e6add:0x3ffb25e0 0x400e3cf9:0x3ffb2600 0x400e4559:0x3ffb2620 0x400e66e5:0x3ffb2660 0x400e67f7:0x3ffb2680 0x400e680b:0x3ffb26a0 0x400d7f16:0x3ffb26c0 0x400d3337:0x3ffb26e0 0x400eddc1:0x3ffb2820 

ELF file SHA256: 0000000000000000

Rebooting...
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0030,len:1324
ho 0 tail 12 room 4
load:0x40078000,len:13508
load:0x40080400,len:3604
entry 0x400805f0
[ -hal-cpu.c:211] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
[    54][D][WiFiGeneric.cpp:831] _eventCallback(): Arduino Event: 0 - WIFI_READY
[   147][V][WiFiGeneric.cpp:272] _arduino_event_cb(): STA Started
[   148][V][WiFiGeneric.cpp:96] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
[   148][D][WiFiGeneric.cpp:831] _eventCallback(): Arduino Event: 2 - STA_START
Connecting to Wi-Fi.......[  2237][V][WiFiGeneric.cpp:284] _arduino_event_cb(): STA Connected: SSID: WAYTELFIBRA_WAYTEL, BSSID: 04:5e:a4:b9:55:7d, Channel: 11, Auth: WPA2_PSK
[  2239][D][WiFiGeneric.cpp:831] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
............[  5582][V][WiFiGeneric.cpp:294] _arduino_event_cb(): STA Got New IP:192.168.100.83
[  5582][D][WiFiGeneric.cpp:831] _eventCallback(): Arduino Event: 7 - STA_GOT_IP
[  5585][D][WiFiGeneric.cpp:880] _eventCallback(): STA IP: 192.168.100.83, MASK: 255.255.255.0, GW: 192.168.100.1

Connected with IP: 192.168.100.83

Firebase Client v3.14.4

Token info: type = id token, status = on request
[  5873][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  5877][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  5884][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  5892][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  5897][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 254256
[  5905][V][ssl_client.cpp:67] start_ssl_client(): Starting socket
[  6345][V][ssl_client.cpp:143] start_ssl_client(): Seeding the random number generator
[  6346][V][ssl_client.cpp:152] start_ssl_client(): Setting up the SSL/TLS structure...
[  6350][I][ssl_client.cpp:173] start_ssl_client(): WARNING: Skipping SSL Verification. INSECURE!
[  6358][V][ssl_client.cpp:244] start_ssl_client(): Setting hostname for TLS session...
[  6366][V][ssl_client.cpp:259] start_ssl_client(): Performing the SSL/TLS handshake...
[  7955][V][ssl_client.cpp:280] start_ssl_client(): Verifying peer X.509 certificate...
[  7955][V][ssl_client.cpp:288] start_ssl_client(): Certificate verified.
[  7958][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 210308
[  7966][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 284 bytes...
[  8169][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  8172][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  8172][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
Token info: type = id token, status = ready
[  8189][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  8190][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  8195][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  8201][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  8208][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  8215][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  8222][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 253436
[  8229][V][ssl_client.cpp:67] start_ssl_client(): Starting socket
[  8288][V][ssl_client.cpp:143] start_ssl_client(): Seeding the random number generator
[  8290][V][ssl_client.cpp:152] start_ssl_client(): Setting up the SSL/TLS structure...
[  8293][I][ssl_client.cpp:173] start_ssl_client(): WARNING: Skipping SSL Verification. INSECURE!
[  8301][V][ssl_client.cpp:244] start_ssl_client(): Setting hostname for TLS session...
[  8309][V][ssl_client.cpp:259] start_ssl_client(): Performing the SSL/TLS handshake...
[  9156][V][ssl_client.cpp:280] start_ssl_client(): Verifying peer X.509 certificate...
[  9156][V][ssl_client.cpp:288] start_ssl_client(): Certificate verified.
[  9159][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 210276
[  9167][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 32 bytes...
[  9175][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 921 bytes...
[  9184][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 198 bytes...
[  9193][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  9196][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  9203][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  9210][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  9217][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[  9223][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 200824
sream path, /test/stream/data
event path, /
data type, json
event type, put

Pretty printed JSON data:
{
    "json": {
        "data": "hello",
        "num": 355
    }
}
Iterate JSON data:

0, Type: object, Name: json, Value: {"data":"hello","num":355}
1, Type: object, Name: data, Value: "hello"
2, Type: object, Name: num, Value: 355

Received stream payload size: 74 (Max. 74)

I see "Starting socket" every 3 loops, maybe that is the time the socket stay open and then closes and it has to open again:

[1631508][V][ssl_client.cpp:311] stop_ssl_socket(): Cleaning SSL connection.
[1631510][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 195436
[1631518][V][ssl_client.cpp:67] start_ssl_client(): Starting socket
[1631539][V][ssl_client.cpp:143] start_ssl_client(): Seeding the random number generator
[1631540][V][ssl_client.cpp:152] start_ssl_client(): Setting up the SSL/TLS structure...
[1631543][I][ssl_client.cpp:173] start_ssl_client(): WARNING: Skipping SSL Verification. INSECURE!
[1631552][V][ssl_client.cpp:244] start_ssl_client(): Setting hostname for TLS session...
[1631560][V][ssl_client.cpp:259] start_ssl_client(): Performing the SSL/TLS handshake...
[1632499][V][ssl_client.cpp:280] start_ssl_client(): Verifying peer X.509 certificate...
[1632499][V][ssl_client.cpp:288] start_ssl_client(): Certificate verified.
[1632502][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 152400
[1632510][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 37 bytes...
[1632519][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 921 bytes...
[1632528][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 250 bytes...
[1632535][V][ssl_client.cpp:351] send_ssl_data(): Writing HTTP request with 25 bytes...

This is the memory in some middle loops:

[11896834][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 117712
[12075785][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 160276
[12076863][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 117220
[12255787][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 159816
[12256898][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 116688
[12435791][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 159300
[12436965][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 116184
[12615793][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 158864
[12616960][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 115776
[12795796][V][ssl_client.cpp:61] start_ssl_client(): Free internal heap before TLS 158404
[12797068][V][ssl_client.cpp:303] start_ssl_client(): Free internal heap after TLS 115348
mobizt commented 2 years ago

The library update v3.15.0 is available with the bugs fixed. Please try.

simondddd commented 2 years ago

Yes, example works stable now. Thank you.