Closed wcwuttke closed 4 months ago
Should be NTP - not BTP.
Issue confirmed. This is a a problem with esp_sntp_servermode_dhcp(1); // (optional)
call.
@wcwuttke - Please check PR #9884 that comments out esp_sntp_servermode_dhcp(1); // (optional)
code line in the example.
I commented out esp_sntp_servermode_dhcp(1); and it appeared to fix the problem. I rebooted the board three times successfully. However, the fourth and fifth time, got "No time available (yet)". Rebooted again and got the time. Rebooted again and got "No time available (yet)". Rebooted again and got the time. It looks like the problem is still there intermittently.
This is interesting... I was getting 100% success while I had debug output as Verbose. But when I tried it with no debug output I also see the issue youo are reporting about the problem being still there.
It may also be related to another fix from the https://github.com/espressif/arduino-esp32/pull/9862/files It seems that it must wait for the WiFi interface to really get started.
Indeed removing esp_sntp_servermode_dhcp(1);
is not the fix.
I have applied the fix from #9862 here and it seems to improve the success rate to 8 out of 10.
Could you apply the change to libraries/WiFi/src/STA.cpp
into the begin()
function?
bool STAClass::begin(bool tryConnect) {
if (!WiFi.enableSTA(true)) {
log_e("STA enable failed!");
return false;
}
if (!waitStatusBits(ESP_NETIF_STARTED_BIT, 1000)) {
log_e("Failed to start STA!");
return false;
}
if (tryConnect) {
return connect();
}
return true;
}
@me-no-dev - Could you please also take a look into it?
@wcwuttke - I think I got the solution: I changed the NTP server to const char *ntpServer1 = "time.google.com";
It has worked 100% of 20 resets of the board.
Applied the above two changes and still will not get the time.
On Mon, Jun 17, 2024 at 8:06 PM Rodrigo Garcia @.***> wrote:
@wcwuttke https://github.com/wcwuttke - I think I got the solution: I changed the NTP server to const char *ntpServer1 = "time.google.com"; It is running 100% of 20 resets of the board.
— Reply to this email directly, view it on GitHub https://github.com/espressif/arduino-esp32/issues/9879#issuecomment-2174874070, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEW6V3DTSAXWHQ3PDNTQWELZH6P27AVCNFSM6AAAAABJOR7HYWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCNZUHA3TIMBXGA . You are receiving this because you were mentioned.Message ID: @.***>
The change in STA.cpp
is irrelevant. esp_sntp_servermode_dhcp(1);
should be the line after WiFi.begin()
as explained in it's comment, but will also not cause NTP to fail, it will just not take it from DHCP if it offers NTP server.
With that said, I am trying to replicate the issue and I can not. I got No time available (yet)
once and a couple of seconds later, it got the time just fine. Restarted tenths of times.
me-no-dev, I don't know what your configuration is, but the only way I can get this sketch to work reliably is with version 2.0.17. With 3.0.1, it will work once in a while, but mostly fails.
I don't know what your configuration is
The example as-is. Nothing else. My SSID and PASS
Did you wait after you got the message to eventually get the NTP or not?
Me No Dev,
I think I waited long enough (only part of the output - that's all I could cut & paste):
Connecting to Apple Network 783caa . CONNECTED
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
No time available (yet)
On Tue, Jun 18, 2024 at 11:43 AM Me No Dev @.***> wrote:
Did you wait after you got the message to eventually get the NTP or not?
— Reply to this email directly, view it on GitHub https://github.com/espressif/arduino-esp32/issues/9879#issuecomment-2176738083, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEW6V3APEVXTVSKOPIBX5TLZIB5UZAVCNFSM6AAAAABJOR7HYWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCNZWG4ZTQMBYGM . You are receiving this because you were mentioned.Message ID: @.***>
@wcwuttke I see, but I can not reproduce here. I made more than 30 restarts with the sketch as-is and could not get it to fail once. I suspect something in your environment is to blame
I would think that if it is working well with v.2.0.17, and simply updating the esp32 core to 3.0.1, it should still work. I have tested 3 different mfg boards on 3 different computers (win 11, macos 14.5 x86, and macos 14.5 m1), using Arduino IDE 2.3.2. (Not compiled for debug.) I will run some more tests tomorrow with the macbook pro and try an esp32-s3 and see what happens. What is your test environment?
On Tue, Jun 18, 2024 at 21:53 Me No Dev @.***> wrote:
@wcwuttke https://github.com/wcwuttke I see, but I can not reproduce here. I made more than 30 restarts with the sketch as-is and could not get it to fail once. I suspect something in your environment is to blame
— Reply to this email directly, view it on GitHub https://github.com/espressif/arduino-esp32/issues/9879#issuecomment-2177734293, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEW6V3CXU6QC4ZB3EUOS763ZIEFFLAVCNFSM6AAAAABJOR7HYWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCNZXG4ZTIMRZGM . You are receiving this because you were mentioned.Message ID: @.***>
ESP32-WROVER-E (ESP32 v3) on a Mac M1MAX (should not matter) and my router is Mikrotik without any special settings for NTP. Sketch is SimpleTime with adjusted SSID, PASS and time offset for my zone. From all reboots I got No time available (yet)
only once for just one time, after which time was updated before next 5 seconds expires.
Any chance you can try in a different network environment? I have no idea why 2.x worked but 3.x fails for you...
I think we may have stumbled upon something. All my boards that exhibit the problem are WROOMs. I tried the esp32-s3 board tonight and it worked well with 3.0.1. So, it appears the esp32s are not created equal.
On Tue, Jun 18, 2024 at 23:53 Me No Dev @.***> wrote:
ESP32-WROVER-E (ESP32 v3) on a Mac M1MAX (should not matter) and my router is Mikrotik without any special settings for NTP. Sketch is SimpleTime with adjusted SSID, PASS and time offset for my zone. From all reboots I got No time available (yet) only once for just one time, after which time was updated before next 5 seconds expires.
Any chance you can try in a different network environment? I have no idea why 2.x worked but 3.x fails for you...
— Reply to this email directly, view it on GitHub https://github.com/espressif/arduino-esp32/issues/9879#issuecomment-2177886430, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEW6V3C4T3BQE34NOLKAFNLZIETF5AVCNFSM6AAAAABJOR7HYWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCNZXHA4DMNBTGA . You are receiving this because you were mentioned.Message ID: @.***>
can you turn core debug to level Verbose and paste the output before setup on those ESPs? I'll try to use the same
Is this what you need?
nvs : addr: 0x00009000, size: 20.0 KB, type: DATA, subtype: NVS
otadata : addr: 0x0000E000, size: 8.0 KB, type: DATA, subtype: OTA
app0 : addr: 0x00010000, size: 1280.0 KB, type: APP, subtype: OTA_0
app1 : addr: 0x00150000, size: 1280.0 KB, type: APP, subtype: OTA_1
spiffs : addr: 0x00290000, size: 1408.0 KB, type: DATA, subtype: SPIFFS
coredump : addr: 0x003F0000, size: 64.0 KB, type: DATA, subtype: COREDUMP
Arduino Board : ESP32_DEV Arduino Variant : esp32 Arduino FQBN : esp32:esp32:esp32:UploadSpeed=921600,CPUFreq=240,FlashFreq=80,FlashMode=qio,FlashSize=4M, PartitionScheme=default,DebugLevel=verbose,PSRAM=disabled,LoopCore=1,EventsCore=1, EraseFlash=none,JTAGAdapter=default,ZigbeeMode=default ============ Before Setup End ============
yes. will test tomorrow
Very strange thing...With v.3.0.1, the sketch repeatedly crashed and rebooted after setting debug level to verbose. I went back to 2.0.17 and got what I think is the correct output, but has no before/after startup:
........[ 4882][V][WiFiGeneric.cpp:363] _arduino_event_cb(): STA Disconnected: SSID: oldfellowstoys, BSSID: 96:04:e3:99:c0:a1, Reason: 2 [ 4894][D][WiFiGeneric.cpp:1040] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED [ 4902][W][WiFiGeneric.cpp:1062] _eventCallback(): Reason: 2 - AUTH_EXPIRE [ 4908][D][WiFiGeneric.cpp:1082] _eventCallback(): WiFi Reconnect Running [ 4917][V][WiFiGeneric.cpp:97] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0 ...[ 6227][V][WiFiGeneric.cpp:356] _arduino_event_cb(): STA Connected: SSID: oldfellowstoys, BSSID: 96:04:e3:99:c0:a1, Channel: 6, Auth: WPA2_WPA3_PSK [ 6240][D][WiFiGeneric.cpp:1040] _eventCallback(): Arduino Event: 4 - STA_CONNECTED [ 6281][V][WiFiGeneric.cpp:370] _arduino_event_cb(): STA Got New IP:10.0.0.162 [ 6288][D][WiFiGeneric.cpp:1040] _eventCallback(): Arduino Event: 7 - STA_GOT_IP [ 6295][D][WiFiGeneric.cpp:1103] _eventCallback(): STA IP: 10.0.0.162, MASK: 255.255.255.0, GW: 10.0.0.1 . CONNECTED No time available (yet) Got time adjustment from NTP! Wednesday, June 19 2024 19:50:34
Now I will try 3.0.1 again: Keeps on crashing with:
assert failed: tcpip_callback /IDF/components/lwip/lwip/src/api/tcpip.c:313 (Invalid mbox)
Something very strange has happened. When I compile with 3.0.1, the app repeatedly crashes. I go back to 2.0.17, all is well. Go back to 3.0.1 continuous crashing.
This is happening on 2 different machines an 2 different boards. I appears that the esp32 core library has changed somehow. Help!
can you please not reply via email? formatting the data you paste is impossible this way and it's very hard to read
I agree. However, to me it looks OK on Github. I had a lot of trouble trying to cut & paste from the Arduino IDE, and I have never used the debug features before. (I have always used "Serial.print" for debugging.) Let me try compiling on the Win 11 machine to see what is happening with it. Maybe if I knew exactly what you are looking for I could try to get it.
Email replies do not support Markdown
After you paste it here and not through email. we can fix the format (though that is something you should do yourself). Email replies are ok if you are just commenting, but pasting logs and code is not good
Something very strange has happened. When I compile with 3.0.1, the app repeatedly crashes. I go back to 2.0.17, all is well. Go back to 3.0.1 continuous crashing.
That sounds like the issue is in your environment. Or are you using another sketch and not the SimpleTime
?
I am using SimpleTime. I just tested on the Win11 machine with the same results. Keeps on crashing - both 3.0.0 and 3.0.1. I revert to 2.0.17 and all is well. Now it is 3 different machines with 3 different OS's.
I do have rev1 wrovers here so will test tomorrow
Just for fun, I tested using Arduino 1.8.19 on the Win11 machine. Same result. OK with 2.0.17, keeps crashing with 3.0.1.
As long as we are testing with two different chips, we will never have the same testing environment. I will order a WROVER board today to see what happens on this end.
Things are getting stranger. I compiled a few other example projects and came back to SimpleTime. Amazingly enough it compiled and ran OK - but, sometimes got the time, sometimes it didn't. I captured the verbose debug output of 3 reboots - both getting time and not getting time - to a file which is attached. Debug.txt
and my output with the same module as yours (many restarts an no fail):
ets Jun 8 2016 00:22:57
rst:0x1 (POWERON_RESET),boot:0x13 (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:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0030,len:1448
load:0x40078000,len:14844
ho 0 tail 12 room 4
load:0x40080400,len:4
load:0x40080404,len:3356
entry 0x4008059c
[ 1][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RX (2) successfully set to 0x400d9648
[ 12][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_TX (3) successfully set to 0x400d9618
[ 26][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_CTS (4) successfully set to 0x400d95e8
[ 39][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RTS (5) successfully set to 0x400d95b8
[ 53][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RX (2) successfully set to 0x400d9648
[ 66][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_TX (3) successfully set to 0x400d9618
[ 79][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_CTS (4) successfully set to 0x400d95e8
[ 93][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RTS (5) successfully set to 0x400d95b8
[ 106][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RX (2) successfully set to 0x400d9648
[ 120][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_TX (3) successfully set to 0x400d9618
[ 133][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_CTS (4) successfully set to 0x400d95e8
[ 147][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RTS (5) successfully set to 0x400d95b8
[ 162][D][esp32-hal-cpu.c:264] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
[ 224][V][esp32-hal-periman.c:160] perimanSetPinBus(): Pin 3 successfully set to type UART_RX (2) with bus 0x3ffbdb80
[ 235][V][esp32-hal-periman.c:160] perimanSetPinBus(): Pin 1 successfully set to type UART_TX (3) with bus 0x3ffbdb80
=========== Before Setup Start ===========
Chip Info:
------------------------------------------
Model : ESP32
Package : D0WD-Q6
Revision : 100
Cores : 2
Frequency : 240 MHz
Embedded Flash : No
Embedded PSRAM : No
2.4GHz WiFi : Yes
Classic BT : Yes
BT Low Energy : Yes
IEEE 802.15.4 : No
------------------------------------------
INTERNAL Memory Info:
------------------------------------------
Total Size : 336152 B ( 328.3 KB)
Free Bytes : 304948 B ( 297.8 KB)
Allocated Bytes : 23948 B ( 23.4 KB)
Minimum Free Bytes: 298816 B ( 291.8 KB)
Largest Free Block: 110580 B ( 108.0 KB)
------------------------------------------
Flash Info:
------------------------------------------
Chip Size : 4194304 B (4 MB)
Block Size : 65536 B ( 64.0 KB)
Sector Size : 4096 B ( 4.0 KB)
Page Size : 256 B ( 0.2 KB)
Bus Speed : 80 MHz
Bus Mode : QIO
------------------------------------------
Partitions Info:
------------------------------------------
nvs : addr: 0x00009000, size: 20.0 KB, type: DATA, subtype: NVS
otadata : addr: 0x0000E000, size: 8.0 KB, type: DATA, subtype: OTA
app0 : addr: 0x00010000, size: 1280.0 KB, type: APP, subtype: OTA_0
app1 : addr: 0x00150000, size: 1280.0 KB, type: APP, subtype: OTA_1
spiffs : addr: 0x00290000, size: 1408.0 KB, type: DATA, subtype: SPIFFS
coredump : addr: 0x003F0000, size: 64.0 KB, type: DATA, subtype: COREDUMP
------------------------------------------
Software Info:
------------------------------------------
Compile Date/Time : Jun 10 2024 10:52:03
Compile Host OS : macosx
ESP-IDF Version : v5.1.4-51-g442a798083-dirty
Arduino Version : 3.0.1
------------------------------------------
Board Info:
------------------------------------------
Arduino Board : ESP32_DEV
Arduino Variant : esp32
Arduino FQBN : esp32:esp32:esp32:UploadSpeed=921600,CPUFreq=240,FlashFreq=80,FlashMode=qio,FlashSize=4M,PartitionScheme=default,DebugLevel=verbose,PSRAM=disabled,LoopCore=1,EventsCore=1,EraseFlash=none,JTAGAdapter=default,ZigbeeMode=default
============ Before Setup End ============
[ 737][V][esp32-hal-uart.c:408] uartBegin(): UART0 baud(115200) Mode(800001c) rxPin(3) txPin(1)
[ 746][V][esp32-hal-uart.c:497] uartBegin(): UART0 not installed. Starting installation
[ 756][V][esp32-hal-uart.c:544] uartBegin(): UART0 initialization done.
Connecting to nbis-test [ 794][V][NetworkEvents.cpp:119] checkForEvent(): Network Event: 9 - WIFI_READY
[ 875][V][STA.cpp:184] _onStaEvent(): STA Started
[ 880][V][NetworkEvents.cpp:119] checkForEvent(): Network Event: 11 - STA_START
[ 887][V][STA.cpp:110] _onStaArduinoEvent(): Arduino STA Event: 11 - STA_START
[ 982][V][STA.cpp:204] _onStaEvent(): STA Connected: SSID: nbis-test, BSSID: 74:4d:28:c6:7a:fc, Channel: 8, Auth: WPA_WPA2_PSK
[ 994][V][NetworkEvents.cpp:119] checkForEvent(): Network Event: 13 - STA_CONNECTED
[ 998][V][NetworkInterface.cpp:66] _onIpEvent(): sta Got New IP: 192.168.254.99 MASK: 255.255.255.0 GW: 192.168.254.1
[ 1012][V][STA.cpp:110] _onStaArduinoEvent(): Arduino STA Event: 13 - STA_CONNECTED
[ 1019][V][NetworkEvents.cpp:119] checkForEvent(): Network Event: 16 - STA_GOT_IP
[ 1027][V][STA.cpp:110] _onStaArduinoEvent(): Arduino STA Event: 16 - STA_GOT_IP
[ 1034][V][STA.cpp:169] _onStaArduinoEvent(): STA IP: 192.168.254.99, MASK: 255.255.255.0, GW: 192.168.254.1
. CONNECTED
=========== After Setup Start ============
INTERNAL Memory Info:
------------------------------------------
Total Size : 336152 B ( 328.3 KB)
Free Bytes : 256700 B ( 250.7 KB)
Allocated Bytes : 69396 B ( 67.8 KB)
Minimum Free Bytes: 253256 B ( 247.3 KB)
Largest Free Block: 110580 B ( 108.0 KB)
------------------------------------------
GPIO Info:
------------------------------------------
GPIO : BUS_TYPE[bus/unit][chan]
--------------------------------------
1 : UART_TX[0]
3 : UART_RX[0]
============ After Setup End =============
Got time adjustment from NTP!
Thursday, June 20 2024 14:02:50
Thursday, June 20 2024 14:02:52
Thursday, June 20 2024 14:02:57
I set up a Win10 machine as an NTP server. In the SimpleTime sketch I used the Win10 IP address in ConfigTime(). This configuration works like a charm (3.0.1). So....to me it looks like a DNS problem of some sort. I have an XFinity router which from time to time has had DNS problems. Let me reboot that and let's see what happens. Progress is being made.
Well, rebooting the router didn't help.
update: Used IP address for time.google.com (216.239.35.4) instead of hostname and it works well. Also for IP address of pool.ntp.org. It looks that at least I've found a workaround.
update: Tried the WROVER. Has the same problem. Gets time only once in a while.
Can you check to see if you already have a DNS server set when trying to start making a NTP request? Quote often the DNS is not immediately set on the first DHCP request and it may also be reset when WiFi is disabled.
Another option is to also check to see if your router supports replying to NTP requests. If so, then you could also try to make a NTP call to your gateway IP. This isn't a universal 'fix', but it may give results faster if powered-on-time matters.
Edit: Another idea... Could it be you try to resolve a DNS record for fetching the time which is using DNSSEC?
My immediate problem with my current project is solved by using the NTP server IP address instead of the hostname. I wrote a small sketch that uses gethostbyname() and it gets the IP address every time. I will not be doing any more testing of this problem - I am working on finishing my project.
It's interesting that this solved your issue. Do you by any chance have IPv6 enabled?
The Xfinity router has IPv6 enabled. There is no way to disable it.
You could try and call WiFi.enableIPv6()
before WiFi.begin()
and see if that improves anything? Is the IPv6 Link-Local only, or do you also have a global address?
It looks like you found the answer! Enabling IPv6 makes everything work as advertised. The router has both local and global IPv6 addresses.
Hmm this makes me wonder why it was not working. Maybe the DNS resolve did only return an AAAA record? But then, why?
Awesome! Could we consider this resolved?
@TD-er could be router specific thing or something that has changed in NTP/LwIP. Unfortunately I can not reproduce it here. Everything works as expected, regardless if I enable v6 in the router or not.
Maybe it returns V4 mapped into V6 address and NTP does not handle it?
As far as I am concerned, you can close the ticket. You might put a note somewhere about this issue, though. It had me tearing my hair out for awhile. Thanks...
we will keep an eye for similar issues
Board
DEVKIT V1, ESP32 Dev Module
Device Description
Clone ESP32 DEVKIT V1, Freenove ESP32-WROOM
Hardware Configuration
no
Version
v3.0.1
IDE Name
Arduino IDE
Operating System
Windows 11 and MACOS 14.5
Flash frequency
80 MHz
PSRAM enabled
no
Upload speed
921600
Description
Never gets time adjustment from BTP almost every time. Only once in a while successfully gets the time adjustment. Worked fine in version 2.0.17.
Sketch
Debug Message
Other Steps to Reproduce
Work fine in version 2.0.17 but not in 3.0 or above
I have checked existing issues, online documentation and the Troubleshooting Guide