3.9 Beta 1-2: работа режима проверки TLS с 1211 и модема T77W676

[dimon27254]

Обнаружил странное поведение KN-1211 на прошивках 3.9 Beta 1-2:

Подключен модем T77W676, используется в качестве основного подключения, резервное подключение IPoE.
Суть проблемы: при включенной TLS-проверке порта TCP в основном подключении через некоторое время работы пропадает доступ к кинетику через веб-интерфейс и мобильное приложение. 

Проявляется так: вхожу в веб-интерфейс кинетика (как по локальному ip-адресу, так и через доменное имя KeenDNS), выполняю авторизацию. После нажатия кнопки "войти", страница авторизации зависает. В консоли разработчика Chrome увидел, что не приходит ответ на запрос "http://ip/rci", в результате чего не происходит дальнейших "движений". 
Если страницу перезагрузить, отобразится пустой dashboard, а в консоли также показывается, что нет ответа на запрос "http://ip/rci".
В мобильном приложении показывается, что роутер не в сети, но также и не приходит уведомление о том, что он офлайн.
При этом, до него можно "достучаться" через telnet, но и там все работает некорректно: например, я не могу просмотреть running-config, self-test, или же, например, получить вывод команд вида "show ping-check", "show interface". После ввода нет ответа, а через некоторое время соединение разрывается. 
Несмотря на это, доступен просмотр лога путем ввода команды "show log". Введя в адресной строке браузера запрос вида "http://ip/ci/log.txt", удалось выгрузить лог. Обнаружил повторяющиеся записи вида:

[W] Nov 18 17:41:21 ndm: Timer: unable to alarm "Network::Interface::LinkDetector" for 7350 seconds. 
[W] Nov 18 17:41:21 ndm: Timer: "Ping-check profile queue" (26866) backtrace: 
[W] Nov 18 17:41:21 ndm: Timer:   no backtrace available. 
[W] Nov 18 17:41:26 ndm: Event::Forwarder: unable to send "Event::Type::Neighbour" to "Network::Interface::AccessPoint" for 7350 seconds. 
[W] Nov 18 17:41:26 ndm: Event::Forwarder: "Ping-check profile queue" (26866) backtrace: 
[W] Nov 18 17:41:26 ndm: Event::Forwarder:   no backtrace available. 
[W] Nov 18 17:41:43 ndm: Core::Watchdog: Ping-check profile queue holds INTERFACE_REPO (62) lock 7372 seconds acquired Nov 18 15:38:51. 
[W] Nov 18 17:41:43 ndm: Core::Watchdog: "Ping-check profile queue" (26866) backtrace: 
[W] Nov 18 17:41:43 ndm: Core::Watchdog:   no backtrace available. 

При этом, self-test схожим методом выгрузить не удается: некоторое время нет ответа, а затем веб-сервер кинетика выдает ошибку 504.
Несмотря на длинную "простыню" в логе, неработающий веб и мобильную часть, нормально работает доступ к интернету по проводу и Wi-Fi, отрабатываются все правила межсетевого экрана, нет проблем с доступом к веб-приложениям через KeenDNS.
Вывести кинетик из такого состояния удается с помощью команды "system reboot" в telnet.

После перезагрузки, доступ к веб-интерфейсу и через мобильное приложение восстанавливается до следующего такого сбоя.

Изменения хоста проверки не решает проблему, но если изменить тип проверки в ping-check на icmp, все вышеописанное перестает проявляться.

В поддержке с этой проблемой мне ничем не смогли помочь, закрыли запрос после того, как я написал, что изменение типа проверки решает данную ситуацию.

На KN-3010 с 3.9 Beta 1-2, где основное подключение PPPoE и на нём включена TLS-проверка порта, все работает стабильно неделями.

В скрытом сообщении прикрепил файлы, которые отправлял в поддержку: логи с "отвалами" и "чистый" self-test, снятый после перезагрузки. Эти файлы были сохранены при установленном компоненте IPv6, так как изначально предполагал, что проблема в нем. Но и удаление этого компонента проблему не решило, поэтому добавил ещё сегодняшний лог и "чистый" self-test без него.

Предполагаю, что полученных данных может оказаться мало для понимания источников проблемы, в связи с чем поддержка и не смогла помочь, но какими еще способами можно снять диагностику при таких "глюках"?

[hellonow]

@dimon27254 с ходу воспроизвести не получилось, возможно имеется зависимость от оператора связи или модема.

Попробовал указать проверку 443 порта и хэндшейк проходит:
 

I [Nov 18 20:16:09] ndm: PingCheck::Profile: "_WEBADMIN_UsbQmi0": interface "UsbQmi0" address 100.70.144.215 gw 100.70.144.216: success count 86/5.
I [Nov 18 20:16:12] ndm: PingCheck::Profile: "_WEBADMIN_UsbQmi0": Check interface UsbQmi0, address 100.70.144.215, gw 100.70.144.216.
I [Nov 18 20:16:12] ndm: PingCheck::Profile: "_WEBADMIN_UsbQmi0": install routes to peers to table 11.
I [Nov 18 20:16:12] ndm: PingCheck::Profile: "_WEBADMIN_UsbQmi0": TLS handshake check of ya.ru.
I [Nov 18 20:16:12] ndm: PingCheck::Profile: "_WEBADMIN_UsbQmi0": connecting to 87.250.250.242:443.
I [Nov 18 20:16:12] ndm: Io::TcpSocket: connected to 87.250.250.242:443.

Если указать выше интервал? Другой домен, например google.com?
 

ping-check profile _WEBADMIN_UsbQmi0
    host ya.ru
    port 443
    update-interval 10
    mode tls
    max-fails 5

Ситуация сохранится?

 В других self-test файлах в логе фиксируется, что домен не резолвится:
 

[W] Nov 14 20:31:43 ndm: PingCheck::Profile: "_WEBADMIN_UsbQmi0": failed to resolve "ya.ru". 

Попробуйте настроить еще работу DNS по протоколу DoT DoH - https://help.keenetic.com/hc/ru/articles/360007687159, чтобы исключить проблему резолвинга.

[dimon27254]

5 часов назад, hellonow сказал:

 с ходу воспроизвести не получилось

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

 

5 часов назад, hellonow сказал:

Если указать выше интервал? Другой домен, например google.com?

Пока что только увеличил интервал и порог срабатывания на ya.ru. Буду наблюдать за поведением.
Короткий интервал и малое количество попыток для срабатывания устанавливал из-за того, что у Мегафона в моей местности перегружены окружающие базовые станции, и бывают моменты, когда интернет может не работать вообще в течение 20-40 секунд. При такой ситуации само подключение модема к сети не рвется, уровень связи остается на том же уровне, просто нет доступа к интернету. В таком случае, кинетик достаточно быстро переключается на IPoE, одновременно с этим перезагружая модем по питанию для переподключения.

 

5 часов назад, hellonow сказал:

В других self-test файлах в логе фиксируется, что домен не резолвится

Но стоит отметить, что домен не резолвится только при загрузке кинетика. Во вчерашнем self-test это произошло, когда еще не был получен адрес через IPoE, а модем еще не инициализировался. В этот момент времени оба подключения еще были недоступны, соответственно, и нет возможности выполнить резолвинг.

В self-test, снятом 28.10 и логе от 30.10 это также произошло при первой загрузке, когда оба подключения еще недоступны.

Затем это же произошло сразу же после получения адреса через IPoE, в тот же момент времени:

[I] Oct 26 22:14:47 ndm: Dhcp::Client: configuring interface ISP. 
[I] Oct 26 22:14:47 ndm: Network::Interface::Ip: "FastEthernet0/Vlan2": IP address is 192.168.0.2/24. 
[I] Oct 26 22:14:47 ndm: Dhcp::Client: obtained IP address 192.168.0.2/24. 
[I] Oct 26 22:14:47 ndm: Dhcp::Client: interface "ISP" is global, priority 700. 
[I] Oct 26 22:14:47 ndm: Dhcp::Client: adding a default route via 192.168.0.1. 
[I] Oct 26 22:14:47 ndm: Dhcp::Client: adding name server 192.168.0.1. 
[I] Oct 26 22:14:47 ndm: Dns::Manager: name server 192.168.0.1 added, domain (default). 
[I] Oct 26 22:14:47 ndm: Network::InterfaceFlusher: flushed conntrack and route cache. 
[W] Oct 26 22:14:47 ndm: PingCheck::Profile: "_WEBADMIN_UsbQmi0": failed to resolve "yandex.ru". 

Но далее по логам такой ошибки больше не появляется.

[dimon27254]

Спустя 11 дней снова словил "отвал".

За это время обновился до 3.9.0, а также экспериментировал с настройками:

Сначала увеличил на хосте ya.ru интервал до 5 секунд. Посмотрел в течение 5 дней, все было стабильно.
Затем попробовал вернуть старый интервал в 3 секунды, но уже с хостом google.com. Спустя 5 дней никаких проблем также не заметил.
Вчера снова установил хост ya.ru и интервал в 3 секунды. Сегодня сработал ping-check, кинетик перезагрузил модем. Сразу же зашел в веб-интерфейс, увидел, что модем подключился к очень отдаленной БС с слабым сигналом. Через небольшое время веб и мобильная часть отвалились.

Лог прикрепил.

[dimon27254]

В попытках выяснить причину, включил на кинетике режим отладки и выгрузку логов на syslog сервер. С момента написания последнего сообщения, только сегодня удалось снова словить "отвал".

В скрытом файле прикрепил лог в отрезке времени с 13:20 до 13:50 сегодняшнего дня. В этом промежутке времени можно заметить, что периодически проверка соединения завершалась неудачей. Затем последняя попытка была в 13:31:58, но она никак не завершилась, в отличие от прежних, после чего и посыпались повторяющиеся записи, подобные выложенным в первом сообщении. В то же время отвалился и веб с мобильным приложением.

При необходимости, могу выложить полный лог с момента запуска режима отладки.

[dimon27254]

Долгое время проблема не проявлялась, за это время с 3.9.0 обновлялся на каждую выходящую версию, но сегодня снова столкнулся в актуальной 4.0 Alpha 3. Поведение идентично всем предыдущим случаям.

[dimon27254]

После выхода 4.0 Alpha 4, перешел на неё. Сегодня ночью снова все "сломалось", весь лог забит повторяющимися записями из первого сообщения вопроса. В этот раз перестал работать и KeenDNS, выдавая ошибку 503 Not Reachable.

 

[hellonow]

@dimon27254 как обстоят дела на версии ПО 4.0.4?

[dimon27254]

@hellonow на последних 4.0 такого поведения мной не замечено.

Исправление NDM-2516 (вошло 4.0 Alpha 6) случаем не относилось к этой проблеме? По ссылке из changelog упоминался схожий случай:

Как я понимаю, в нем также проблема была из-за TLS-проверки в ping-check.