Jump to content
  • 0
OmegaTron

Statistics collector thread holds ULTIMATE (255) lock xxx seconds acquired

Question

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

2018-02-11 15:11:08    User.Warning    192.168.0.1    Feb 11 15:10:05 ndm: Core::Watchdog: Statistics collector thread holds ULTIMATE (255) lock 24780 seconds acquired Feb 11 08:17:05.
2018-02-11 15:11:08    User.Warning    192.168.0.1    Feb 11 15:10:05 ndm: Core::Watchdog: Timer holds CORE (2) lock 24775 seconds acquired Feb 11 08:17:10.
2018-02-11 15:11:08    User.Warning    192.168.0.1    Feb 11 15:10:06 ndm: Core::Watchdog: Interface Bridge0 neighbour explorer holds ARP_TABLE (57) lock 24774 seconds acquired Feb 11 08:17:11.
2018-02-11 15:11:08    User.Warning    192.168.0.1    Feb 11 15:10:06 ndm: Core::Watchdog: Event sender holds CORE (2) lock 8226 seconds acquired Feb 11 12:52:59.
2018-02-11 15:12:07    User.Warning    192.168.0.1    Feb 11 15:11:05 ndm: Core::Watchdog: Statistics collector thread holds ULTIMATE (255) lock 24840 seconds acquired Feb 11 08:17:05.
2018-02-11 15:12:07    User.Warning    192.168.0.1    Feb 11 15:11:05 ndm: Core::Watchdog: Timer holds CORE (2) lock 24835 seconds acquired Feb 11 08:17:10.
2018-02-11 15:12:07    User.Warning    192.168.0.1    Feb 11 15:11:06 ndm: Core::Watchdog: Interface Bridge0 neighbour explorer holds ARP_TABLE (57) lock 24834 seconds acquired Feb 11 08:17:11.
2018-02-11 15:12:08    User.Warning    192.168.0.1    Feb 11 15:11:06 ndm: Core::Watchdog: Event sender holds CORE (2) lock 8286 seconds acquired Feb 11 12:52:59.
2018-02-11 15:13:07    User.Warning    192.168.0.1    Feb 11 15:12:05 ndm: Core::Watchdog: Statistics collector thread holds ULTIMATE (255) lock 24900 seconds acquired Feb 11 08:17:05.
2018-02-11 15:13:07    User.Warning    192.168.0.1    Feb 11 15:12:05 ndm: Core::Watchdog: Timer holds CORE (2) lock 24895 seconds acquired Feb 11 08:17:10.
2018-02-11 15:13:07    User.Warning    192.168.0.1    Feb 11 15:12:06 ndm: Core::Watchdog: Interface Bridge0 neighbour explorer holds ARP_TABLE (57) lock 24894 seconds acquired Feb 11 08:17:11.
2018-02-11 15:13:08    User.Warning    192.168.0.1    Feb 11 15:12:06 ndm: Core::Watchdog: Event sender holds CORE (2) lock 8346 seconds acquired Feb 11 12:52:59.
2018-02-11 15:14:07    User.Warning    192.168.0.1    Feb 11 15:13:05 ndm: Core::Watchdog: Statistics collector thread holds ULTIMATE (255) lock 24960 seconds acquired Feb 11 08:17:05.
2018-02-11 15:14:07    User.Warning    192.168.0.1    Feb 11 15:13:05 ndm: Core::Watchdog: Timer holds CORE (2) lock 24955 seconds acquired Feb 11 08:17:10.
2018-02-11 15:14:07    User.Warning    192.168.0.1    Feb 11 15:13:06 ndm: Core::Watchdog: Interface Bridge0 neighbour explorer holds ARP_TABLE (57) lock 24954 seconds acquired Feb 11 08:17:11.
2018-02-11 15:14:08    User.Warning    192.168.0.1    Feb 11 15:13:06 ndm: Core::Watchdog: Event sender holds CORE (2) lock 8406 seconds acquired Feb 11 12:52:59.
2018-02-11 15:15:06    User.Warning    192.168.0.1    Feb 11 15:14:05 ndm: Core::Watchdog: Statistics collector thread holds ULTIMATE (255) lock 25020 seconds acquired Feb 11 08:17:05.
2018-02-11 15:15:07    User.Warning    192.168.0.1    Feb 11 15:14:05 ndm: Core::Watchdog: Timer holds CORE (2) lock 25015 seconds acquired Feb 11 08:17:10.
2018-02-11 15:15:07    User.Warning    192.168.0.1    Feb 11 15:14:06 ndm: Core::Watchdog: Interface Bridge0 neighbour explorer holds ARP_TABLE (57) lock 25014 seconds acquired Feb 11 08:17:11.
2018-02-11 15:15:08    User.Warning    192.168.0.1    Feb 11 15:14:06 ndm: Core::Watchdog: Event sender holds CORE (2) lock 8466 seconds acquired Feb 11 12:52:59.
2018-02-11 15:16:06    User.Warning    192.168.0.1    Feb 11 15:15:05 ndm: Core::Watchdog: Statistics collector thread holds ULTIMATE (255) lock 25080 seconds acquired Feb 11 08:17:05.
2018-02-11 15:16:06    User.Warning    192.168.0.1    Feb 11 15:15:05 ndm: Core::Watchdog: Timer holds CORE (2) lock 25075 seconds acquired Feb 11 08:17:10.
2018-02-11 15:16:07    User.Warning    192.168.0.1    Feb 11 15:15:06 ndm: Core::Watchdog: Interface Bridge0 neighbour explorer holds ARP_TABLE (57) lock 25074 seconds acquired Feb 11 08:17:11.
2018-02-11 15:16:07    User.Warning    192.168.0.1    Feb 11 15:15:06 ndm: Core::Watchdog: Event sender holds CORE (2) lock 8526 seconds acquired Feb 11 12:52:59.
2018-02-11 15:17:07    User.Warning    192.168.0.1    Feb 11 15:16:05 ndm: Core::Watchdog: Statistics collector thread holds ULTIMATE (255) lock 25140 seconds acquired Feb 11 08:17:05.
2018-02-11 15:17:07    User.Warning    192.168.0.1    Feb 11 15:16:05 ndm: Core::Watchdog: Timer holds CORE (2) lock 25135 seconds acquired Feb 11 08:17:10.
2018-02-11 15:17:07    User.Warning    192.168.0.1    Feb 11 15:16:06 ndm: Core::Watchdog: Interface Bridge0 neighbour explorer holds ARP_TABLE (57) lock 25134 seconds acquired Feb 11 08:17:11.
2018-02-11 15:17:08    User.Warning    192.168.0.1    Feb 11 15:16:06 ndm: Core::Watchdog: Event sender holds CORE (2) lock 8586 seconds acquired Feb 11 12:52:59.
2018-02-11 15:18:06    User.Warning    192.168.0.1    Feb 11 15:17:05 ndm: Core::Watchdog: Statistics collector thread holds ULTIMATE (255) lock 25200 seconds acquired Feb 11 08:17:05.
2018-02-11 15:18:06    User.Warning    192.168.0.1    Feb 11 15:17:05 ndm: Core::Watchdog: Timer holds CORE (2) lock 25195 seconds acquired Feb 11 08:17:10.

 

Увидев строки "core" и "Watchdog" подумал, что роутер основательно залип - так и оказалось. Telnet не отвечал, ssh из комплекта entware не отвечал (соединение вроде устанавливалось, но залипало и висело), коннекта к интернету не было. Единственное, что хоть что-то отвечало - это веб-фейс. После авторизации он отображался, но на динамически обновляемых блоках висел прогресс-бар, который крутился бесконечно. Спустя пару минут в веб-фейсе появлялись ошибки "error: not responded" (или типа того) и восклицательный знак в углу, а в syslog валилось

2018-02-11 15:33:51    Daemon.Error    192.168.0.1    Feb 11 15:32:50 keenetic_omni nginx: (conn: *1406) upstream timed out (145: Unknown error) while reading response header from upstream, client: 192.168.0.245
2018-02-11 15:33:51    Daemon.Error    192.168.0.1    Feb 11 15:32:50 keenetic_omni nginx: (conn: *1400) upstream timed out (145: Unknown error) while reading response header from upstream, client: 192.168.0.245

Попытался ребутнуть роутер через CI, получил ответ

<packet>
    <response id="0">
        <message>rebooting the system</message>
    </response>
</packet>

но ребута не случилось (выждал минут 5) и роутер пришлось дёргать по питанию. После включения сообразил, что можно было дёрнуть через CI лог, но было уже поздно :( Сегодня займусь установкой syslog-ng (или как его там), надоели уже такие случаи.

 

Теперь вопрос - что это могло быть ?

Share this post


Link to post
Share on other sites

20 answers to this question

Recommended Posts

  • 0

Нужен весь вывод syslog, в том числе и то, что случилось 25 тысяч секунд до этого куска.

А версия  прошивки-то хоть какая?

Share this post


Link to post
Share on other sites
  • 0
55 минут назад, Le ecureuil сказал:

Нужен весь вывод syslog, в том числе и то, что случилось 25 тысяч секунд до этого куска.

Комп до этого был выключен - эти цикличные блоки данных всё, что насыпалось в syslog. Адреса log.txt я на тот момент не знал (сейчас уже поглядел), а через CI/RCI дёрнуть лог не сообразил. Хотя я сомневаюсь, что он вообще бы отдался при такой клинике - там get/post запросы проходили с минутными задержками.

55 минут назад, Le ecureuil сказал:

А версия  прошивки-то хоть какая?

Дык в подписи - 2.10.C.2.0-4

Ещё момент - в entware кроме базового dropbear'a никакого софта нет, равно как и скриптов в автозагрузке. Руки до этого не дошли.

На момент возникновения проблемы роутер никто не эксплуатировал и о висяке я узнал лишь постфактум.

Edited by OmegaTron

Share this post


Link to post
Share on other sites
  • 0
4 минуты назад, OmegaTron сказал:

Дык в подписи - 2.10.C.2.0-4

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

Share this post


Link to post
Share on other sites
  • 0
1 минуту назад, AndreBA сказал:

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

Угу, вижу. Как раз пишу со смарта.

Share this post


Link to post
Share on other sites
  • 0
3 hours ago, OmegaTron said:

Теперь вопрос - что это могло быть ?

Нужен был self-test или вывод "show threads" + log.

Share this post


Link to post
Share on other sites
  • 0
3 минуты назад, sergeyk сказал:

Нужен был self-test или вывод "show threads" + log.

На момент висяка или на текущий момент ? Если первое, то врятли это было бы возможно ибо веб-морда зависала, а прямых линков файлов я на тот момент не знал. ОК, буду иметь ввиду, что смотреть.

Share this post


Link to post
Share on other sites
  • 0
2 minutes ago, OmegaTron said:

На момент висяка или на текущий момент ? Если первое, то врятли это было бы возможно ибо веб-морда зависала, а прямых линков файлов я на тот момент не знал. ОК, буду иметь ввиду, что смотреть.

В момент вывода сообщений.

Share this post


Link to post
Share on other sites
  • 0
3 часа назад, sergeyk сказал:

В момент вывода сообщений.

ОК. Главное, чтобы хоть что-то при этом отвечало - telnet/ssh/web. В данном случае работал web, да и то только через запросы к CI/RCI через curl/wget.

Раз пошла такая пьянка - как через ssh имея доступ к корню дёрнуть упомянутые данные ? А то не так давно был сбой при котором был доступ лишь через ssh, а всё остальное отвалилось.

Edited by OmegaTron

Share this post


Link to post
Share on other sites
  • 0
1 минуту назад, OmegaTron сказал:

ОК. Главное, чтобы хоть что-то при этом отвечало - telnet/ssh/web. В данном случае работал web, но только через запросы к CI/RCI через curl/wget.

Раз пошла такая пьянка - как через ssh имея доступ к корню дёрнуть упомянутые данные ? А то не так давно был сбой при котором был доступ лишь через ssh, а всё остальное отвалилось.

Почти никак. Нужен syslog с внешним сохранением.

Share this post


Link to post
Share on other sites
  • 0
2 минуты назад, Le ecureuil сказал:

Почти никак. Нужен syslog с внешним сохранением.

Мне казалось лог хранится где-то типа /var/run/log Вроде ж должна быть локальная копия куда пишется журнао отображаемый в веб-фейсе.

Share this post


Link to post
Share on other sites
  • 0
Только что, OmegaTron сказал:

Мне казалось лог хранится где-то типа /var/run/log Вроде ж должна быть локальная копия куда пишется журнао отображаемый в веб-фейсе.

Он существует только в ОЗУ в процессе ndm.

Share this post


Link to post
Share on other sites
  • 0
6 minutes ago, OmegaTron said:

ОК. Главное, чтобы хоть что-то при этом отвечало - telnet/ssh/web. В данном случае работал web, но только через запросы к CI/RCI через curl/wget.

Раз пошла такая пьянка - как через ssh имея доступ к корню дёрнуть упомянутые данные ? А то не так давно был сбой при котором был доступ лишь через ssh, а всё остальное отвалилось.

Проще всего, пожалуй, через браузер

http://192.168.1.1/rci/show/threads
http://192.168.1.1/rci/more?filename=log

 

Share this post


Link to post
Share on other sites
  • 0
1 минуту назад, sergeyk сказал:

Проще всего, пожалуй, через браузер

В том случае

1 минуту назад, sergeyk сказал:

доступ лишь через ssh, а всё остальное отвалилось.

В данном случае, веб-морда не отвечала и через минуту отваливалась

2018-02-11 15:33:51    Daemon.Error    192.168.0.1    Feb 11 15:32:50 keenetic_omni nginx: (conn: *1406) upstream timed out (145: Unknown error) while reading response header from upstream, client: 192.168.0.245
2018-02-11 15:33:51    Daemon.Error    192.168.0.1    Feb 11 15:32:50 keenetic_omni nginx: (conn: *1400) upstream timed out (145: Unknown error) while reading response header from upstream, client: 192.168.0.245

Так что не проще. Если по этим запросам

3 минуты назад, sergeyk сказал:

http://192.168.1.1/rci/show/threads

http://192.168.1.1/rci/more?filename=log

отдаются txt, как в случае с */ci/* то можно попробовать в следующий раз слить через curl/wget,  хотя я лучше поступлю более радикально https://forum.keenetic.net/topic/527-запись-syslog-на-внешний-usb-диск-с-помощю-syslog-ng/

Share this post


Link to post
Share on other sites
  • 0
2 minutes ago, OmegaTron said:

В том случае

В данном случае, веб-морда не отвечала и через минуту отваливалась


2018-02-11 15:33:51    Daemon.Error    192.168.0.1    Feb 11 15:32:50 keenetic_omni nginx: (conn: *1406) upstream timed out (145: Unknown error) while reading response header from upstream, client: 192.168.0.245
2018-02-11 15:33:51    Daemon.Error    192.168.0.1    Feb 11 15:32:50 keenetic_omni nginx: (conn: *1400) upstream timed out (145: Unknown error) while reading response header from upstream, client: 192.168.0.245

Так что не проще. Если по этим запросам

отдаются txt, как в случае с */ci/* то можно попробовать в следующий раз слить через curl/wget,  хотя я лучше поступлю более радикально https://forum.keenetic.net/topic/527-запись-syslog-на-внешний-usb-диск-с-помощю-syslog-ng/

Через ssh запускайте ndmc

(config)> show threads
(config)> more log

Просто журнал — это хорошо, но очень желательно видеть еще и состояние потоков.

Share this post


Link to post
Share on other sites
  • 0
1 час назад, ndm сказал:

@OmegaTron: ситуация должна заметно улучшиться в версии 2.12.A.3.0-4.

Вы расскажите, в чём цимес ситуации и почему роутер тогда повисал.

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

Share this post


Link to post
Share on other sites
  • 0
1 час назад, OmegaTron сказал:

Вы расскажите, в чём цимес ситуации и почему роутер тогда повисал.

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

Вам слово netlink о чем-нибудь говорит?

Share this post


Link to post
Share on other sites
  • 0
В 16.02.2018 в 03:17, Le ecureuil сказал:

Вам слово netlink о чем-нибудь говорит?

Нет. Т.е. объяснения для дилентантов не будет ? Хотя бы в общих чертах ?)

Share this post


Link to post
Share on other sites
  • 0
9 часов назад, OmegaTron сказал:

Нет. Т.е. объяснения для дилентантов не будет ? Хотя бы в общих чертах ?)

В общих чертах - при считывании ARP-таблицы из ядра по netlink происходило блокирование операции I/O на этом сокете, в итоге этот поток зависал с захваченным mutex, и вызывал зависание других потоков, также пытающихся захватить этот mutex.

Share this post


Link to post
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.
Note: Your post will require moderator approval before it will be visible.

Guest
Answer this question...

×   Pasted as rich text.   Paste as plain text instead

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.


  • Recently Browsing   0 members

    No registered users viewing this page.

×
×
  • Create New...