Ликбез по поведению dhcp клиента

[r13]

@vst

Нужна помощь с объяснением поведения DHCP клиента

Смотрю клиента на wisp интерфейсе(Ultra 2.16.D.8.0-2),

время аренды 72 часа, но при этом у клиента идет какая-то ежечасная активность в которой  периодически что-то идет не так и происходит сброс соединения сильно раньше полуаренды

Что это за активность такая?

Пример, в 3:20 что-то пошло не так:

Скрытый текст

[I] Nov 26 02:29:56 ndhcpc: WifiMaster0/WifiStation0: dispatch all, res: 0
[I] Nov 26 02:29:56 ndhcpc: WifiMaster0/WifiStation0: terminate: 0
[I] Nov 26 02:29:56 ndhcpc: WifiMaster0/WifiStation0: timer 130046.580707329, now 25647.280396649
[I] Nov 26 02:29:56 ndhcpc: WifiMaster0/WifiStation0: timeout 130046.580707329, now 25647.280560769
[I] Nov 26 02:29:56 ndhcpc: WifiMaster0/WifiStation0: set timeout 3600000 ms
[I] Nov 26 02:29:56 ndhcpc: WifiMaster0/WifiStation0: set fd: 6, events: 0x39, revents: 0x0
[I] Nov 26 02:29:56 ndhcpc: WifiMaster0/WifiStation0: start poll: 1, 3600000, 0x7337c8
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: poll return error!
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: dispatch all, res: -1
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: signal callback: received signal: Terminated (15)
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: del socket 0x733050
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: add sock 6, flags: 0x2, handler: 0x40de8c, data: 0x733098
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: add socket 0x733050
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: terminate: 0
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: timer 130046.580707329, now 28672.333610439
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: timeout 130046.580707329, now 28672.333710493
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: set timeout 3600000 ms
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: set fd: 6, events: 0x3c, revents: 0x0
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: start poll: 1, 3600000, 0x7337c8
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: dispatch all, res: 1
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: terminate: 0
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: timer 130046.580707329, now 28672.336558236
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: disp fd: 6, events: 0x3c, revents: 0x4
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: socket write event
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: DHCP client state is RELEASING
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: sending RELEASE for 192.168.1.6 to 192.168.1.1
[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: starting client script with reason "leasefail"

 

[slomblobov]

В селфтесте 3 рестарта DHCP, вызванные отправкой сигнала SIGTERM, первые два связаны с посылкой команды dhcp client debug.

Цитата

[I] Nov 25 19:28:08 ndm: Core::Scgi::Auth: opened session WUXTPMROXWEXFUDW for user ***.
[I] Nov 25 19:28:31 ndm: Dhcp::Client: WifiMaster0/WifiStation0 DHCP client debug enabled.

 

Цитата

[I] Nov 25 19:29:33 ndm: Core::Authenticator: "admin" logged in, SSH authenticated.
[I] Nov 25 19:29:44 ndhcpc: WifiMaster0/WifiStation0: signal callback: received signal: Terminated (15)
[I] Nov 25 19:29:44 ndm: Dhcp::Client: WifiMaster0/WifiStation0 DHCP client debug enabled.

Третий рестарт произошел по неизвестной причине:

Цитата

[I] Nov 26 03:20:21 ndhcpc: WifiMaster0/WifiStation0: signal callback: received signal: Terminated (15)
[I] Nov 26 03:20:22 kernel: Wi-Fi client: probe request: SSID=momwifi, BSSID=00:13:33:81:0a:e9
[I] Nov 26 03:20:22 kernel: Wi-Fi client: probe response: SSID=momwifi, BSSID=00:13:33:81:0a:e9

Срабатывает какой-то триггер и ndm перезапускает DHCP. Это может быть связано с изменением линка, настроек устройства.

Пока сделаю следующее: не перезапускать DHCP если состояние debug не изменилось.

[r13]

11 минуту назад, vst сказал:

В селфтесте 3 рестарта DHCP, вызванные отправкой сигнала SIGTERM, первые два связаны с посылкой команды dhcp client debug.

 

Третий рестарт произошел по неизвестной причине:

Срабатывает какой-то триггер и ndm перезапускает DHCP. Это может быть связано с изменением линка, настроек устройства.

Пока сделаю следующее: не перезапускать DHCP если состояние debug не изменилось.

Да этот в 3 часа  как раз и не ясен, по логу вроде все чисто и тем не менее идут рестарты периодически

Стстусы в телегу прилетают.

Что то еще могу проверить со своей стороны? Может сам интерфейс тоже в debug перевести?

Edited November 27, 2020 by r13

[slomblobov]

Давайте ещё несколько селфтестов посмотрим, может прояснится ситуация. Далее будем расширять отладку.

[r13]

8 часов назад, vst сказал:

Давайте ещё несколько селфтестов посмотрим, может прояснится ситуация. Далее будем расширять отладку.

Есть селфтест подревнее, еще без отладки dhcp клиета + pcap dhcp клиента

События:

Nov 24 15:49:13

Nov 25 02:23:49

Nov 25 06:06:24