supla-espresif-esp restarty w wersji 2.8.20 - 2.8.21

[lukfud]

ta 10.0.4.1, tak, 10.0.0.1 nie.

Jakiegoś tunelu VPN nie masz zestawionego na sieci 10.0.0.0/8?
No coś ewidentnie podrzuca do ESP niewłaściwe dane bramy, co powoduje restart połączenia (nie moze być zrealizowane przez Tą bramę) i poszukiwanie nowej dzierżawy, tym razem właściwej, do momentu próby odnowienia dzierżawy, gdzie znowu fakeDHCP jest usłużny.

Nie mam nic w tej podsieci. Kolejny test na innej podsieci.

Code: Select all

22:21:40.413 -> connected with supla_dev, channel 1
22:21:40.413 -> dhcp client start...
22:21:40.460 -> WiFi Status: 1
22:21:43.405 -> ip:25.25.25.28,mask:255.255.255.0,gw:25.25.25.25
22:21:43.452 -> WiFi Status: 5
22:21:43.452 -> supla_esp_devconn_resolvandconnect
22:21:43.452 -> Disconnect 6
22:21:43.452 -> Resolv svr30.supla.org
22:21:43.452 -> supla_esp_devconn_dns__found
22:21:43.452 -> Disconnect 6
22:21:43.452 -> please start sntp first !
22:21:43.506 -> client handshake start.
22:21:43.606 -> client handshake ok!
22:21:43.606 -> supla_esp_devconn_connect_cb
22:21:43.706 -> Registered and ready.
22:21:43.706 -> Free heap size: 18008
22:21:50.372 -> pm open,type:2 0
22:26:42.210 -> ip:25.25.25.28,mask:255.0.0.0,gw:25.0.0.1
22:26:45.272 -> sproto send count: 39 result: -5
22:26:59.211 -> ACTIVITY TIMEOUT
22:26:59.211 -> Disconnect 4
22:26:59.211 -> WiFi - Connecting...
22:26:59.211 -> Disconnected
22:26:59.274 -> supla_esp_devconn_disconnect_cb
22:26:59.274 -> state: 5 -> 0 (0)
22:26:59.274 -> rm 0
22:26:59.274 -> pm close 7
22:26:59.412 -> WiFi Status: 1
22:26:59.412 -> Disconnected
22:27:01.217 -> Disconnect 6
22:27:01.217 -> WiFi - Connecting...
22:27:01.217 -> scandone
22:27:01.217 -> Disconnected
22:27:01.364 -> scandone
22:27:01.364 -> state: 0 -> 2 (b0)
22:27:01.364 -> state: 2 -> 3 (0)
22:27:01.364 -> state: 3 -> 5 (10)
22:27:01.364 -> add 0
22:27:01.364 -> aid 1
22:27:01.364 -> cnt 
22:27:01.417 -> 
22:27:01.417 -> connected with supla_dev, channel 1
22:27:01.417 -> dhcp client start...
22:27:04.272 -> ip:25.25.25.28,mask:255.255.255.0,gw:25.25.25.25
22:27:04.425 -> WiFi Status: 5
22:27:04.425 -> supla_esp_devconn_resolvandconnect
22:27:04.425 -> Disconnect 6
22:27:04.425 -> Resolv svr30.supla.org
22:27:04.425 -> supla_esp_devconn_dns__found
22:27:04.425 -> Disconnect 6
22:27:04.472 -> please start sntp first !
22:27:04.472 -> client handshake start.
22:27:04.626 -> client handshake ok!
22:27:04.626 -> supla_esp_devconn_connect_cb
22:27:04.773 -> Registered and ready.
22:27:04.773 -> Free heap size: 17720
22:27:11.392 -> pm open,type:2 0

[Goral64]

Na Twoim miejscu testowałbym na sieciach prywatnych (nieroutowalnych w internecie).

Code: Select all

Klasa: 	Zakres adresów publicznych: 	Maska sieci: 	Notacja CIDR:
A 	10.0.0.0 - 10.255.255.255 	255.0.0.0 	10.0.0.0/8
B 	172.16.0.0 - 172.31.255.255 	255.240.0.0 	172.16.0.0/12
C 	192.168.0.0 - 192.168.255.255 	255.255.0.0 	192.168.0.0/16

[lukfud]

Na Twoim miejscu testowałbym na sieciach prywatnych (nieroutowalnych w internecie).

Code: Select all

Klasa: 	Zakres adresów publicznych: 	Maska sieci: 	Notacja CIDR:
A 	10.0.0.0 - 10.255.255.255 	255.0.0.0 	10.0.0.0/8
B 	172.16.0.0 - 172.31.255.255 	255.240.0.0 	172.16.0.0/12
C 	192.168.0.0 - 192.168.255.255 	255.255.0.0 	192.168.0.0/16

Nie ma to znaczenia.

Code: Select all

22:46:01.096 -> connected with supla_dev, channel 1
22:46:01.096 -> dhcp client start...
22:46:03.657 -> ip:192.168.25.27,mask:255.255.255.0,gw:192.168.25.25
22:46:03.704 -> WiFi Status: 5
22:46:03.704 -> supla_esp_devconn_resolvandconnect
22:46:03.704 -> Disconnect 6
22:46:03.757 -> Resolv svr30.supla.org
22:46:03.757 -> supla_esp_devconn_dns__found
22:46:03.757 -> Disconnect 6
22:46:03.757 -> please start sntp first !
22:46:03.757 -> client handshake start.
22:46:03.904 -> client handshake ok!
22:46:03.904 -> supla_esp_devconn_connect_cb
22:46:04.004 -> Registered and ready.
22:46:04.004 -> Free heap size: 18016
22:46:11.079 -> pm open,type:2 0
22:50:58.405 -> ip:192.168.25.27,mask:255.255.255.0,gw:192.168.25.1
22:50:59.963 -> sproto send count: 39 result: -5
22:51:13.901 -> ACTIVITY TIMEOUT
22:51:13.901 -> Disconnect 4
22:51:13.901 -> WiFi - Connecting...
22:51:13.901 -> Disconnected
22:51:13.901 -> supla_esp_devconn_disconnect_cb
22:51:13.948 -> state: 5 -> 0 (0)
22:51:13.948 -> rm 0
22:51:13.948 -> pm close 7
22:51:14.048 -> scandone
22:51:14.048 -> state: 0 -> 2 (b0)
22:51:14.048 -> state: 2 -> 3 (0)
22:51:14.048 -> state: 3 -> 5 (10)
22:51:14.048 -> add 0
22:51:14.048 -> aid 1
22:51:14.048 -> cnt 
22:51:14.101 -> 
22:51:14.101 -> connected with supla_dev, channel 1
22:51:14.101 -> dhcp client start...
22:51:14.101 -> WiFi Status: 1
22:51:14.101 -> Disconnected
22:51:15.906 -> Disconnect 6
22:51:15.906 -> WiFi - Connecting...
22:51:15.906 -> state: 5 -> 0 (0)
22:51:15.906 -> rm 0
22:51:15.906 -> Disconnected
22:51:16.053 -> scandone
22:51:16.053 -> state: 0 -> 2 (b0)
22:51:16.053 -> state: 2 -> 3 (0)
22:51:16.053 -> state: 3 -> 5 (10)
22:51:16.053 -> add 0
22:51:16.053 -> aid 1
22:51:16.053 -> cnt 
22:51:16.122 -> 
22:51:16.122 -> connected with supla_dev, channel 1
22:51:16.122 -> dhcp client start...
22:51:18.914 -> ip:192.168.25.27,mask:255.255.255.0,gw:192.168.25.25
22:51:18.914 -> WiFi Status: 5
22:51:18.914 -> supla_esp_devconn_resolvandconnect
22:51:18.914 -> Disconnect 6
22:51:18.914 -> Resolv svr30.supla.org
22:51:18.914 -> supla_esp_devconn_dns__found
22:51:18.914 -> Disconnect 6
22:51:18.914 -> please start sntp first !
22:51:18.955 -> client handshake start.
22:51:19.077 -> client handshake ok!
22:51:19.077 -> supla_esp_devconn_connect_cb
22:51:19.215 -> Registered and ready.
22:51:19.215 -> Free heap size: 17888
22:51:26.034 -> pm open,type:2 0

[Goral64]

@lukfud w sumie widać powtarzalny schemat...
Startuje klient DHCP na ESP i pobiera prawidłowe dane sieci z serwera DHCP, łączy się i wszystko jest OK. W połowie czasu dzierżawy nagle ma złe dane sieci co do maski i bramy... Dostał je z serwera DHCP? Raczej nie... źle odczytał prawidłowe dane czy uległy modyfikacji te co sobie zapisał 5 minut temu i chciał się nimi posłużyć ale bezskutecznie, co doprowadziło do reconnecta i ponownego uruchomienia klienta DHCP, który z serwera uzyskał właściwe dane??
Przydałby się sniffer w tym segmencie sieci, który podsłuchałby "rozmowę" ESP z serwerem DHCP.

[Goral64]

To jeszcze pytanie do wszystkich, u których działa
Czy wasza brama w podsieci ma adres zakończony na ostatnim oktecie wartością 1 czyli x.x.x.1?

[Goral64]

Schemat jest taki, że ESP w tym przykładzie przy ustalaniu adresu po włączeniu ustawia IP, maskę i bramę zgodnie z tym co otrzymał z serwera DHCP.
Jednak przy odnawianiu dzierżawy wygląda na to, że ignoruje to co wysyła mu serwer DHCP, tylko po potwierdzeniu ESP buduje sobie domyślną maskę dla używanego IP i tym samym domyślną bramę, czyli ostatni oktet = 1.
Jako, że dzieje się to tylko na jednym urządzeniu to wygląda o na jakiś bug w oprogramowaniu klienta DHCP na ESP.

[lukfud]

Po testach mogę stwierdzić, że jeśli adresem sieci nie jest 192.168.0.0 i brama nie jest 1 to esp zrywa połączenie.
Jest tak na minirowie i na testowym esp. Moduły na SupaDevice stabilne na każdej adresacji.

[lesny8]

Ja mam bramę 192.168.100.1 i działa

[lukfud]

Zobacz jak się zachowuje 2.7.x.

Podrzucisz mi jakąś binarkę?

[Goral64]

Po testach mogę stwierdzić, że jeśli adresem sieci nie jest 192.168.0.0 i brama nie jest 1 to esp zrywa połączenie.

Napisałem wyżej jaki mechanizm za to odpowiada i myślę, że to błąd w kliencie DHCP dla ESP.
192.168.0.0/24 jest podsiecią klasy C i domyślna maska to 255.255.255.0 a domyślna brama to x.x.x.1 dla tej podsieci.

Przy adresie podsieci klasy A, np. 10.0.4.0/24 domyślna maska to 255.0.0.0 a domyślna brama to x.0.0.1.

Jeśli użyjesz jakikolwiek adres, także publiczny z zakresu 192.0.0.0 - 223.255.255.255 i brama będzie miała ostatni oktet 1 to też powinno ci działać bez rozłączania.