OpenMQTTGateway icon indicating copy to clipboard operation
OpenMQTTGateway copied to clipboard

Published 20 hours ago • verified publisher icon 1technophile

OMG works fine, then stops after few hours

Open jmbinette opened this issue 3 years ago • 25 comments

Before submitting a problem please check the troubleshooting section https://docs.openmqttgateway.com/upload/troubleshoot.html

Describe the bug The OMG gateway stop working after a few hours

To Reproduce Remove battery, boot and wait for "freeze"

Expected behavior Run continuously without stopping

Environment (please complete the following information):

  • OpenMQTTGateway v. 0.9.10 I tried both hardware : M5 Stack AND M5 Stick C Plus I tried associated images "esp32-m5stack-ble" and "esp32-m5stick-cp-ble"

Additional context I am receiving data from one Xiaomi temperature/humidity sensor.

jmbinette avatar Feb 22 '22 19:02 jmbinette

Could you try to upload it manually and set this to false instead of true

1technophile avatar Feb 26 '22 17:02 1technophile

Hello,

I created a file called "actual_env.ini" with this content :

[platformio]
default_envs = esp32-m5stick-cp-ble

[env:esp32-m5stick-cp-ble]
platform = ${com.esp32_platform}
board = pico32
board_build.partitions = min_spiffs.csv
lib_deps =
  ${com-esp.lib_deps}
  ${libraries.wifimanager32}
  ${libraries.ble}
  ${libraries.decoder}
  ${libraries.m5stickcp}
  ${libraries.irremoteesp}
build_flags =
  ${com-esp.build_flags}
  '-DZgatewayBT="BT"'
  '-DZgatewayIR="IR"'
  '-DZsensorGPIOInput="GPIOInput"'
  '-DZboardM5STICKCP="M5StickCP"'
  '-DACTUATOR_ONOFF_GPIO=10'
  '-DINPUT_GPIO=37'
  '-DLED_SEND_RECEIVE=10'
  '-DLED_SEND_RECEIVE_ON=0'
  '-DSLEEP_BUTTON=39'
  '-DTRIGGER_GPIO=39'
  '-DIR_EMITTER_INVERTED=true'
  '-DIR_EMITTER_GPIO=9'
  '-DGateway_Name="OpenMQTTGateway_ESP32_M5STICK_CP_BLE_IR"'
  '-LOG_TO_LCD=False'
board_upload.speed = 1500000

Compiled and upload.

The LCD still displays. Did I set the flag correctly in my config ?

Or is it LCD logging only that is disabled with the flag ?

jmbinette avatar Mar 01 '22 20:03 jmbinette

You need to set it like this: '-LOG_TO_LCD="false"'

1technophile avatar Mar 01 '22 21:03 1technophile

Compiled and running, will update you in a few hours

jmbinette avatar Mar 02 '22 02:03 jmbinette

Stopped updating MQTT after +/- 2 hours :(

Last status :

{"uptime":3614,"version":"version_tag","freemem":129928,"mqttport":"1883","mqttsecure":false,"freestack":3512,"rssi":-17,"SSID":"xxx","ip":"192.168.1.175","mac":"4C:75:25:CB:8D:C0","lowpowermode":0,"btqblck":3,"btqsum":8,"btqsnd":5,"btqavg":1.6,"interval":55555,"scanbcnct":10,"scnct":1,"m5batvoltage":4.1162,"m5batcurrent":0,"m5vinvoltage":0,"m5vincurrent":0,"m5vbusvoltage":4.9912,"m5vbuscurrent":52.125,"m5tempaxp":23.60001,"m5batpower":0,"m5batchargecurrent":0,"m5apsvoltage":4.8986,"modules":["IR","BT","GPIOInput"]}

jmbinette avatar Mar 02 '22 05:03 jmbinette

Let me try to reproduce it

1technophile avatar Mar 02 '22 22:03 1technophile

Can I post most verbose logs to MQTT ? Maybe it could help ?

jmbinette avatar Mar 04 '22 04:03 jmbinette

Yes you can put the log level to LOG_LEVEL_TRACE and share here when the gateway gets stuck

1technophile avatar Mar 04 '22 11:03 1technophile

What topic should it publish to ? I still have SYStoMQTT with these values :

{"uptime":11,"version":"version_tag","freemem":123888,"mqttport":"1883","mqttsecure":false,"freestack":4568,"rssi":-23,"SSID":"xxx","ip":"192.168.1.175","mac":"4C:75:25:CB:8D:C0","lowpowermode":1,"btqblck":1,"btqsum":0,"btqsnd":0,"btqavg":0,"interval":55555,"scanbcnct":10,"scnct":0,"m5batvoltage":3.8731,"m5batcurrent":86.5,"m5vinvoltage":0,"m5vincurrent":0,"m5vbusvoltage":4.8994,"m5vbuscurrent":192,"m5tempaxp":30.60001,"m5batpower":0,"m5batchargecurrent":46.5,"m5apsvoltage":4.8006,"modules":["IR","BT","GPIOInput"]}

jmbinette avatar Mar 05 '22 03:03 jmbinette

To have access to the logs you will need to let the ESP32 connected to your computer and open a serial connection (the plug symbol in platformio).

1technophile avatar Mar 05 '22 12:03 1technophile

My log :

E NimBLEClient: "Connection failed; status=574 "
ets Jun  8 2016 00:22:57

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 188777542, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:1044
load:0x40078000,len:10124
load:0x40080400,len:5828
entry 0x400806a8
�N: 
************* ␀M5StickCPlus initializing...OK
{
  "mqtt_server": "192.168.1.72",
  "mqtt_port": "1883",
  "mqtt_user": "xxx",
  "mqtt_pass": "xxx",
  "mqtt_topic": "homeassistant/",
  "gateway_name": "OpenMQTTGateway",
  "mqtt_broker_secure": false,
  "mqtt_broker_cert": "",
  "mqtt_ss_index": 0,
  "ota_server_cert": ""
}*WM: [1] Free heap:        148640
*WM: [1] ESP-IDF version:  v3.3.5-1-g85c43024c
*WM: [3] allocating params bytes: 20
*WM: [2] Added Parameter: server
*WM: [2] Added Parameter: port
*WM: [2] Added Parameter: user
*WM: [2] Added Parameter: pass
*WM: [2] Added Parameter: secure
*WM: [3] Updated _max_params: 10
*WM: [3] re-allocating params bytes: 40
*WM: [2] Added Parameter: cert
*WM: [2] Added Parameter: name
*WM: [2] Added Parameter: topic
E (2941) wifi:sta is connecting, return error
E (3443) wifi:sta is connecting, return error
E (3944) wifi:sta is connecting, return error
E (4445) wifi:sta is connecting, return error
*WM: [1] AutoConnect
*WM: [2] ESP32 event handler enabled
*WM: [1] AutoConnect: ESP Already Connected
*WM: [1] STA static IP:
*WM: [2] setSTAConfig static ip not set
*WM: [1] AutoConnect: SUCCESS
*WM: [1] STA IP Address: 192.168.1.175
E NimBLEClient: "Connection failed; status=574 "

jmbinette avatar Mar 07 '22 03:03 jmbinette

Then trying to reboot :

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

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 188777542, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:1044
load:0x40078000,len:10124
load:0x40080400,len:5828
entry 0x400806a8
N: 
************* WELCOME TO OpenMQTTGateway **************
N: Setup M5
N: Low power set to: 2
N: Setup M5 end
N: OpenMQTTGateway Version: version_tag
{
  "mqtt_server": "192.168.1.72",
  "mqtt_port": "1883",
  "mqtt_user": "xxx",
  "mqtt_pass": "xxx",
  "mqtt_topic": "homeassistant/",
  "gateway_name": "OpenMQTTGateway",
  "mqtt_broker_secure": false,
  "mqtt_broker_cert": "",
  "mqtt_ss_index": 0,
  "ota_server_cert": ""
}*WM: [1] Free heap:        148960
*WM: [1] ESP-IDF version:  v3.3.5-1-g85c43024c
*WM: [3] allocating params bytes: 20
*WM: [2] Added Parameter: server
*WM: [2] Added Parameter: port
*WM: [2] Added Parameter: user
*WM: [2] Added Parameter: pass
*WM: [2] Added Parameter: secure
*WM: [3] Updated _max_params: 10
*WM: [3] re-allocating params bytes: 40
*WM: [2] Added Parameter: cert
*WM: [2] Added Parameter: name
*WM: [2] Added Parameter: topic
N: Attempting Wifi connection with saved AP: 0
N: Attempting Wifi connection with saved AP: 1
E (995) wifi:sta is connecting, return error
[E][WiFiSTA.cpp:221] begin(): connect failed!
N: Attempting Wifi connection with saved AP: 2
E (1497) wifi:sta is connecting, return error
[E][WiFiSTA.cpp:221] begin(): connect failed!
N: Attempting Wifi connection with saved AP: 3
E (1999) wifi:sta is connecting, return error
[E][WiFiSTA.cpp:221] begin(): connect failed!
N: Attempting Wifi connection with saved AP: 4
E (2500) wifi:sta is connecting, return error
[E][WiFiSTA.cpp:221] begin(): connect failed!
assertion "mu->handle" failed: file ".pio/libdeps/esp32-m5stick-cp-ble/NimBLE-Arduino/src/porting/npl/freertos/src/npl_os_freertos.c", line 185, function: npl_freertos_mutex_pend
abort() was called at PC 0x401321d3 on core 1

ELF file SHA256: 0000000000000000

Backtrace: 0x400908d8:0x3ffce8c0 0x40090b55:0x3ffce8e0 0x401321d3:0x3ffce900 0x400ff217:0x3ffce930 0x400f78cc:0x3ffce950 0x400f78e3:0x3ffce970 0x400f9afb:0x3ffce990 0x400fe613:0x3ffce9b0 0x400efe1e:0x3ffce9d0 0x400d3a48:0x3ffce9f0 0x400d3f95:0x3ffcea10 0x400e02db:0x3ffcea30 0x400e0752:0x3ffcebc0 0x40117ac2:0x3ffcec60 0x40091b66:0x3ffcec80

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

jmbinette avatar Mar 07 '22 04:03 jmbinette

One thing I would like to try is to set a static IP, is it possible using a parameter/flag ?

jmbinette avatar Mar 07 '22 04:03 jmbinette

Any other ideas?

Thanks,

jmbinette avatar Mar 10 '22 16:03 jmbinette

I have decoded your trace and it seems that what I was suspecting it the cause of the problem, unfortunately the solution provided is missing a D and false should be lower case, so instead of adding: '-LOG_TO_LCD=False' You should add '-DLOG_TO_LCD=false'

1technophile avatar Mar 10 '22 23:03 1technophile

Just compiled and tried again.

Here is the debug :

*WM: [1] AutoConnect 
*WM: [2] ESP32 event handler enabled
*WM: [2] Connecting as wifi client...
*WM: [1] STA static IP:
*WM: [2] setSTAConfig static ip not set
*WM: [3] WIFI station disconnect
*WM: [1] Connecting to saved AP: xxx*WM: [2] [EVENT] WIFI_REASON: 8

*WM: [3] Using Password: xxx
*WM: [3] WiFi station enable 
*WM: [2] 5000 ms connectTimeout set
*WM: [2] 5000 ms timeout, waiting for connect...
*WM: [2] .
(Multiple times the same line)
*WM: [2] . 
*WM: [2] Connection result: WL_CONNECTED
*WM: [3] lastconxresult: WL_CONNECTED
*WM: [1] AutoConnect: SUCCESS
*WM: [1] STA IP Address: 192.168.1.175
E NimBLEClient: "Connection failed; status=574 "

Rebooted the M5, then got this after another while :

E (2936) wifi:sta is connecting, return error
E (3438) wifi:sta is connecting, return error
E (3939) wifi:sta is connecting, return error
E (4440) wifi:sta is connecting, return error
*WM: [1] AutoConnect 
*WM: [2] ESP32 event handler enabled
*WM: [1] AutoConnect: ESP Already Connected
*WM: [1] STA static IP:
*WM: [2] setSTAConfig static ip not set
*WM: [1] AutoConnect: SUCCESS
*WM: [1] STA IP Address: 192.168.1.175
E NimBLEClient: "Connection failed; status=13 "

jmbinette avatar Mar 11 '22 03:03 jmbinette

Interesting that we are attempting a connect during the config Could you try to add this on your env definition please: '-DAttemptBLECOnnect=false'

1technophile avatar Mar 11 '22 20:03 1technophile

Hi,

Crashed again after +/- 20min. Here is the log :

*WM: [1] ESP-IDF version:  v3.3.5-1-g85c43024c
*WM: [3] allocating params bytes: 20
*WM: [2] Added Parameter: server
*WM: [2] Added Parameter: port
*WM: [2] Added Parameter: user
*WM: [2] Added Parameter: pass
*WM: [2] Added Parameter: secure
*WM: [3] Updated _max_params: 10
*WM: [3] re-allocating params bytes: 40
*WM: [2] Added Parameter: cert
*WM: [2] Added Parameter: name
*WM: [2] Added Parameter: topic
E (3000) wifi:sta is connecting, return error
E (3502) wifi:sta is connecting, return error
E (4003) wifi:sta is connecting, return error
E (4504) wifi:sta is connecting, return error
*WM: [1] AutoConnect 
*WM: [2] ESP32 event handler enabled
*WM: [1] AutoConnect: ESP Already Connected
*WM: [1] STA static IP:
*WM: [2] setSTAConfig static ip not set
*WM: [1] AutoConnect: SUCCESS
*WM: [1] STA IP Address: 192.168.1.175
�N: 
************* ␀M5StickCPlus initializing...OK
{
  "mqtt_server": "192.168.1.72",
  "mqtt_port": "1883",
  "mqtt_user": "xxx",
  "mqtt_pass": "xxx",
  "mqtt_topic": "homeassistant/",
  "gateway_name": "OpenMQTTGateway",
  "mqtt_broker_secure": false,
  "mqtt_broker_cert": "",
  "mqtt_ss_index": 0,
  "ota_server_cert": ""
}*WM: [1] Free heap:        148728
*WM: [1] ESP-IDF version:  v3.3.5-1-g85c43024c
*WM: [3] allocating params bytes: 20
*WM: [2] Added Parameter: server
*WM: [2] Added Parameter: port
*WM: [2] Added Parameter: user
*WM: [2] Added Parameter: pass
*WM: [2] Added Parameter: secure
*WM: [3] Updated _max_params: 10
*WM: [3] re-allocating params bytes: 40
*WM: [2] Added Parameter: cert
*WM: [2] Added Parameter: name
*WM: [2] Added Parameter: topic
E (2917) wifi:sta is connecting, return error
E (3419) wifi:sta is connecting, return error
E (3920) wifi:sta is connecting, return error
E (4421) wifi:sta is connecting, return error
*WM: [1] AutoConnect 
*WM: [2] ESP32 event handler enabled
*WM: [1] AutoConnect: ESP Already Connected
*WM: [1] STA static IP:
*WM: [2] setSTAConfig static ip not set
*WM: [1] AutoConnect: SUCCESS 
*WM: [1] STA IP Address: 192.168.1.175
␀

(NUL is part of the log, this is exactly what I had in the serial monitor)

jmbinette avatar Mar 14 '22 17:03 jmbinette

Sorry to bother, let me know if you have other debug ideas !

jmbinette avatar Mar 16 '22 19:03 jmbinette

No problem, thanks for the reminder. Could you try to erase the flash and reupload the last config?

if it doesn't work you can try to erase again the flash and upload the base esp32ble fimrware.

1technophile avatar Mar 16 '22 21:03 1technophile

Hello,

I uploaded the "esp32-lolin32lite-ble" and been running for +/-12hours .. so far so good.

I would have preferred to have M5 Stick functionalities but at least the BLE gateway seems to work

jmbinette avatar Mar 17 '22 13:03 jmbinette

I understand , I will try to do some testing so as to reproduce

1technophile avatar Mar 18 '22 00:03 1technophile

Hi! First of all, thank you for this amazing project! It's unbelievably quick and easy to get going with it. 🙇

I have the same or very similar problem then @jmbinette . After some time, when the battery runs out of juice my M5StickC Plus gets into reboot cycle. I flashed the official esp32-m5stick-cp-ble image from https://docs.openmqttgateway.com/upload/web-install.html .

Here are my logs in case it helps:

Rebooting...
N: 
************* WELCOME TO OpenMQTTGateway **************
N: Setup M5
N: Low power set to: 2
N: Setup M5 end
N: OpenMQTTGateway Version: v0.9.12
{
  "mqtt_server": "192.168.2.48",
  "mqtt_port": "1883",
  "mqtt_user": "<redacted>",
  "mqtt_pass": "<redacted>",
  "mqtt_topic": "home/",
  "gateway_name": "OpenMQTTGateway_1",
  "mqtt_broker_secure": false,
  "mqtt_broker_cert": "",
  "mqtt_ss_index": 0,
  "ota_server_cert": ""
}*WM: [1] Free heap:        148980
*WM: [1] ESP-IDF version:  v3.3.5-1-g85c43024c
*WM: [3] allocating params bytes: 20
*WM: [2] Added Parameter: server
*WM: [2] Added Parameter: port
*WM: [2] Added Parameter: user
*WM: [2] Added Parameter: pass
*WM: [2] Added Parameter: secure
*WM: [3] Updated _max_params: 10
*WM: [3] re-allocating params bytes: 40
*WM: [2] Added Parameter: cert
*WM: [2] Added Parameter: name
*WM: [2] Added Parameter: topic
N: Attempting Wifi connection with saved AP: 0
N: Attempting Wifi connection with saved AP: 1
E (990) wifi:sta is connecting, return error
[E][WiFiSTA.cpp:221] begin(): connect failed!
N: Attempting Wifi connection with saved AP: 2
E (1492) wifi:sta is connecting, return error
[E][WiFiSTA.cpp:221] begin(): connect failed!
N: Attempting Wifi connection with saved AP: 3
E (1994) wifi:sta is connecting, return error
[E][WiFiSTA.cpp:221] begin(): connect failed!
N: Attempting Wifi connection with saved AP: 4
E (2496) wifi:sta is connecting, return error
[E][WiFiSTA.cpp:221] begin(): connect failed!
assertion "mu->handle" failed: file ".pio/libdeps/esp32-m5stick-cp-ble/NimBLE-Arduino/src/porting/npl/freertos/src/npl_os_freertos.c", line 185, function: npl_freertos_mutex_pend
abort() was called at PC 0x40132bbb on core 1

ELF file SHA256: 0000000000000000

Backtrace: 0x400908d8:0x3ffce8b0 0x40090b55:0x3ffce8d0 0x40132bbb:0x3ffce8f0 0x400ff83b:0x3ffce920 0x400f7ef0:0x3ffce940 0x400f7f07:0x3ffce960 0x400fa11f:0x3ffce980 0x400fec37:0x3ffce9a0 0x400f0537:0x3ffce9c0 0x400d39fc:0x3ffce9e0 0x400d3ff5:0x3ffcea00 0x400e0bd3:0x3ffcea20 0x400e1046:0x3ffcebb0 0x401184ae:0x3ffcec50 0x40091b66:0x3ffcec70

Rebooting...
N:

jkrnak avatar Jun 05 '22 12:06 jkrnak

Hi @jkrnak ,

From the start until you get this log you are in low power mode 2 ?

1technophile avatar Jun 05 '22 14:06 1technophile

I had around 12 hours running in low power mode 0. Then I noticed in the morning that the device shut down, battery got depleted. I put on a new battery and switched to low power 2. It was going on with the new battery for some time, around 1-2 hours and then it shut down again. I'm not sure why, if the battery ran out of charge or this loop happened. Ever since it's in this loop. I will try to re-flash again and maybe power it from a wall socket to see how it behaves.

jkrnak avatar Jun 05 '22 14:06 jkrnak

Closing, feel free to comment if issue is still present

1technophile avatar Aug 30 '23 22:08 1technophile