Jump to content
Как правильно добавить self-test и прочую отладку в тему
Где взять тестовые сборки
Официальное хранилище ПО в виде файлов
  • 0

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

OmegaTron

Asked by OmegaTron,

 Share

Question

OmegaTron Content Generator

OmegaTron

Posted
Posted

Сел сегодня за комп и обнаружил, что в 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 (или как его там), надоели уже такие случаи.

 

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

Link to comment
Share on other sites

20 answers to this question

Recommended Posts

  • 0
OmegaTron Content Generator

OmegaTron

Posted
  • Author
Posted (edited)
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
Link to comment
Share on other sites
  • 0
OmegaTron Content Generator

OmegaTron

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

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

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

Link to comment
Share on other sites
  • 0
sergeyk Honored Flooder

sergeyk

Posted
Posted
2 minutes ago, OmegaTron said:

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

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

Link to comment
Share on other sites
  • 0
OmegaTron Content Generator

OmegaTron

Posted
  • Author
Posted (edited)
3 часа назад, sergeyk сказал:

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

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

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

Edited by OmegaTron
Link to comment
Share on other sites
  • 0
Le ecureuil Honored Flooder

Le ecureuil

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

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

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

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

Link to comment
Share on other sites
  • 0
OmegaTron Content Generator

OmegaTron

Posted
  • Author
Posted
2 минуты назад, Le ecureuil сказал:

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

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

Link to comment
Share on other sites
  • 0
Le ecureuil Honored Flooder

Le ecureuil

Posted
Posted
Только что, OmegaTron сказал:

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

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

Link to comment
Share on other sites
  • 0
sergeyk Honored Flooder

sergeyk

Posted
Posted
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

 

Link to comment
Share on other sites
  • 0
OmegaTron Content Generator

OmegaTron

Posted
  • Author
Posted
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/

Link to comment
Share on other sites
  • 0
sergeyk Honored Flooder

sergeyk

Posted
Posted
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

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

Link to comment
Share on other sites
  • 0
OmegaTron Content Generator

OmegaTron

Posted
  • Author
Posted
1 час назад, ndm сказал:

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

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

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

Link to comment
Share on other sites
  • 0
Le ecureuil Honored Flooder

Le ecureuil

Posted
Posted
1 час назад, OmegaTron сказал:

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

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

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

Link to comment
Share on other sites
  • 0
OmegaTron Content Generator

OmegaTron

Posted
  • Author
Posted
В 16.02.2018 в 03:17, Le ecureuil сказал:

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

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

Link to comment
Share on other sites
  • 0
Le ecureuil Honored Flooder

Le ecureuil

Posted
Posted
9 часов назад, OmegaTron сказал:

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

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

Link to comment
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.

×
 Share
Go to question listing

  • Recently Browsing   0 members

    • No registered users viewing this page.
×
×
  • Create New...