Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ESP32&mega-20220809 AdaGFX helper issue #4194

Closed
sobolkz opened this issue Aug 12, 2022 · 72 comments · Fixed by #4199
Closed

ESP32&mega-20220809 AdaGFX helper issue #4194

sobolkz opened this issue Aug 12, 2022 · 72 comments · Fixed by #4199
Labels
Category: Plugin Related to supported sensors Status: Needs Info Needs more info before action can be taken Type: Bug Considered a bug

Comments

@sobolkz
Copy link

sobolkz commented Aug 12, 2022

Hi all!
Just checked latest mega-20220809 with Wemos D32 mini pro - it's look like an error in AdaGFX helper was expected.
Mega-20220809 was uploaded to clean Wemos D32 mini pro, it can work without issues due ILI9341 plugin was enabled.
After it board stopping to boot at ADAGFX helper initialization step:

INIT : Booting version: mega-20220809_57b0c0c (ESP32 SDK v4.4.3)
48 : Info   : INIT : Free RAM:267076
50 : Info   : INIT : Cold Boot - Restart Reason: CPU0: RTC Watch dog reset digital core and rtc module CPU1: for APP CPU, reseted by PRO CPU
51 : Info   : FS   : Mounting...
92 : Info   : FS   : Mount successful, used 151552 bytes of 8318976
175 : Info   : CRC  : SecuritySettings CRC   ...OK
198 : Info   : INIT : I2C
201 : Info   : INIT : SPI Init (without CS)
203 : Info   : ExtRTC: Read external time source: [1660235047](tel:1660235047)
204 : Info   : Time set to [1660235047](tel:1660235047).000
206 : Info   : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 360 min
207 : Info   : Local time: 2022-08-11 22:24:07
209 : Info   : WiFi : Start network scan all channels
311 : Info   : WiFi : STA Started
6927 : Info   : WiFi : Scan finished, found: 10
6931 : Info   : WiFi : Best AP candidate: XXXXXXXXXXXXXXXXXXXX Ch:9 (-58dBm) WPA2/PSK
6933 : Info   : WIFI : Connecting XXXXXXXXXXXXXXXXXXXXX Ch:9 (-58dBm) WPA2/PSK attempt #0
6943 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
6967 : Info   : INIT : Free RAM:219656
7014 : Info   : ILI9341: Init start.
7015 : Info   : ILI9341: Init done, address: 0x3ffd3abc valid, commands: tft/tftcmd
7016 : Info   : AdaGFX_helper:

Web server wasn't yet enabled, therefore only full reset can help to boot board again (with disabled ILI9341). I'll try to check latest build with @tonhuisman commit #3903

@TD-er TD-er added Type: Bug Considered a bug Category: Plugin Related to supported sensors Status: Needs Info Needs more info before action can be taken labels Aug 12, 2022
@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

There is no watchdog reset?

@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

Just looking through your logs and I wonder what the tel: does in the logs:

203 : Info   : ExtRTC: Read external time source: [1660235047](tel:1660235047)
204 : Info   : Time set to [1660235047](tel:1660235047).000

Is this some browser extention trying to create clickable links for phone nrs?

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

There is no watchdog reset?

Due to testing any watchdogs wasn't configured. Internal also wasn't affected - ": Info : AdaGFX_helper:" was last message in log for a long time until board was reloaded.

Just looking through your logs and I wonder what the tel: does in the logs:

203 : Info   : ExtRTC: Read external time source: [1660235047](tel:1660235047)
204 : Info   : Time set to [1660235047](tel:1660235047).000

Is this some browser extention trying to create clickable links for phone nrs?

As I understand it's RTC module native work. I can try to unplug it. Also - this log was copied from serial console, not wrom web log. Which extension can make it inside of serial connection?

@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

The logs should only show something like this:

203 : Info   : ExtRTC: Read external time source: 1660235047

Not the brackets and (tel:....) part.

Given the fact it wasn't rebooting, that means it is stuck somewhere where it is still calling something which resets the watchdog timer.
So perhaps it is waiting for some pin to react or data to be read?
Ton told me he would have a look at it later this evening.

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

So perhaps it is waiting for some pin to react or data to be read? Ton told me he would have a look at it later this evening.

Yep, it's look like waiting or block code. But there is no such reactions inside of ILI9341 plugin, because there is no buttons on it's board. Touch plugin is different part of this boards, it can be used separately and it's disabled now.
Also as you can see - main ILI9341 plugin was successfully initialized before AdaGFX helper.
Therefore it can't be a waiting for pin reaction, as minimum for ILI9341.

@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

If you have log level Debug enabled, then you might see a bit more, depending on where it halts.
In the initialize() function, there is some debug logs.
It is possible it might just dump enough extra into the log buffers so more logs will be flushed to give an idea of where it stops.

@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

I think it may be halted here:

That's the first line where there's actual interaction with the display.

Do you have the backlight pin set?
If so, then it should put a PWM signal onto that pin.

I will also check on my board to see if analog write is still working as it should, as there have been quite a few issues lately with changed implementation of low-level GPIO code in the most recent SDK.

@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

Looked a bit more into the code of Adafruit_SPITFT::sendCommand
It looks like this is a lot of calls to pinWrite etc. and other Arduino calls.
This is probably way too slow since the last SDK update.
So I guess Ton might need to adapt this code to use the new direct calls to GPIO pins, or maybe this library has been updated by Adafruit as it will probably cause more issues for others too.

It seems there is already some code in there wrapped in #if defined(USE_FAST_PINIO) checks.
So maybe it is as simple as defining this in PlatformIO envs.... in a newer version of the library at least as there is this in the code:

// Probably ESP8266 or ESP32. USE_FAST_PINIO is not available here (yet)
// but don't worry about it too much...the digitalWrite() implementation
// on these platforms is reasonably efficient and already RAM-resident,
// only gotcha then is no parallel connection support for now.
typedef uint32_t ADAGFX_PORT_t; ///< PORT values are 32-bit

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

Do you have the backlight pin set? If so, then it should put a PWM signal onto that pin.

Nope, Backlight control isn't used by plugin (therefore PIN not configured in plugin). It's used through rules, without PWM, only On\Off functionality after booting and before sleeping.

@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

You could set GPIO-2 to be as backlight pin, as that one is often connected to a LED. This may help to see what's wrong?
On the other hand, GPIO-2 is often "inverted" so if the PWM is set to "almost max" then you might not see anything.

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

You could set GPIO-2 to be as backlight pin, as that one is often connected to a LED. This may help to see what's wrong? On the other hand, GPIO-2 is often "inverted" so if the PWM is set to "almost max" then you might not see anything.

As I wrote before (at the forum) - it's Wemos TFT 2.4 shield. It's backlight control was linked to TFT connector at GPIO32 for Wemos D32 Pro and through pin header. Therefore I'm using rules like

on System#Boot do
GPIO32,1
endon

and

on System#Sleep do
GPIO32,0
GPIO2,0
endon

GPIO2 also used in my project, but for power control of environment through MOSFET. This GPIO controlled by Hardware at boot and by rules at sleep.
As I understand it can't take impact to display, because it's controller are powered by 3.3V line separately.

@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

It was merely meant as a suggestion for diagnostic reasons as we now have no clue where it halts.

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

It was merely meant as a suggestion for diagnostic reasons as we now have no clue where it halts.

I'll check situation with increased logging level as you proposed.

@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

Which pins do you use?
Can you also show some info about CPU revision and flash shown on the sysinfo page?

Do you have any pins set on the Hardware tab to anything other than "default" (e.g. pull-up resistors enabled)

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

Which pins do you use? Can you also show some info about CPU revision and flash shown on the sysinfo page?

Do you have any pins set on the Hardware tab to anything other than "default" (e.g. pull-up resistors enabled)

Hmmm it's very long story. because almost all free PINs was used. There is 2 HW Serials (one for PMSx003, another one for Senseair S8), 2 active I2C - one is BME280, another one is RTC module. There is third one I2C module planned- SCD41 (instead of S8) but it isn't used now due to P135 wasn't released yet. SPI for TFT screen and GPIO2 for power latching.
There is no external pull up or pull down resistors, only that used inside of modules.
All work's good with @tonhuisman custom release, which discussed in #4060 at 21 May.
Now some previous builds also tested - @tonhuisman build for #4174 and same issue expected - board stopping boot at AdaGFX helper step.
There is Debug dev serial log.
This is first boot and activation of TFT plugin afrer it:

rst:0xc (SW_CPU_RESET),boot:0x17 (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:DOUT, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12616
load:0x40080400,len:2916
entry 0x400805c4
▒U46 : Info :

INIT : Booting version: mega-20220809_57b0c0c (ESP32 SDK v4.4.3)
47 : Info : INIT : Free RAM:267076
49 : Info : INIT : Soft Reboot #2 Last Action before Reboot: Intended Reboot: CommandReboot Last systime: 1660313699 - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
50 : Info : FS : Mounting...
90 : Info : FS : Mount successful, used 151552 bytes of 8318976
173 : Info : CRC : SecuritySettings CRC ...OK
195 : Info : INIT : I2C
198 : Info : INIT : SPI Init (without CS)
210 : Info : Time set to 1660313699.000
211 : Info : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 360 min
213 : Info : Local time: 2022-08-12 20:14:59
226 : Info : WiFi : Start network scan all channels
330 : Info : WiFi : STA Started
7346 : Info : WiFi : Scan finished, found: 10
7349 : Info : WiFi : Best AP candidate: access_point8 88:DC:96:26:7F:0A Ch:9 (-58dBm) WPA2/PSK
7351 : Info : WIFI : Connecting access_point8 88:DC:96:26:7F:0A Ch:9 (-58dBm) WPA2/PSK attempt #0
7358 : Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
7382 : Info : INIT : Free RAM:219908
7963 : Info : INFO : Plugins: 124 [Normal] [MAX ESP32] (ESP32 SDK v4.4.3)
7966 : Info : EVENT: System#Wake
8061 : Info : EVENT: System#BootMode=1,1,1,0
8077 : Info : Webserver: start
8091 : Info : OTA : Arduino OTA enabled on port 3232
8103 : Info : EVENT: System#Boot
RuleDebug Processing:rules1.txt
flags CMI parse output:
8128 : Info : ACT : timerSet,1,5
8133 : Info : ACT : GPIO,32,1
8138 : Info : GPIO : port#32: set to 1
8243 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 10 ms
8259 : Error : WiFi : Scan not allowed, unprocessed WiFi events: disconn
8360 : Info : WIFI : Set WiFi to OFF
8585 : Info : WIFI : Arduino wifi status: WL_NO_SHIELD 255 ESPeasy internal wifi status: DISCONNECTED
8587 : Info : WiFi : Best AP candidate: access_point8 88:DC:96:26:7F:0A Ch:9 (-58dBm) WPA2/PSK
8589 : Info : WIFI : Connecting access_point8 88:DC:96:26:7F:0A Ch:9 (-58dBm) WPA2/PSK attempt #1
8690 : Info : WIFI : Set WiFi to STA
8701 : Info : WiFi : STA Started
9278 : Info : EVENT: Time#Initialized
9304 : Info : WIFI : Connected! AP: access_point8 (88:DC:96:26:7F:0A) Ch: 9 Duration: 708 ms
9309 : Info : EVENT: WiFi#Disconnected
9324 : Info : WIFI : DHCP IP: 192.168.3.3 (MAX-ESP32) GW: 192.168.3.1 SN: 255.255.255.0 duration: 22 ms
9336 : Info : WIFI : Starting mDNS...
9338 : Info : WIFI : mDNS started, with name: MAX-ESP32.local
9365 : Info : EVENT: Clock#Time=Fri,20:15
9376 : Debug : EVENT: Clock#Time=Fri,20:15 Processing time:11 milliSeconds
9381 : Info : EVENT: WiFi#ChangedAccesspoint
9392 : Debug : EVENT: WiFi#ChangedAccesspoint Processing time:11 milliSeconds
9395 : Info : EVENT: WiFi#ChangedWiFichannel
9406 : Debug : EVENT: WiFi#ChangedWiFichannel Processing time:11 milliSeconds
9410 : Info : UDP : Start listening on port 8266
9411 : Info : firstLoopConnectionsEstablished
9411 : Debug More : UDP : Send Sysinfo message
9416 : Info : EVENT: WiFi#Connected
9428 : Debug : EVENT: WiFi#Connected Processing time:11 milliSeconds
9475 : Info : WD : Uptime 0 ConnectFailures 0 FreeMem 192904 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
9477 : Debug More : UDP : Send Sysinfo message
9770 : Debug : HTML : Request file /index.htm.gz
9776 : Debug : HTML : Request file /index.htm
9802 : Debug dev : sendcontent free: 187956 chunk size:1360
9813 : Debug dev : sendcontent free: 186240 chunk size:1360
9824 : Debug dev : sendcontent free: 187956 chunk size:1360
9836 : Debug dev : sendcontent free: 186272 chunk size:1360
9854 : Debug dev : sendcontent free: 187824 chunk size:1360
9875 : Debug dev : sendcontent free: 189488 chunk size:1360
9884 : Debug dev : sendcontent free: 182196 chunk size:430
9896 : Debug dev : sendcontent free: 186116 chunk size:0
9921 : Debug More : NTP : NTP host 192.168.3.1 (192.168.3.1) queried
9935 : Info : NTP : NTP replied: delay 11 mSec Accuracy increased by 0.820 seconds
9937 : Info : Time set to 1660313709.820 Time adjusted by 1092.71 msec. Wander: 0.000 msec/second Source: NTP
9940 : Info : Local time: 2022-08-12 20:15:09
9945 : Info : EVENT: Time#Set
9955 : Debug : EVENT: Time#Set Processing time:10 milliSeconds
10364 : Debug : LoopStats: shortestLoop: 23 longestLoop: 1150028 avgLoopDuration: 101.48 loopCounterMax: 1304347 loopCounterLast: 21604
10366 : Debug : Scheduler stats: (called/tasks/max_length/idle%) 21603/69/7/7.98
13133 : Info : EVENT: Rules#Timer=1,1
13144 : Debug : EVENT: Rules#Timer=1,1 Processing time:11 milliSeconds
39475 : Info : WD : Uptime 1 ConnectFailures 0 FreeMem 191744 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
39477 : Debug More : UDP : Send Sysinfo message
40364 : Debug : LoopStats: shortestLoop: 23 longestLoop: 1150028 avgLoopDuration: 34.99 loopCounterMax: 1304347 loopCounterLast: 833067
40366 : Debug : Scheduler stats: (called/tasks/max_length/idle%) 833067/2133/7/91.90
47308 : Debug dev : sendcontent free: 187708 chunk size:1360
47320 : Debug dev : sendcontent free: 185988 chunk size:1360
47331 : Debug dev : sendcontent free: 187712 chunk size:1360
47344 : Debug dev : sendcontent free: 184404 chunk size:1360
47357 : Debug dev : sendcontent free: 187628 chunk size:1360
47373 : Debug dev : sendcontent free: 189200 chunk size:265
47397 : Debug dev : sendcontent free: 189128 chunk size:1360
47409 : Debug dev : sendcontent free: 187532 chunk size:1360
47422 : Debug dev : DEBUG: String size:9785
47424 : Debug dev : sendcontent free: 189200 chunk size:1344
47434 : Debug dev : sendcontent free: 184300 chunk size:0
48513 : Debug dev : sendcontent free: 187388 chunk size:29
48525 : Debug dev : sendcontent free: 186044 chunk size:0
48677 : Debug dev : sendcontent free: 187080 chunk size:1360
48689 : Debug dev : sendcontent free: 185364 chunk size:1360
48699 : Debug dev : sendcontent free: 187080 chunk size:1360
48710 : Debug dev : sendcontent free: 185364 chunk size:1360
48724 : Debug dev : sendcontent free: 187008 chunk size:1360
48737 : Info : Webserver 2 Arguments: 0: 'index' length: 1 1: 'page' length: 1
48744 : Debug dev : sendcontent free: 188592 chunk size:1360
48760 : Debug dev : sendcontent free: 186988 chunk size:1360
48777 : Debug dev : sendcontent free: 185272 chunk size:1360
48793 : Debug dev : sendcontent free: 186996 chunk size:1360
48810 : Debug dev : sendcontent free: 188576 chunk size:1360
48826 : Debug dev : sendcontent free: 187088 chunk size:1360
48843 : Debug dev : DEBUG: String size:14960
48846 : Debug dev : sendcontent free: 188588 chunk size:892
48855 : Debug dev : sendcontent free: 183480 chunk size:0
54462 : Debug dev : sendcontent free: 186448 chunk size:1360
54474 : Debug dev : sendcontent free: 184724 chunk size:1360
54485 : Debug dev : sendcontent free: 186452 chunk size:1360
54497 : Debug dev : sendcontent free: 184712 chunk size:1360
54509 : Debug dev : sendcontent free: 180900 chunk size:1360
54523 : Info : Webserver 5 Arguments: 0: 'index' length: 1 1: 'page' length: 1 2: 'TDNUM' length: 2 3: 'edit' length: 1 4: 'page' length: 1
54527 : Debug dev : Write settings: CustomTaskSettings index: 0
55718 : Debug dev : Write settings: TaskSettings index: 0
55721 : Info : SaveToFile: free stack: 7096
56883 : Info : FILE : Saved config.dat offset: 32768 size: 536
56885 : Info : SaveToFile: free stack after: 7096
56887 : Info : SaveToFile: free stack: 7176
58445 : Info : FILE : Saved config.dat offset: 0 size: 3004
58447 : Info : SaveToFile: free stack after: 7176
58448 : Debug dev : Write settings: ExtendedControllerCredentials index: 0
58470 : Info : SaveToFile: free stack: 6728
58552 : Info : FILE : Saved security.dat offset: 1024 size: 6
58553 : Info : SaveToFile: free stack after: 6728
58555 : Debug dev : Read settings: TaskSettings index: 0
58617 : Debug dev : Read settings: TaskSettings index: 0
58652 : Debug dev : sendcontent free: 189328 chunk size:1360
58672 : Debug dev : sendcontent free: 187744 chunk size:1360
58693 : Debug dev : sendcontent free: 189328 chunk size:1360
58713 : Debug dev : sendcontent free: 187836 chunk size:1360
58733 : Debug dev : sendcontent free: 189528 chunk size:1360
58748 : Debug dev : sendcontent free: 187908 chunk size:1360
58763 : Debug dev : sendcontent free: 189516 chunk size:1360
58777 : Debug dev : Read settings: CustomTaskSettings index: 0
58808 : Debug dev : sendcontent free: 186280 chunk size:1360
58826 : Debug dev : sendcontent free: 189580 chunk size:1360
58838 : Debug dev : sendcontent free: 189516 chunk size:1360
58861 : Debug dev : DEBUG: String size:20400
58867 : Debug dev : sendcontent free: 189436 chunk size:1360
58879 : Debug dev : sendcontent free: 187852 chunk size:399
58889 : Debug dev : sendcontent free: 186060 chunk size:0
58903 : Info : EVENT: TaskExit#=1,0
58982 : Debug : Rules : Read 23 lines from rules1.txt
58984 : Debug : Cache rules event: rules1.txt pos: 0 on System#Boot do
58985 : Debug : Cache rules event: rules1.txt pos: 4 on XPT2046#OnOff do
58985 : Debug : Cache rules event: rules1.txt pos: 7 on BME280#Press do
58986 : Debug : Cache rules event: rules1.txt pos: 10 on PMS7003#pm2.5 do
58986 : Debug : Cache rules event: rules1.txt pos: 13 on PMS7003#pm10 do
58987 : Debug : Cache rules event: rules1.txt pos: 16 on VBAT#Batt do
58987 : Debug : Cache rules event: rules1.txt pos: 19 on System#Sleep do
59028 : Debug : EVENT: TaskExit#=1,0 Processing time:124 milliSeconds
61037 : Info : EVENT: Clock#Time=Fri,20:16
61046 : Debug : EVENT: Clock#Time=Fri,20:16 Processing time:9 milliSeconds
69475 : Info : WD : Uptime 1 ConnectFailures 0 FreeMem 190492 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
69477 : Debug More : UDP : Send Sysinfo message
70364 : Debug : LoopStats: shortestLoop: 22 longestLoop: 4453596 avgLoopDuration: 40.89 loopCounterMax: 1363636 loopCounterLast: 716698
70366 : Debug : Scheduler stats: (called/tasks/max_length/idle%) 716697/1786/7/93.03
79220 : Debug dev : sendcontent free: 184668 chunk size:1360
79231 : Debug dev : sendcontent free: 182948 chunk size:1360
79242 : Debug dev : sendcontent free: 184668 chunk size:1360
79253 : Debug dev : sendcontent free: 182944 chunk size:1360
79272 : Debug dev : sendcontent free: 184536 chunk size:1360
79287 : Info : Webserver 50 Arguments (First 20): 0: 'index' length: 1 1: 'page' length: 1 2: 'TDNUM' length: 2 3: 'TDN' length: 7 4: 'TDE' length: 2 5: 'taskdevicepin1' length: 2 6: 'taskdevicepin2' length: 2 7: 'taskdevicepin3' length: 2 8: 'p095_backlight' length: 2 9: 'p095_backpercentage' length: 3 10: 'p095_button' length: 2 11: 'p095_timer' length: 1 12: 'p095_rotate' length: 1 13: 'p095_mode' length: 1 14: 'p095_fontscale' length: 1 15: 'p095_commandtrigger' length: 1 16: 'p095_NoDisplay' length: 2 17: 'p095_compat' length: 2 18: 'p095_backfill' length: 2 19: 'p095_foregroundcolor' length: 5
79294 : Debug dev : Write settings: TaskSettings index: 0
79317 : Info : SaveToFile: free stack: 6792
80489 : Info : FILE : Saved config.dat offset: 32768 size: 536
80490 : Info : SaveToFile: free stack after: 6792
80513 : Debug dev : Read settings: TaskSettings index: 0
80568 : Debug dev : Write settings: CustomTaskSettings index: 0
80571 : Info : SaveToFile: free stack: 5912
81735 : Info : FILE : Saved config.dat offset: 33792 size: 24
81737 : Info : SaveToFile: free stack after: 5912
81738 : Debug dev : Write settings: TaskSettings index: 0
81758 : Info : SaveToFile: free stack: 7096
83144 : Info : FILE : Saved config.dat offset: 32768 size: 536
83146 : Info : SaveToFile: free stack after: 7096
83147 : Info : SaveToFile: free stack: 7176
84694 : Info : FILE : Saved config.dat offset: 0 size: 3004
84696 : Info : SaveToFile: free stack after: 7176
84697 : Debug dev : Write settings: ExtendedControllerCredentials index: 0
84706 : Info : SaveToFile: free stack: 6728
84772 : Info : FILE : Saved security.dat offset: 1024 size: 6
84774 : Info : SaveToFile: free stack after: 6728
84776 : Debug dev : Read settings: TaskSettings index: 0
84806 : Info : ILI9341: Init start.

There is part of display initialization:

84808 : Info : ILI9341: Init done, address: 0x3ffd3b9c valid, commands: tft/tftcmd
84808 : Info : AdaGFX_helper: TFT Init.
84808 : Debug : AdaGFX: Init, x: 240, y
At this point board going offline, web server stop's work.
There is boot after it:

rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371
ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x17 (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:DOUT, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12616
load:0x40080400,len:2916
entry 0x400805c4
▒U47 : Info :

INIT : Booting version: mega-20220809_57b0c0c (ESP32 SDK v4.4.3)
48 : Info : INIT : Free RAM:267076
50 : Info : INIT : Cold Boot - Restart Reason: CPU0: RTC Watch dog reset digital core and rtc module CPU1: for APP CPU, reseted by PRO CPU
51 : Info : FS : Mounting...
77 : Info : FS : Mount successful, used 151552 bytes of 8318976
139 : Info : CRC : SecuritySettings CRC ...OK
156 : Info : INIT : I2C
158 : Info : INIT : SPI Init (without CS)
160 : Info : WiFi : Start network scan all channels
271 : Info : WiFi : STA Started
7488 : Info : WiFi : Scan finished, found: 11
7491 : Info : WiFi : Best AP candidate: access_point8 88:DC:96:26:7F:0A Ch:9 (-58dBm) WPA2/PSK
7493 : Info : WIFI : Connecting access_point8 88:DC:96:26:7F:0A Ch:9 (-58dBm) WPA2/PSK attempt #0
7503 : Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
7527 : Info : INIT : Free RAM:220116
7569 : Info : ILI9341: Init start.
7570 : Info : ILI9341: Init done, address: 0x3ffd385c valid, commands: tft/tftcmd
7571 : Info : AdaGFX_helper

As you can see - there is no any additional information while Debug dev was activated.
Also - RTC module wasn't connected, only NTP server was configured.

@tonhuisman
Copy link
Contributor

tonhuisman commented Aug 12, 2022

Which pins do you use? Can you also show some info about CPU revision and flash shown on the sysinfo page?

Can you also provide this info?
Pins are mostly on Hardware page (show entire page please, also the separate GPIO configuration settings), and for ILI9341 on its Device Configuration page, and CPU/flash stuff on the Tools/Info page (or More info button on Main page), sections 'ESP Board' and 'Storage'.

Edit: Bonus question: How long are the wires to the display, and are they all of the same length (less than 2 cm. diff)?

@tonhuisman
Copy link
Contributor

tonhuisman commented Aug 12, 2022

I've been testing this for a while (though I haven't got a display connected to this device, tried that and works just as fine with a 4MB ESP32), I got this log (at INFO level):
NB: No code changes to ILI9341 or AdafruitGFX_helper

INIT : Booting version: [**hidden to protect the innocent**] (ESP32 SDK v4.4.3)
60 : Info   : INIT : Free RAM:266208
62 : Info   : INIT : Soft Reboot #7 Last Action before Reboot: Background Task Last systime: 1660316244 - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
63 : Info   : FS   : Mounting...
86 : Info   : FS   : Mount successful, used 151552 bytes of 8318976
129 : Info   : CRC  : SecuritySettings CRC   ...OK
141 : Info   : INIT : I2C
143 : Info   : INIT : SPI Init (without CS)
155 : Info   : Time set to 1660316244.000
156 : Info   : Current Time Zone:  DST time start: 2022-03-27 02:00:00 offset: 120 min STD time start: 2022-10-30 03:00:00 offset: 60 min
159 : Info   : Local time: 2022-08-12 16:57:24
171 : Info   : WiFi : Start network scan all channels
288 : Info   : WiFi : STA Started
6904 : Info   : WiFi : Scan finished, found: 45
6910 : Info   : WiFi : Best AP candidate: [**ssid**] 6E:FF:7B:68:06:44 Ch:8 (-44dBm) WPA2/PSK
6912 : Info   : WIFI : Connecting [**ssid**] 6E:FF:7B:68:06:44 Ch:8 (-44dBm) WPA2/PSK attempt #0
6919 : Info   : IP   : Static IP : 192.168.1.103 GW: 192.168.1.1 SN: 255.255.255.0 DNS: 192.168.1.1
6929 : Info   : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
6952 : Info   : INIT : Free RAM:214988
7004 : Info   : ILI9341: Init start.
7708 : Info   : ILI9341: Init done, address: 0x3ffd4d78 valid, commands: tft/tftcmd
7709 : Info   : AdaGFX_helper: TFT Init.
7770 : Info   : P095 Splash start
8327 : Info   : INFO : Plugins: 126 [Normal] [MAX ESP32] (ESP32 SDK v4.4.3)
8329 : Info   : EVENT: System#Wake
8363 : Info   : EVENT: System#BootMode=1,1,1,0
8368 : Info   : Webserver: start
8372 : Info   : OTA  : Arduino OTA enabled on port 3232
8393 : Info   : EVENT: System#Boot
8497 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 18 ms
8517 : Error  : WiFi : Scan not allowed, unprocessed WiFi events:  disconn
8618 : Info   : WIFI : Set WiFi to OFF
8858 : Info   : WIFI : Arduino wifi status: WL_NO_SHIELD 255 ESPeasy internal wifi status: DISCONNECTED
8861 : Info   : WiFi : Best AP candidate: [**ssid**] 6E:FF:7B:68:06:44 Ch:8 (-44dBm) WPA2/PSK
8863 : Info   : WIFI : Connecting [**ssid**] 6E:FF:7B:68:06:44 Ch:8 (-44dBm) WPA2/PSK attempt #1
8964 : Info   : WIFI : Set WiFi to STA
8986 : Info   : WiFi : STA Started
9094 : Info   : IP   : Static IP : 192.168.1.103 GW: 192.168.1.1 SN: 255.255.255.0 DNS: 192.168.1.1
9115 : Info   : EVENT: Time#Initialized
9621 : Info   : EVENT: TaskInit#ILI9341=8,1
9625 : Info   : WIFI : Connected! AP: [**ssid**] (6E:FF:7B:68:06:44) Ch: 8 Duration: 754 ms
9627 : Info   : WIFI : Static IP: 192.168.1.103 (ESP-32-103) GW: 192.168.1.1 SN: 255.255.255.0   duration: 8 ms
9639 : Info   : WIFI : Starting mDNS...
9641 : Info   : WIFI : mDNS started, with name: ESP-32-103.local
9643 : Info   : EVENT: WiFi#Disconnected
9660 : Info   : EVENT: Clock#Time=Fri,16:57
9666 : Info   : EVENT: WiFi#ChangedAccesspoint
9668 : Info   : EVENT: WiFi#ChangedWiFichannel
9669 : Info   : EVENT: WiFi#Connected
9720 : Info   : UDP : Start listening on port 65500
9721 : Info   : firstLoopConnectionsEstablished
9730 : Info   : WD   : Uptime 0 ConnectFailures 0 FreeMem 187868 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
9793 : Error  : MQTT : Intentional reconnect
13801 : Error  : MQTT : Broker C002 connection failed (1/0)
13867 : Info   : NTP  : NTP replied: delay 21 mSec Accuracy increased by 0.782 seconds
13870 : Info   : Time set to 1660316280.782 Time adjusted by 23067.76 msec. Wander: 0.000 msec/second Source: NTP
13872 : Info   : Local time: 2022-08-12 16:58:00
13875 : Info   : EVENT: Clock#Time=Fri,16:58
13881 : Info   : EVENT: Time#Set
16706 : Info   : P095 Splash finished.
37873 : Info   :  Webserver 2 Arguments: 0: 'index' length: 1 1: 'page' length: 1
39729 : Info   : WD   : Uptime 1 ConnectFailures 1 FreeMem 183148 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init

Edit: And the same result with P095 Splash turned off.
Edit 2: On the ESP with the display connected, also the XPT2046 touch screen is connected in parallel on the SPI pins.

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

Ok, there is information for @tonhuisman release (as fully working one):
image
image
image
image
image
image
image
image
image
image
image

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

Edit: Bonus question: How long are the wires to the display, and are they all of the same length (less than 2 cm. diff)?

It's native Wemos TFT cable used.
Whole device with you release (as you can see it's working :-)
here:
image

It's working with you release but isn't working with newest builds.
Also - you test release for SCD4X module was checked with another board, with Wemos D1 pro board. This one for Wemos D32 pro can't be used with same display issue.

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

Bingo!
Some progress with investigation - If all devices was added without TFT screen (and, also without rules ) board crashes was reproduced at PMS7003 initialization:

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:DOUT, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12616
load:0x40080400,len:2916
entry 0x400805c4
▒U47 : Info :

INIT : Booting version: mega-20220809_57b0c0c (ESP32 SDK v4.4.3)
48 : Info : INIT : Free RAM:267076
50 : Info : INIT : Soft Reboot #7 Last Action before Reboot: Const Interval: TIMER_MQTT Last systime: 1660318992 - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
51 : Info : FS : Mounting...
109 : Info : FS : Mount successful, used 151552 bytes of 8318976
209 : Info : CRC : SecuritySettings CRC ...OK
236 : Info : INIT : I2C
238 : Info : INIT : SPI not enabled
239 : Info : ExtRTC: Read external time source: 1660319031
241 : Info : Time set to 1660319031.000
242 : Info : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 360 min
244 : Info : Local time: 2022-08-12 21:43:51
246 : Info : WiFi : Start network scan all channels
349 : Info : WiFi : STA Started
7566 : Info : WiFi : Scan finished, found: 11
7569 : Info : WiFi : Best AP candidate: access_point8 88:DC:96:26:7F:0A Ch:9 (-56dBm) WPA2/PSK
7570 : Info : WIFI : Connecting access_point8 88:DC:96:26:7F:0A Ch:9 (-56dBm) WPA2/PSK attempt #0
7577 : Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
7601 : Info : INIT : Free RAM:219884
7654 : Info : PMSx003 : using hardware serialGuru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled.

Core 1 register dump:
PC : 0x40093bbe PS : 0x00060f30 A0 : 0x80094212 A1 : 0x3ffb22e0
A2 : 0xffffffff A3 : 0x00000017 A4 : 0x3ffc7b64 A5 : 0x0000abab
A6 : 0x00060f23 A7 : 0x00060f20 A8 : 0x00000002 A9 : 0xffffffff
A10 : 0x00000002 A11 : 0x00000110 A12 : 0x00000017 A13 : 0x0000abab
A14 : 0x00060f23 A15 : 0x00060f23 SAR : 0x00000003 EXCCAUSE: 0x0000001c
EXCVADDR: 0x0000001b LBEG : 0x4008c43d LEND : 0x4008c44d LCOUNT : 0xffffffff

Backtrace:0x40093bbb:0x3ffb22e00x4009420f:0x3ffb2300 0x4009447c:0x3ffb2320 0x4008499a:0x3ffb2340 0x400849ad:0x3ffb2360 0x40084bc8:0x3ffb2380 0x401eb96d:0x3ffb23a0 0x401e5b9e:0x3ffb23e0 0x401e1d7a:0x3ffb2440 0x400e258a:0x3ffb2480 0x401b0453:0x3ffb24b0 0x40135df7:0x3ffb2510 0x4018b9f3:0x3ffb2620 0x4018bd0a:0x3ffb2670 0x40199096:0x3ffb2760 0x40189d39:0x3ffb27a0 0x40123f7f:0x3ffb2800 0x401e5ea6:0x3ffb2820

ELF file SHA256: 0000000000000000

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

Board was going to cycle reboot with same serial messages for some time and then going back with disabled PMS7003 plugin:
image
After it board was working good until display was added and board was rebooted after it:

rst:0xc (SW_CPU_RESET),boot:0x17 (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:DOUT, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12616
load:0x40080400,len:2916
entry 0x400805c4
▒U47 : Info :

INIT : Booting version: mega-20220809_57b0c0c (ESP32 SDK v4.4.3)
48 : Info : INIT : Free RAM:267076
50 : Info : INIT : Soft Reboot #13 Last Action before Reboot: Intended Reboot: CommandReboot Last systime: 1660320187 - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
51 : Info : FS : Mounting...
67 : Info : FS : Mount successful, used 151552 bytes of 8318976
94 : Info : CRC : SecuritySettings CRC ...OK
104 : Info : INIT : I2C
107 : Info : INIT : SPI Init (without CS)
109 : Info : ExtRTC: Read external time source: 1660320187
110 : Info : Time set to 1660320187.000
111 : Info : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 360 min
112 : Info : Local time: 2022-08-12 22:03:07
114 : Info : WiFi : Start network scan all channels
216 : Info : WiFi : STA Started
7432 : Info : WiFi : Scan finished, found: 9
7435 : Info : WiFi : Best AP candidate: access_point8 88:DC:96:26:7F:0A Ch:9 (-58dBm) WPA2/PSK
7437 : Info : WIFI : Connecting access_point8 88:DC:96:26:7F:0A Ch:9 (-58dBm) WPA2/PSK attempt #0
7444 : Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
7468 : Info : INIT : Free RAM:219972
7501 : Info : ILI9341: Init start.
7502 : Info : ILI9341: Init done, address: 0x3ffd391c valid, commands: tft/tftcmd
7503 : Info : AdaGFX_h

After this additional step board isn't going back as previously, it's stucking in this state

@sobolkz
Copy link
Author

sobolkz commented Aug 12, 2022

P.S. also - WiFi isn't connected to AP, there is no such device in WiFi client's list at the router.

@tonhuisman
Copy link
Contributor

Thinking about this for a while, but I'm inclined to think that this is related to recent IDF changes, regarding pin mode settings etc.
Also, using pins 13 and 14 for CS and a serial connection pin might interfere with the regular HSPI pin designation (that's not initialized as you have selected VSPI), so it shouldn't matter, but if it does that could be a bug introduced by the latest IDF update, but that's just a wild guess.

@TD-er
Copy link
Member

TD-er commented Aug 12, 2022

I don't have the exact same display here (or at least I can't find it...)
But I tested with an ST7789 which does seem to be using the same Adafruit libraries.
I also used the VSPI bus and it is working just fine.
So I don't think it is related to the timing issues we saw for other plugins when accessing GPIO pins on recent ESP32 SDK builds.
image

image

Also looked at the signals using the Logic Analyzer, but there doesn't seem to be any strange jitter in the timings
image
It is a very high frequency SPI clock by the way (roughly 26 MHz).
Not sure if this frequency has changed since older builds.

@sobolkz
Copy link
Author

sobolkz commented Aug 13, 2022

OK, I'll try to check situation with new same board. It isn't soldered, therefore it can't take HW affect, only SW.

@sobolkz
Copy link
Author

sobolkz commented Aug 13, 2022

So, same bootloop with new board, wasn't previously used yet. Was flashed with mega-20220809 and minimally configured - same Advanced settings, same Hardware and VSPI. GPIO2&32 was manually changed to 1 by "Commands" through web server. After Display was added it send Core panic, rebooted and stucked at AdaGFX helper step:

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x17 (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:DOUT, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12616
load:0x40080400,len:2916
entry 0x400805c4
▒U42 : Info :

INIT : Booting version: mega-20220809_57b0c0c (ESP32 SDK v4.4.3)
43 : Info : INIT : Free RAM:267396
45 : Info : INIT : Cold Boot - Restart Reason: CP./components/esp_littlefs/src /littlefs/lfs.c:1229:error: Corrupted dir pair at {0x0, 0x1}
U0: Vbat power on reset CPU1: for APP CPU, reseted by PRO CPU
46 : Info : FS : Mounting...
FS : Mount failed
54 : Error : FS : Mount failed
RESET./components/esp_littlefs/src/littlefs/lfs.c:1229:error: Corrupted dir pair at {0x0, 0x1}
: Resetting factory defaults... using default settings
RESET: Warm boot, reset count: 0
RESET: formatting...
RESET: formatting done...
31170 : Info : SaveToFile: free stack: 7416
33202 : Info : FILE : Saved config.dat offset: 8192 size: 820
33203 : Info : SaveToFile: free stack after: 7416
33204 : Info : SaveToFile: free stack: 7448
35374 : Info : FILE : Saved config.dat offset: 0 size: 3004
35375 : Info : SaveToFile: free stack after: 7448
35377 : Info : SaveToFile: free stack: 7256
35488 : Info : FILE : Saved security.dat offset: 0 size: 593
35489 : Info : SaveToFile: free stack after: 7256
35501 : Info : SaveToFile: free stack: 7000
35587 : Info : FILE : Saved security.dat offset: 1024 size: 6
35588 : Info : SaveToFile: free stack after: 7000
RESET: Successful, rebooting. (you might need to press the reset button if you've just flashed the firmware)
36771 : Info : WIFI : Set WiFi to OFFets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x17 (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:DOUT, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12616
load:0x40080400,len:2916
entry 0x400805c4
▒U47 : Info :

INIT : Booting version: mega-20220809_57b0c0c (ESP32 SDK v4.4.3)
48 : Info : INIT : Free RAM:267076
50 : Info : INIT : Soft Reboot #1 Last Action before Reboot: Intended Reboot: ResetFactory Last systime: 36 - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
51 : Info : FS : Mounting...
89 : Info : FS : Mount successful, used 151552 bytes of 8318976
175 : Info : CRC : SecuritySettings CRC ...OK
197 : Info : INIT : I2C
199 : Info : INIT : SPI not enabled
200 : Info : Time set to 36.000 Time adjusted by 35800.00 msec. Wander: 0.000 msec/second Source: RTC at boot
202 : Info : Current Time Zone: STD time start: 1970-10-25 03:00:00 offset: 0 min
203 : Info : Local time: 1970-01-01 00:00:36
205 : Info : WiFi : Start network scan all channels
305 : Info : WiFi : STA Started
6720 : Info : WiFi : Scan finished, found: 9
6723 : Error : WIFI : No valid wifi settings
6825 : Info : WIFI : Set WiFi to AP+STA
6828 : Info : WiFi : AP Started
7390 : Info : WiFi : AP Stopped
7391 : Info : WiFi : AP Started
7392 : Info : WIFI : AP Mode ssid will be MAX-ESP32 with address 192.168.4.1
7394 : Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
7500 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 7398 ms
7515 : Error : WiFi : Scan not allowed, unprocessed WiFi events: disconn
7617 : Info : WIFI : Set WiFi to OFF
7842 : Info : WiFi : Start network scan all channels
7854 : Info : WiFi : STA Started
14468 : Info : WiFi : Scan finished, found: 12
14575 : Info : WIFI : Set WiFi to AP+STA
15139 : Info : WIFI : AP Mode ssid will be MAX-ESP32 with address 192.168.4.1
15241 : Info : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 14 s
15257 : Error : WiFi : Scan not allowed, unprocessed WiFi events: disconn
15358 : Info : WIFI : Set WiFi to OFF
15583 : Info : WIFI : Arduino wifi status: WL_NO_SHIELD 255 ESPeasy internal wifi status: DISCONNECTED
15686 : Info : WIFI : Set WiFi to AP
15697 : Info : WiFi : AP Started
16258 : Info : WiFi : AP Stopped
16259 : Info : WiFi : AP Started
16260 : Info : WIFI : AP Mode ssid will be MAX-ESP32 with address 192.168.4.1
16296 : Info : INIT : Free RAM:214892
16877 : Info : INFO : Plugins: 124 [Normal] [MAX ESP32] (ESP32 SDK v4.4.3)
16882 : Info : WIFI : Arduino wifi status: WL_NO_SHIELD 255 ESPeasy internal wifi status: DISCONNECTED
16887 : Info : Webserver: start
16903 : Info : OTA : Arduino OTA enabled on port 3232
18256 : Info : WD : Uptime 0 ConnectFailures 0 FreeMem 195232 WiFiStatus WL_NO_SHIELD 255 ESPeasy internal wifi status: DISCONNECTED
26477 : Info : AP Mode: Client connected: 54:27:1E:06:27:B4 Connected devices: 1
26482 : Error : UNKNOWN WIFI/ETH EVENT: 14
48244 : Info : WD : Uptime 1 ConnectFailures 0 FreeMem 189848 WiFiStatus WL_NO_SHIELD 255 ESPeasy internal wifi status: DISCONNECTED
50378 : Info : SaveToFile: free stack: 7208
52563 : Info : FILE : Saved config.dat offset: 0 size: 3004
52564 : Info : SaveToFile: free stack after: 7208
52565 : Info : SaveToFile: free stack: 7016
52671 : Info : FILE : Saved security.dat offset: 0 size: 593
52672 : Info : SaveToFile: free stack after: 7016
52689 : Info : SaveToFile: free stack: 6760
52780 : Info : FILE : Saved security.dat offset: 1024 size: 6
52781 : Info : SaveToFile: free stack after: 6760
52783 : Info : WIFI : Credentials Changed, retry connection. SSID: access_point8
52785 : Info : WiFi : Best AP candidate: access_point8 88:DC:96:26:7F:0A Ch:9 (-61dBm) WPA2/PSK
52786 : Info : WIFI : Connecting access_point8 88:DC:96:26:7F:0A Ch:9 (-61dBm) WPA2/PSK attempt #0
52887 : Info : WIFI : Set WiFi to AP+STA
52891 : Info : WiFi : STA Started
52997 : Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
53895 : Info : WIFI : Connected! AP: access_point8 (88:DC:96:26:7F:0A) Ch: 9 Duration: 1102 ms
53912 : Info : WIFI : DHCP IP: 192.168.3.25 (MAX-ESP32) GW: 192.168.3.1 SN: 255.255.255.0 duration: 20 ms
53930 : Info : SaveToFile: free stack: 7096
54019 : Info : FILE : Saved security.dat offset: 1024 size: 6
54021 : Info : SaveToFile: free stack after: 7096
54022 : Info : WIFI : Arduino wifi status: WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP
54022 : Info : WIFI : Starting mDNS...
54026 : Info : WIFI : mDNS started, with name: MAX-ESP32.local
54040 : Info : UDP : Start listening on port 8266
54041 : Info : firstLoopConnectionsEstablished
55666 : Info : AP Mode: Client disconnected: 54:27:1E:06:27:B4 Connected devices: 1
60503 : Info : AP Mode: Client connected: 54:27:1E:06:27:B4 Connected devices: 1
60514 : Error : UNKNOWN WIFI/ETH EVENT: 14
78237 : Info : WD : Uptime 1 ConnectFailures 0 FreeMem 183432 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
99519 : Info : Webserver 33 Arguments (First 20): 0: 'userules' length: 2 1: 'enable_rules_cache' length: 2 2: 'usentp' length: 2 3: 'ntphost' length: 11 4: 'exttimesource' length: 1 5: 'dststartweek' length: 1 6: 'dststartdow' length: 1 7: 'dststartmonth' length: 1 8: 'dststarthour' length: 1 9: 'dstendweek' length: 1 10: 'dstenddow' length: 1 11: 'dstendmonth' length: 2 12: 'dstendhour' length: 1 13: 'timezone' length: 3 14: 'latitude' length: 8 15: 'longitude' length: 8 16: 'syslogip' length: 0 17: 'syslogport' length: 3 18: 'syslog_log_level' length: 1 19: 'syslogfacility' length: 1
99527 : Info : SaveToFile: free stack: 7240
101708 : Info : FILE : Saved config.dat offset: 0 size: 3004
101709 : Info : SaveToFile: free stack after: 7240
101727 : Info : SaveToFile: free stack: 6792
101824 : Info : FILE : Saved security.dat offset: 1024 size: 6
101826 : Info : SaveToFile: free stack after: 6792
101842 : Info : NTP : NTP replied: delay 10 mSec Accuracy increased by 0.007 seconds
101845 : Error : ExtRTC: Cannot set time to external time source
101845 : Info : Time set to 1660364288.007
101846 : Info : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 360 min
101848 : Info : Local time: 2022-08-13 10:18:08
102007 : Info : EVENT: Time#Set
102231 : Info : EVENT: Clock#Time=Sat,10:18
108238 : Info : WD : Uptime 2 ConnectFailures 0 FreeMem 179404 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
133899 : Info : Upload: START, filename: rules1.txt
133917 : Info : Upload: WRITE, Bytes: 85
133922 : Info : Upload: END, Size: 85
134004 : Info : Webserver 1 Arguments: 0: 'enctype' length: 19
134048 : Info : CRC : SecuritySettings CRC ...OK
138237 : Info : WD : Uptime 2 ConnectFailures 0 FreeMem 181100 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
154231 : Info : EVENT: Clock#Time=Sat,10:19
168237 : Info : WD : Uptime 3 ConnectFailures 0 FreeMem 181792 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
170507 : Info : Webserver 41 Arguments (First 20): 0: 'pled' length: 2 1: 'pledi' length: 2 2: 'pres' length: 2 3: 'psda' length: 2 4: 'pscl' length: 2 5: 'pi2csp' length: 6 6: 'pi2cspslow' length: 6 7: 'pi2cmuxtype' length: 2 8: 'pi2cmuxaddr' length: 2 9: 'pi2cmuxreset' length: 2 10: 'initspi' length: 1 11: 'spipinsclk' length: 2 12: 'spipinmiso' length: 2 13: 'spipinmosi' length: 2 14: 'sd' length: 2 15: 'p0' length: 1 16: 'p2' length: 1 17: 'p4' length: 1 18: 'p5' length: 1 19: 'p12' length: 1
170513 : Info : SaveToFile: free stack: 7048
172669 : Info : FILE : Saved config.dat offset: 0 size: 3004
172670 : Info : SaveToFile: free stack after: 7048
172684 : Info : SaveToFile: free stack: 6600
172773 : Info : FILE : Saved security.dat offset: 1024 size: 6
172775 : Info : SaveToFile: free stack after: 6600
172776 : Info : INIT : I2C
197206 : Info : Webserver 1 Arguments: 0: 'cmd' length: 9
197207 : Info : HTTP: GPIO,32,1
197214 : Info : GPIO : port#32: set to 1
198237 : Info : WD : Uptime 3 ConnectFailures 0 FreeMem 181216 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
202844 : Info : Webserver 1 Arguments: 0: 'cmd' length: 8
202845 : Info : HTTP: GPIO,2,1
202851 : Info : GPIO : port#2: set to 1
214231 : Info : EVENT: Clock#Time=Sat,10:20
217490 : Info : Webserver 2 Arguments: 0: 'index' length: 1 1: 'page' length: 1
224655 : Info : Webserver 5 Arguments: 0: 'index' length: 1 1: 'page' length: 1 2: 'TDNUM' length: 2 3: 'edit' length: 1 4: 'page' length: 1
226274 : Info : SaveToFile: free stack: 7096
227882 : Info : FILE : Saved config.dat offset: 32768 size: 536
227883 : Info : SaveToFile: free stack after: 7096
227885 : Info : SaveToFile: free stack: 7176
230023 : Info : FILE : Saved config.dat offset: 0 size: 3004
230024 : Info : SaveToFile: free stack after: 7176
230041 : Info : SaveToFile: free stack: 6728
230135 : Info : FILE : Saved security.dat offset: 1024 size: 6
230136 : Info : SaveToFile: free stack after: 6728
230451 : Info : EVENT: TaskExit#=1,0
230542 : Info : WD : Uptime 4 ConnectFailures 0 FreeMem 180668 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
258239 : Info : WD : Uptime 4 ConnectFailures 0 FreeMem 181792 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
258986 : Info : Webserver 49 Arguments (First 20): 0: 'index' length: 1 1: 'page' length: 1 2: 'TDNUM' length: 2 3: 'TDN' length: 7 4: 'TDE' length: 2 5: 'taskdevicepin1' length: 2 6: 'taskdevicepin2' length: 2 7: 'taskdevicepin3' length: 2 8: 'p095_backlight' length: 2 9: 'p095_backpercentage' length: 3 10: 'p095_button' length: 2 11: 'p095_timer' length: 1 12: 'p095_rotate' length: 1 13: 'p095_mode' length: 1 14: 'p095_fontscale' length: 1 15: 'p095_commandtrigger' length: 1 16: 'p095_compat' length: 2 17: 'p095_backfill' length: 2 18: 'p095_foregroundcolor' length: 5 19: 'p095_backgroundcolor' length: 5
259010 : Info : SaveToFile: free stack: 6792
260634 : Info : FILE : Saved config.dat offset: 32768 size: 536
260635 : Info : SaveToFile: free stack after: 6792
260700 : Info : SaveToFile: free stack: 5912
262306 : Info : FILE : Saved config.dat offset: 33792 size: 24
262307 : Info : SaveToFile: free stack after: 5912
262325 : Info : SaveToFile: free stack: 7096
263924 : Info : FILE : Saved config.dat offset: 32768 size: 536
263925 : Info : SaveToFile: free stack after: 7096
263927 : Info : SaveToFile: free stack: 7176
266087 : Info : FILE : Saved config.dat offset: 0 size: 3004
266088 : Info : SaveToFile: free stack after: 7176
266112 : Info : SaveToFile: free stack: 6728
266215 : Info : FILE : Saved security.dat offset: 1024 size: 6
266217 : Info : SaveToFile: free stack after: 6728
266268 : Info : ILI9341: Init start.
266269 : Info : ILI9341: Init done, address: 0x3ffd10dc valid, commands: tft/tftcmd
266270 : Info : AdaGFXGuru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled.

Core 1 register dump:
PC : 0x401e53fd PS : 0x00060730 A0 : 0x800d2bc4 A1 : 0x3ffb2140
A2 : 0x00000000 A3 : 0x3ffc2c04 A4 : 0x00000040 A5 : 0x00000000
A6 : 0x00ff0000 A7 : 0xff000000 A8 : 0x801e3fdc A9 : 0x3ffb2120
A10 : 0x00000000 A11 : 0x00000001 A12 : 0x00000010 A13 : 0x3ffc6a68
A14 : 0x40263738 A15 : 0x3ffdab28 SAR : 0x00000005 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000000 LBEG : 0x400d38ac LEND : 0x400d38b0 LCOUNT : 0x00000000

Backtrace:0x401e53fa:0x3ffb21400x400d2bc1:0x3ffb2170 0x400d383d:0x3ffb2190 0x400d38c2:0x3ffb21b0 0x400d3955:0x3ffb21d0 0x400d3a93:0x3ffb21f0 0x4026374f:0x3ffb2210 0x401b9afe:0x3ffb2230 0x401453e7:0x3ffb22a0 0x4018c36c:0x3ffb24c0 0x401de0f3:0x3ffb25b0 0x4026e4e5:0x3ffb2660 0x400d7f8a:0x3ffb2680 0x400dcb61:0x3ffb26a0 0x400dcc11:0x3ffb26e0 0x400dcd19:0x3ffb2740 0x4018964e:0x3ffb2790 0x401898fd:0x3ffb27c0 0x40123f87:0x3ffb2800 0x401e5eb8:0x3ffb2820

ELF file SHA256: 0000000000000000

Rebooting...
ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x17 (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:DOUT, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12616
load:0x40080400,len:2916
entry 0x400805c4
▒U47 : Info :

INIT : Booting version: mega-20220809_57b0c0c (ESP32 SDK v4.4.3)
48 : Info : INIT : Free RAM:267076
50 : Info : INIT : Soft Reboot #2 Last Action before Reboot: Background Task Last systime: 1660364444 - Restart Reason: CPU0: Software reset CPU CPU1: Software reset CPU
51 : Info : FS : Mounting...
114 : Info : FS : Mount successful, used 151552 bytes of 8318976
222 : Info : CRC : SecuritySettings CRC ...OK
251 : Info : INIT : I2C
254 : Info : INIT : SPI Init (without CS)
256 : Info : ExtRTC: Read external time source: 1660364449
257 : Info : Time set to 1660364449.000
258 : Info : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 360 min
260 : Info : Local time: 2022-08-13 10:20:49
262 : Info : WiFi : Start network scan all channels
363 : Info : WiFi : STA Started
6980 : Info : WiFi : Scan finished, found: 13
6983 : Info : WiFi : Best AP candidate: access_point8 88:DC:96:26:7F:0A Ch:9 (-56dBm) WPA2/PSK
6985 : Info : WIFI : Connecting access_point8 88:DC:96:26:7F:0A Ch:9 (-56dBm) WPA2/PSK attempt #0
6995 : Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
7019 : Info : INIT : Free RAM:219540
7072 : Info : ILI9341: Init start.
7073 : Info : ILI9341: Init done, address: 0x3ffd3ab4 valid, commands: tft/tftcmd
7074 : Info : AdaGFX_helper

Test scheme is:
image

@sobolkz
Copy link
Author

sobolkz commented Aug 13, 2022

By the way - if it can help - I can't use @tonhuisman 's May's config from test release at new build (by save&load), look's like a difference in filesystem and new build can't successfully load it - board going to cyclic bootloop after loading old config.

@tonhuisman
Copy link
Contributor

It is a very high frequency SPI clock by the way (roughly 26 MHz).
Not sure if this frequency has changed since older builds.

That 26 MHz is what I've seen in these display-related sources ever since I started working with them, so most likely that hasn't changed.

@Jason2866
Copy link
Contributor

@Jason2866 Can you make a new release of the ESP32 SDK, including your latest commits, as suggested here ? I have a very strong feeling we're running into issues here related to LittleFS and DOUT/DIO mode.

Also you seem to have tackled the flashing issues where the ESP would not be set into flash mode without pulling GPIO-0 down.

I dont think it will solve your issues. The SDK (Arduino) is the same. Changed is only that esptool v4.1 and the USB reset command can be used.
You can try already with

platform = https://github.com/Jason2866/platform-espressif32.git

@TD-er
Copy link
Member

TD-er commented Aug 14, 2022

OK, will try.

Do you have any idea whether issues like these are really related to the slower speed of LittleFS on larger file systems?
I did try to flash nodes using QIO, but esptool kept changing it to DIO mode (also on configs where I set it to DOUT).
So on those nodes I cannot even switch to QIO even if I want to.

@Jason2866
Copy link
Contributor

Dont think LittleFS issues are speed related, we use heavily for Tasmota and our standard flash mode is dout. But when there is a mismatch in flashed bootloader and firmware i always had strange issues with LittleFS.
Are the issues when flashed with platformio and/or with factory firmware?

@Jason2866
Copy link
Contributor

Added https://github.com/arendst/Tasmota/blob/development/pio-tools/post_esp32.py#L134-L142 in factory firmware build script since you can not flash bootloaders in flash mode qio and qout.

@Jason2866
Copy link
Contributor

Tasmota USB serial code changes starting here

@TD-er
Copy link
Member

TD-er commented Aug 14, 2022

Thanks, will look into these links.

@Jason2866
Copy link
Contributor

Yes, sure. Download tool v. 3.9.2. As all before. Also, 16m1m was successfully flashed after it.

@TD-er Since how the bootloader are built for core 2.0.4 idk if using old tools is still working. There are NO defaults anymore in magic bytes firmware header.

@TD-er
Copy link
Member

TD-er commented Aug 14, 2022

Oh and just curious, why don't you have the option to not append the SHA digest when generating the factory bin?

@Jason2866
Copy link
Contributor

Jason2866 commented Aug 14, 2022

esptool v4.1 does not patch the header if there is the SHA diggest. So the need to be stripped before to make it possible to do the needed header patching.
In IDF this is not needed since the bootloaders are built together with the firmware with the settings made for size, speed and mode.
This remove of the diggest is only possible in elf2image command. The command is in the changed platformio espressif framework

@TD-er
Copy link
Member

TD-er commented Aug 14, 2022

Yep, I know why it is needed when patching the speed/mode flags.
But if it isn't possible to do so on "factory" images, then flashing using flash tools which may patch these on the fly will cause bootloops, right?

@Jason2866
Copy link
Contributor

Jason2866 commented Aug 14, 2022

See annswer above. The firmware.img does not have anymore the diggest. So the needed header patching is now possible with esptool v4.1 too.
The check for diggest and not to do patching (not to brake SHA) is introduced with esptool v4.x. Esptool v3.x patches always header. NO check! So this problem only arrives when using Esptool v4.

@sobolkz
Copy link
Author

sobolkz commented Aug 14, 2022

What state has the checkbox to change the bin? (not sure about the exact text) Does it allow to change the bin during flash or not? What does the flash tool show about the detected module? (flash frequency, flash mode, etc.)

As I use natuve Win tool Esspessif Download tool and remember option like "Do mot change the bin" always checked. Also it doesn't matter which type of flashing mode was used - it always use propriate type DIO or QIO.
Also, as I wrote before @tonhuisman's old test release 16M8M can be successfully used with same tool and same flashing options.

@Jason2866
Copy link
Contributor

Exactly old test release, stuff changed. Old may not working anymore!

@Jason2866
Copy link
Contributor

Even Platformio guys seems sometimes a bit confused about. Did a PR platformio/platform-espressif32#880

@sobolkz
Copy link
Author

sobolkz commented Aug 15, 2022

I'm testing now with only old one, because it's look like board HW independent issue. So, latest results - you build 3227 seems to work with 4M316k and 16M1M versions - I can upload this versions and use with backup. Version 16M8M LittleFS still can't be used - I can't restore backup. Board going to cyclic reboot after restoring, hardware power disconnection doesn't help. Also board going to reboot after PMS7003 was added at HWSerial1 or HWSerial2. I'll upload 16M1M version and will test it more detail.

2 days of testing- no issues. PMS7003 was changed to PMS5003ST, additional parameters was added for new events from this device - all looks good, some board stats:

1
2

@Jason2866
Copy link
Contributor

Jason2866 commented Aug 15, 2022

So issues are introduced somewhere since that. Since we encounter no issues in Tasmota it has to do something related to Espeasy or the tools around used to build or flash.
@sobolkz Please try with flash mode qio. This is the main change in core 2.0.4(.1) The way the bootloaders are builded has changed.
I recommend to set all boards to mode qio since it makes no difference. ONLY the second stage bootloader enables the flash mode which is used finally!
In my experience strange errors that may occur does disappear by doing this.
Maybe we are not hit by this since we use dout as standard flash mode for Tasmota.
It could be that the problem in this mode do not happen?!

@tonhuisman
Copy link
Contributor

ESPEasy uses flash-mode dout by default, currently. We made a test build 2 days ago with qio, but that wasn't an improvement

@sobolkz
Copy link
Author

sobolkz commented Aug 15, 2022

So issues are introduced somewhere since that. Since we encounter no issues in Tasmota it has to do something related to Espeasy or the tools around used to build or flash. @sobolkz Please try with flash mode qio. This is the main change in core 2.0.4(.1) The way the bootloaders are builded has changed. I recommend to set all boards to mode qio since it makes no difference. ONLY the second stage bootloader enables the flash mode which is used finally! In my experience strange errors that may occur does disappear by doing this. Maybe we are not hit by this since we use dout as standard flash mode for Tasmota. It could be that the problem in this mode do not happen?!

@Jason2866 , is it important, which tool should be used? As discussed with @TD-er some time ago - it can be sensitive for esptool. But as I use for las time only native Espressif win tool flash mode - it sholud like this one:
image
I'll test it again for you, but as I remember - it was already tested yesterday, it's look like this option doesn't affected while ESPEasy .factory.bin used. Independent that I choose upload procedure was going without errors and final mode is DOUT or QIO is provided inside of FW file.

@TD-er
Copy link
Member

TD-er commented Aug 15, 2022

The DoNotChgBin option is checked in your screenshot.
This means (or at least should mean) that no matter what you set in your SPI config there, or what is detected on the ESP unit, the flashed data should be exactly what was compiled.

However with that checkbox unchecked, or using other tools like esptool.py, the flash settings may be changed while flashing.

So this leaves us with several possible causes when flashing results in a boot loop (or other unexpected behavior) :

  • Settings used during build were wrong for your setup (with DoNotChgBin checked)
  • SPI config may have been changed by the flash tool, which makes it incompatible with the bootloader or the sketch
  • something else (yet unknown to me, but I am convinced we may have other causes for these issues)

Even with all the SPI flash settings set correct, I am still a bit worried to why exactly your build did behave like it did.
In other words, I am not 100% convinced that even though Ton's builds seem to work now, all new builds will too.
The reason I'm still not convinced is simply because I am not sure about whether our explanation can explain all we're seeing.

@TD-er
Copy link
Member

TD-er commented Aug 15, 2022

Just read through the comments a bit more.
The 4M build and 16M1M build both use SPIFFS.
The 16M8M uses LittleFS.
Maybe LittleFS is a bit more timing sensitive?
Or maybe it uses a bit more low level function calls, making assumptions it shouldn't?

@TD-er TD-er reopened this Aug 15, 2022
@Jason2866
Copy link
Contributor

For Tasmota we only use LittleFS and it is in every Esp32x build. If there would be a general problem users would have opened issues in github

@Jason2866
Copy link
Contributor

Mhh,. do you use ESPAsyncWebServer? There was a problem in the past. Needs newest version to work together.

@TD-er
Copy link
Member

TD-er commented Aug 15, 2022

Nope, we don't use that one.

@Jason2866
Copy link
Contributor

One point. I have no idea why the second stage bootloader does not switch in mode qio. I did not managed. But this is not new, previous version did behave identically

@Jason2866
Copy link
Contributor

Jason2866 commented Aug 15, 2022

Later this week I have some more time to do investigations around the qio miracle
Will start with IDF examples. If qio mode is activated I will try this generated bootloader to use with Tasmota.

@sobolkz
Copy link
Author

sobolkz commented Aug 19, 2022

Closing issue due to solved by theme.

@sobolkz sobolkz closed this as completed Aug 19, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Category: Plugin Related to supported sensors Status: Needs Info Needs more info before action can be taken Type: Bug Considered a bug
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants