Перезапуск платы по ватчдогу после сообщений snmpd о connection refused

[san]

У пользователя в сети спонтанно перезагружаются блоки по watchdog, в логах перед перезапуском имеются странные сообщения типа:
Nov 18 06:01:41 sw01 daemon.err snmpd[251]: connect: Connection refused

Нужно разобраться в чём причина и, если это зависит от нас, устранить.

---

Приведу цитаты из предыдущего обсуждения проблемы:

alx, [30.11.2022 12:29]
Я написал программу, посылающую SNMP запросы плате SW-01.
Пробовал послать 1000 запросов за 1 мс. Ничего плохого не произошло (нет ни перезагрузки, ни сообщений connection refused в логе).

Пробовал послать 1000 запросов за 1 секунду (один запрос каждую мс). Ничего плохого не произошло...

Похоже, что причина перезагрузки не связана с SNMP...

alx, [30.11.2022 16:03]
Похоже, что я был неправ.
Провел эксперимент: в swd в цикл, принимающий соединения, добавл задержку 100 мс (то есть он может принять не более 1 подключения за 100 мс). После этого передаю в плату 20 запросов SNMP с интервалом 1 мс. Результат - на все 20 запросов плата дает ответы. А я ожидал, что только 6 запросов будет обработано, остальные потеряются (сокету устанавливается размер очереди 5 - listen(sockfd, 5))...

Выходит, я не знаю, как добиться ошибки refused, и не знаю, почему она возникает.

man connect дает следующее объяснение этой ошибки:
ECONNREFUSED

A connect() on a stream socket found no one listening on the remote address.

В то же время man listen говорит про второй аргумент:
The backlog argument defines the maximum length to which the queue of pending connections for sockfd may grow. If a connection request arrives when the queue is full, the

client may receive an error with an indication of ECONNREFUSED or, if the underlying protocol supports retransmission, the request may be ignored so that a later reattempt
at connection succeeds.

alx, [30.11.2022 16:23]
Мне удалось получить сообщения connection refused только когда я закомментарил вызов listen().
Получается, что в реальной жизни такие сообщения могут возникнуть только при попытке соединения в период между вызоывми bind(), когда сокет реально создается, и listen()... При этом вызовы bind() и listen() в программе следуют непосредственно друг за другом...
Возможно, на момент старта swd система уже чем-то так загружена, что два последовательных вызова занимают существенное время?...

alx, [30.11.2022 19:01]
В логах видел несколько странностей.
Во-первых, прошивка в плате SW-01 устарела почти два года назад. Почему-то в ней давно (или никогда?) не обновляли ПО...

Еще там есть серия странных сообщений типа:
Nov 17 10:11:25 sw01 daemon.err swd[254]: transport.cpp:841: slot 16: Too big packet from tx queue (length = 2708648 bytes)
Это значит из очереди передачи вытащили сообщение с безумным значением длины. Непонятно, как такое возможно (и я никогда такого на практике не видел)...

Есть еще такое наблюдение. Сообщения Connection refused начинают появляться внезапно, иногда после многих часов "нормальной" работы. Ровно через 35 секунд после этого идет новая загрузка. Это очень похоже на период watchdot timer. Вероятно, по какой-то причине swd "падает", что ведет к перезагрузке. А Connection refused - это уже следствие того, что процесса, который раньше слушал сокет, больше нет.

Я провел эксперимент: загрузил snmpd запросами к плате, после чего убил swd сигналом SIGKILL. В результате получил в логе точную копию того, что прислал ты: сначала Got invalid response, потом Connection refused, а через 35 секунд - перезагрузка.

Мой вывод: сообщения Connection refused являются следствием падения swd по неизвестным причинам, с запросами SNMP напрямую не связанными.

alx, [30.11.2022 19:26]
Одному падению предшествовало странное самопроизвольное пропадание платы SM-02, менее через минуту после которого swd упал...

Многим (но не всем) падениям непосредственно предшествовал Alignment trap. Причем всегда на одной и той же инструкции...

san, [30.11.2022 19:30]
Понятно.
Для начала попрошу пользователя обновиться до актуальной версии и понаблюдать за работой блока снова.

[san]

Логи с трёх блоков в xchange\alx\Test_and_bugs\перезапуск_WD\ekb\

• Пользователь воспроизвёл проблему в swd-r2210 - смотри логи 172.16.114.12
• 172.16.25.30 - логи, которые смотрели ранее

[alx]

Replying to san:

У пользователя в сети спонтанно перезагружаются блоки по watchdog, в логах перед перезапуском имеются странные сообщения типа:
Nov 18 06:01:41 sw01 daemon.err snmpd[251]: connect: Connection refused

Такое сообщение означает, что принимающая сторона (процесс swd) не слушает сокет. Это довольно странно, так как пра старте swd создает сокет вызовом bind, и сразу вслед за ним выполняет listen(). Теоретически возможно, что попытка коннекта к сокету произошла в тот краткий промежуток времени, когда bind() уже создал сокет, а listen() еще не выполнился. Однако вероятность такого совпадения крайне мала. А уж попасть в эти "ворота" несколько раз вообще практически невероятно...

Есть другая возможность получить подобную ситуацию - если процесс swd завершился нештатно (например убит сигналом SIGKILL, SIGABT и т.п.). В этом случае swd не может удалить за собой свой сокет. По той же причине в описанном случае последует перезагрузка из-за срабатывания watchdog...

Нужно разобраться в чём причина и, если это зависит от нас, устранить.

Спонтанное срабатывание watchdog может возникать от того, что плата (а именно, ее процессор) чем-то настолько сильно загружена, что иногда не успевает вовремя выполнить сброс таймера. Другой возможной причины спонтанных срабатываний watchdog я представить не могу. Однако эта причина противоречит написанному выше - наличию сообщений "Connection refused"...

Предлагаю помониторить уровень загрузки CPU и сообщить, какова была величина загрузки непосредственно перед спонтанными перезагрузками.

Приведу цитаты из предыдущего обсуждения проблемы:

Если выше говорится о той же самой проблеме, обсуждение которой приведено ниже, то я считаю (на 99% уверен в этом), что перезагрузки по срабатыванию watchdog совсем не спонтанные, а вызваны некорректными завершениями процесса swd - см. написанное выше.

[san]

Если выше говорится о той же самой проблеме

Да, это всё происходит в сети одного пользователя.

спонтанные

Имелось в виду с точки зрения пользователя: он ничего не делал и тут...

вызваны некорректными завершениями процесса swd

Раз у пользователя довольно легко это воспроизводится, может быть сделаем специальную версию swd с выводомом в лог каких-то дополнительных сведений, которые помогут локализовать причину падения?

[alx]

В новом логе обнаружил новую странность - много сообщений о том, что swd не смог распарсить ответ платы RP-650 (на самом деле двух разных плат RP-650) на запрос. Могу предположить, что падения swd как-то связаны с получением некорректных ответов от PR-650, которые swd недостаточно тщательно валидирует.

Для исследования этой версии (а также для выявления других возможных причин падений swd) предлагаю увеличить подробность лога swd добавлением ключа "-l7" в переменную ARGS в файле /etc/init.d/swd.sh платы SW-01. Сразу предупреждаю, что с таким уровнем подробности логи заполняются быстро, поэтому желательно забрать их из платы насколько возможно скорее после возникновения перезагрузки.

[alx]

Replying to san:

Раз у пользователя довольно легко это воспроизводится, может быть сделаем специальную версию swd с выводомом в лог каких-то дополнительных сведений, которые помогут локализовать причину падения?

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

[alx]

Еще можно предложить такой вариант: в /etc/init.d/swd.sh после "start)" вставить строку

ulimit -c unlimited

Тогда при падении swd должен оставить core-файл (скорее всего в корне). Этот файл можно загрузить в отладчик и попытаться получить stack trace. Прадва практика показывает что получить адекватный stack trace в подобных случаях удается очень редко...

Но хотя бы должно быть видно, каким сигналом был убит процесс...