letscontrolit / ESPEasy

Easy MultiSensor device based on ESP8266/ESP32
http://www.espeasy.com
Other
3.28k stars 2.22k forks source link

reboot after deepsleep #3072

Closed stefbo27 closed 4 years ago

stefbo27 commented 4 years ago

After waking up from deepsleep I get the following log:

1889 : Info  : WIFI : Connected! AP: Bruni (9C:C7:A6:81:E6:56) Ch: 11 Duration: 21 ms
1891 : Info  : WIFI : DHCP IP: 192.168.178.111 (esp12-01test2-11) GW: 192.168.178.1 SN: 255.255.0.0   duration: 18 ms
1907 : Info  : WIFI  : WiFiConnected() out of sync
1908 : Info  : WIFI  : WiFiConnected() out of sync
1908 : Info  : WIFI  : WiFiConn
Exception (29):
epc1=0x4026ebd5 epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000000 depc=0x00000000
...

Same happens with fixed IP:

1669 : Info  : WIFI : Connecting Bruni attempt #1
1895 : Info  : WIFI : Connected! AP: Bruni (9C:C7:A6:81:E6:56) Ch: 11 Duration: 23 ms
1897 : Info  : WIFI : Static IP: 192.168.178.111 (esp12-01test2-11) GW: 192.168.178.1 SN: 255.255.255.0   duration: 202 ms
1913 : Info  : WIFI  : WiFiConnected() out of sync
1913 : Info  : WIFI  : WiFiConnected() out of sync
1914 : Info  : WIFI  : Wi
Exception (29):
epc1=0x4026ebd5 epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000000 depc=0x00000000
...

I am using latest version (mega20200515). Same observation with another device. Both were running before with older version (~1month old) without problems.

TD-er commented 4 years ago

Hmm I was preparing the release as Travis messed up, but reports like these will be a good reason to pause it a bit and test it first tomorrow morning.

This is the ZIP I prepared. Can you please test it before I finalize the release.

TD-er commented 4 years ago

Can you also test a 'beta' labelled build from that zip file? If that's working then I will update the core lib also.

TD-er commented 4 years ago

Can you check what flash chip you're using? See: https://github.com/esp8266/Arduino/issues/7267

stefbo27 commented 4 years ago

Here the info from flash :



ESP Board
--
ESP Chip ID: | 13825371 (0xD2F55B)
ESP Chip Frequency: | 80 MHz
ESP Board Name: | PLATFORMIO_ESP12E
Storage
Flash Chip ID: | Vendor: 0xE0 Device: 0x4016
Flash Chip Real Size: | 4096 kB
 ```
I will test the versions from zip in the next minutes....
stefbo27 commented 4 years ago

Ok I tested the ESP_Easy_mega_20200516_custom_beta_ESP8266_4M1M Version. It is a little better but still not fine: The reboot loop after waking up breaks after a few reboots, but is still there. In some rarae cases waking up and re-connection works fine.

ESP_Easy_mega_20200516_custom_beta_ESP8266_4M1M and ESP_Easy_mega_20200516_custom_ESP8266_4M1M give unfortunately same result :-(

My testing config: wake 5s sleep 30s

stefbo27 commented 4 years ago

I rolled back the version to mega-20200305 this is much more stable, However from time to time I also have seen the re-boots during waking up. But maybe one out of 20....

TD-er commented 4 years ago

OK, so it is not really a newly introduced bug, but more like the frequency at which it occurs has increased?

Knowing this, I published the last build I made as the 20200515 nightly build.: https://github.com/letscontrolit/ESPEasy/releases/tag/mega-20200515

I will link this topic as a semi-known issue.

stefbo27 commented 4 years ago

Yes, looks like it. However, I set up a competely new device ~1 month ago, and that works fine (sleeping for ~900s) and giving reliably data after wakeup. The new "old" (compiled today) does wake up (i see it in the serial log) but does not send data I also see it goes to AP+STA mode after the reboot(due to error)... Maybe I should try a precompiled older version instead of compiling it myself...

INIT : Booting version: tt01 (ESP82xx Core 2_6_3, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
71 : Info  : INIT : Free RAM:30768
72 : Info  : INIT : Warm boot #39 Last Task: Background Task Last systime: 0 - Restart Reason: Exception
74 : Info  : FS   : Mounting...
100 : Info  : FS   : Mount successful, used 76053 bytes of 957314
121 : Info  : CRC  : No program memory checksum found. Check output of crc2.py
155 : Info  : CRC  : SecuritySettings CRC   ...OK
242 : Info  : INIT : Free RAM:27536
245 : Info  : INIT : I2C
246 : Info  : INIT : SPI not enabled
271 : Info  : ULTRASONIC : TaskNr: 2 TrigPin: 12 IRQ_Pin: 13 max dist [cm]: 90 max echo: 5187 Filter: none nr_tasks: 1
373 : Info  : ULTRASONIC : micros() test: 100 msec, 100042 usec,
650 : Info  : INFO : Plugins: 81 [Normal] [Testing] [Development] (ESP82xx Core 2_6_3, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
653 : Info  : EVENT: System#NoSleep=4
678 : Info  : EVENT: System#Wake

5915 : Info  : EVENT: filling#Distance=90.00
10750 : Info  : ULTRASONIC : TaskNr: 2 Distance: 0.00 cm  Error: Echo pulse error, Echopin not low on trigger
10997 : Info  : EVENT: filling#Distance=90.00
12343 : Info  : WD   : Uptime 1 ConnectFailures 0 FreeMem 18800 WiFiStatus 6
12373 : Info  : SLEEP: Entering deep sleep in 30 seconds.
12375 : Info  : EVENT: System#NoSleep=30
20268 : Info  : WIFI : Set WiFi to AP+STA
21259 : Info  : WIFI : AP Mode ssid will be esp12-01test2 with address 192.168.4.1
42400 : Info  : EVENT: WiFi#APmodeEnabled
42411 : Info  : EVENT: System#Sleep
42417 : Info  : ACT  : gpio,15,0
42418 : Info  : Command: gpio
42420 : Info  : SW   : GPIO 15 Set to 0
42425 : Info  : SLEEP: Powering down to deepsleep...

sensors are not connected during testing.

nasluby commented 4 years ago

Hi I'm starting the adventure with IoT. I have several modules for controlling the furnace and lighting. All based on SUPLA. I want to experiment and learn z ESPeasy. I am sending various projects from this department. Everything calls for a WiFi password. Can you give me that password. Or where can I find him. I will be grateful for help.

Regards

TD-er commented 4 years ago

@nasluby These questions are better asked on the forum As a quick hint for the initial AP password, to start the setup, you may try configesp. If you still have questions (not bugs) please use the forum.

nasluby commented 4 years ago

@TD-er OK, thank you

stefbo27 commented 4 years ago

I investigated my situation further: I used several old pre-build images working me back in history.(now I'm at 20191208). I monitored the behaviour of the device after deepsleep: From time to time I see a reboot during connection to WIFI. The early 2020 versions seem more stable than the recent ones. However I see a strange behaviour there as well: The webserver does not start from time to time. I appended serial logfile (for mega-20191208: in #2 and #3 the webserver does not start (also no sensor values are sent to the database, syslog server does not recieve any info)

4 seems normal (NTP is called, MQTT initialized, syslog works,

5 connects to alternative WIFI after 2 unseccessful tries.

6 and #7 do not start webserver(they try to connect to alternative WIFI (seems the device remembers last setting)).

As it is a old version maybe this is already adressed in the more recent versions.

What's also really strange: I updated another device with the latest version (causing the reboots as described above) but now after going back to older version I observe that during several wakeup periods no data are reported to database. Before updating the device worked reliably. Any Idea?

logfile.txt

TD-er commented 4 years ago

I do have the feeling the WiFi radio may not always be turned on in the same way as on a cold boot. Maybe some registers remain filled with the same value as when powered off.

If so, then it may be quite hard to draw conclusions from just a few sleep/boot loops when changing firmware versions. For a proper comparison you may also need to do a full cold boot after firmware flash and let it cycle for at least 10x (preferably more) to get some idea of stability when booting from deep sleep.

stefbo27 commented 4 years ago

I continued testing... Seems that reconnectin after deepsleep is somehow problematic. So I added the following rule:

on System#Wake do
clearRTCram
endon

This gives stable restarts. Would it be possible to disable the saving of WIFI registers?

TD-er commented 4 years ago

Sure. Just curious, does your access point use a fixed channel, or is it possible its channel has changed?

Another difference your change makes is that it will perform a full scan. This adds roughly 2 seconds to the boot time, which may also make a difference here.

stefbo27 commented 4 years ago

My access point does not use fixed channel, so it is possible that it changed channel. But I do not expect that it changed it every 60s... Watching the syslog (serial) I did not observe a long delay during boot. It seemed quite normal and the connection to WIFI went fine during first try- before I observed sometimes several retries... Unfortunately I can not test right now, as my outdoor-test did not work as expected- water entered the housing and I am currently drying and hoping everything is still fine...

stefbo27 commented 4 years ago

OK testing did continue. Obviously the ESP was under water for about 6hrs and is still working! (the led was alight when I rescued it.., Only my SR04 seems to be broken...) Last time when I tested I had 2 different set-ups. One setup just a bare ESP directly connected to PC and monitor via serial port. This setting worked fine (also without clearing RTC) without reboots after deepsleep. Then I changed to second setting (stand-alone device with SR04 sensor connected). There I observed the reboots after deep-sleep. (I monitored via SYSLOG server) Reboots could be detected due to the 30s delay until entering deep-sleep again. Now I changed second setup to read out serial directly (in stand-alone setting): My observation: as soon as I disable SYSLOG sever all works fine! I can reproduce this in first setup and with another ESP as well. So my current solution: disable SYSLOG server & leave RTC settings as they are...

TD-er commented 4 years ago

OK, so the flushing of syslog, or maybe more accurately: trying to write before we have a network connection, is causing a crash. And not when performing a cold boot, but only when doing a deep sleep.

Just a note to myself: Maybe the reported "connected" state is incorrect when doing a reconnect after deep sleep. See also this updated documentation in the Arduino repo: https://github.com/esp8266/Arduino/commit/27ef03fc057c91f66c32316eec1c5a79838a3979 Maybe related, although we should not be affected since we're not using the same deep sleep mode as mentioned there.

stefbo27 commented 4 years ago

The issue with syslog is definitely not new. I have one ESP measuring temperature in my cellar. It always had problems to send data on regular base. I thought it was due to bad WIFI. But since I disabled syslog-server it records fine after each deepsleep interval. (firmware is from nov 2018)

2020-06-12 00_48_49-temp - Grafana

TD-er commented 4 years ago

OK, will have a look at it, as I'm currently working in the network-layer part of the code. (for another feature I'm working on)

JohanE67 commented 4 years ago

Hi, I am the starter of this forum thread: https://www.letscontrolit.com/forum/viewtopic.php?f=6&t=7555, seeing the same/similar issues in my Wemos D1 Mini's. I started examining further this morning, having flashed mega-20200608 on one of the devices. Initially I was still seeing the issues I reported on the forum. To summarize:

Searching for similar issues, I found this thread and the Syslog connection. I have the D1's log to the syslog on my home server. Switching the syslog off totally removes the issues on the D1 I was testing on. To me, that confirms the diagnose set here. I will remove syslogging on the other D1's to confirm.

I can't help in troubleshooting the code I'm afraid, but I'm happy to help testing where ever I can.

Johan

TD-er commented 4 years ago

I just merged a commit that may reduce the needed amount of stack memory for sending out syslog log entries. Hopefully that also fixes these issues.

Please let me know if it does fix these issues.

JohanE67 commented 4 years ago

I just merged a commit that may reduce the needed amount of stack memory for sending out syslog log entries. Hopefully that also fixes these issues.

Please let me know if it does fix these issues.

I'm unable to build from source. If you can provide a binary, I'm happy to test. Johan

stefbo27 commented 4 years ago

Dear @TD-er, I compiled and uploaded the image this afternoon (~13:00) and activated SYSLOG again. Seems that the new image does unfortunately not solve the Syslog issue, as data from my device now come irregularly again (see picture below; same behaviour as some weeks ago before I deactivated SYSLOG). grafik

TD-er commented 4 years ago

I just merged a commit that may reduce the needed amount of stack memory for sending out syslog log entries. Hopefully that also fixes these issues. Please let me know if it does fix these issues.

I'm unable to build from source. If you can provide a binary, I'm happy to test. Johan

I made a test build of the current mega branch:

As @stefbo27 showed, the reduced stack usage of the add to syslog does not fix this particular issue.

JohanE67 commented 4 years ago

Thanks. Tested anyway and confirm it does not solve the problem. Part of the log, FWIW:

`INIT : Booting version: (ESP82xx Core d85ff6ef, NONOS SDK 2.2.2-dev(a58da79), LWIP: 2.1.2 PUYA support) 73 : Info : INIT : Free RAM:31056 73 : Info : INIT : Warm boot #12 Last Task: Background Task Last systime: 0 - Restart Reason: Exception 74 : Info : FS : Mounting... 99 : Info : FS : Mount successful, used 76555 bytes of 957314 118 : Info : CRC : No program memory checksum found. Check output of crc2.py 125 : Info : CRC : SecuritySettings CRC ...OK 237 : Info : INIT : Free RAM:28480 240 : Info : INIT : I2C 241 : Info : INIT : SPI not enabled 540 : Info : INFO : Plugins: 83 [Normal] [Testing] (ESP82xx Core d85ff6ef, NONOS SDK 2.2.2-dev(a58da79), LWIP: 2.1.2 PUYA support) 543 : Info : EVENT: System#NoSleep=20 577 : Info : EVENT: System#Wake 583 : Info : ACT : let,1,0 585 : Info : Command: let fpm close 3 716 : Info : WIFI : Set WiFi to STAmode : sta(ec:fa:bc:21:5d:ea) add if0

820 : Info : WIFI : Connecting RommeNet_1 attempt #0 827 : Info : Webserver: start 842 : Info : EVENT: System#Boot scandone state: 0 -> 2 (b0) 1830 : Info : WIFI : Connecting RommeNet_1 attempt #1state: 2 -> 3 (0) state: 3 -> 5 (10) add 0 aid 2 cnt

connected with RommeNet_1, channel 5 dhcp client start... ip:192.168.1.25,mask:255.255.255.0,gw:192.168.1.1 scandone 2056 : Info : WIFI : Connected! AP: RommeNet_1 (E0:91:F5:CC:EF:D2) Ch: 5 Duration: 27 ms 2057 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini-2) GW: 192.168.1.1 SN: 255.255.255.0 duration: 23 ms 2074 : Info : WIFI : WiFiConnected() out of sync 2074 : Info : WIFI : WiFiConnected() out of sync 2074 : Info : WIFI : WiFiConnected() out of sync 2075 : Info : WIFI : WiFiConnected() out of sync 2075 : Info : WIFI : WiFiConFatal exception 28(LoadProhibitedCause): epc1=0x4028f994, epc2=0x00000000, epc3=0x00000000, excvaddr=0x0000000b, depc=0x00000000

--------------- CUT HERE FOR EXCEPTION DECODER ---------------

Exception (28): epc1=0x4028f994 epc2=0x00000000 epc3=0x00000000 excvaddr=0x0000000b depc=0x00000000

stack>>>

ctx: sys sp: 3fff1d80 end: 3fffffb0 offset: 0190 3fff1f10: 00000828 0000000a 3fff1f80 4028b6b5`

TD-er commented 4 years ago

Could you test with this test build? https://github.com/letscontrolit/ESPEasy/pull/3148#issuecomment-654445752

JohanE67 commented 4 years ago

Sorry, I was not able to test any sooner. I can confirm that in this version, the "reboot after deepsleep" does not occur anymore, even with syslog enabled. However, there is no syslogging going on after wake from deepsleep. I consistently see syslog entries from cold boot until first deep sleep, but then it stops. So it looks like syslogging is effectively disabled when deepsleep is enabled. I can imagine that solves the issue, but I don't think that it should work that way.

In addition, I sometimes see the following in the (serial) log:

`1711 : Info : Domoticz: Sensortype: 1 idx: 160 values: 3.00 1817 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 1932 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 2047 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 2172 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 2286 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 2401 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 2516 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 2528 : Info : WD : Uptime 0 ConnectFailures 0 FreeMem 22072 WiFiStatus 6 2632 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 2747 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 2861 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 2874 : Info : ADC : Analog value: 3 = 3.000 2876 : Info : Domoticz: Sensortype: 1 idx: 160 values: 3.00 2981 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 3107 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 3221 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 3336 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 3450 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 3565 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 3680 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 3794 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 3910 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 4024 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 4148 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 4263 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 4378 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 4493 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 4607 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 4722 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 4735 : Info : ADC : Analog value: 3 = 3.000 4737 : Info : Domoticz: Sensortype: 1 idx: 160 values: 3.00 4842 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 4958 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 5083 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 5197 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 5311 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 5426 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 5540 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 5655 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 5769 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 5883 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 6008 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 6122 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 6237 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 6350 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 6465 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 6580 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 6694 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 6708 : Info : ADC : Analog value: 3 = 3.000 6709 : Info : Domoticz: Sensortype: 1 idx: 160 values: 3.00 6815 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 6928 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 7053 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 7168 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 7282 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 7397 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 7511 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 7625 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 7740 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 7855 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 7980 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 8093 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 8209 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 8324 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 8438 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 8553 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 8667 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 8680 : Info : ADC : Analog value: 3 = 3.000 8682 : Info : Domoticz: Sensortype: 1 idx: 160 values: 3.00 8787 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 8901 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 9026 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 9141 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 9254 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 9369 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 9484 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 9598 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 9712 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 9826 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 9951 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 10066 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 10180 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 10295 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 10408 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 10523 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 10638 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 10752 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 10765 : Info : ADC : Analog value: 3 = 3.000 10767 : Info : Domoticz: Sensortype: 1 idx: 160 values: 3.00 10873 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 10987 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 11112 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 11227 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 11341 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 11456 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 11569 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 mspm open,type:2 0

11684 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 11799 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 11913 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 12038 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 12152 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 12267 : Info : WIFI : DHCP IP: 192.168.1.25 (D1Mini) GW: 192.168.1.1 SN: 255.255.255.0 duration: 21 ms 12290 : Info : WD : Uptime 1 ConnectFailures 0 FreeMem 20816 WiFiStatus 6 12302 : Info : SLEEP: Powering down to deepsleep... `

This also happens when I use static IP, then "DHCP IP" in the lines is replaced with "Static IP". It does not seem to affect the working. It takes a couple of minutes after cold boot until this happens, but then it occurs repeatedly. I am attaching a longer log file where you can see all this happen.

[Com COM13] (2020-07-11_111456).log

Conclusion: it's looking much better, but not quite there yet.

Johan

TD-er commented 4 years ago

I'm still working on the WiFi stuff.

It appeared we had several issues here at hand.

Crash when sending the log is now fixed, but the issue with the incorrect state of the WiFi is still a work in progress. Sending to syslog depends on the observed state, which is sometimes out of sync. (some nodes experience it more often then others)