Thread "Item Poller" does not respond to watchdog thread
-
@victor said in Thread "Item Poller" does not respond to watchdog thread:
@anth0ny said in Thread "Item Poller" does not respond to watchdog thread:
Интерес не праздный: столкнулся вчера со странной проблемой. По неясной мне пока причине вчера на двух серверах наблюдал странную картину, возможно схожую с твоей...
2 одинаковых сервера, опрос одинаковых сервисов ведётся через ServiceCheck.HTTP.
Так вот, в какой-то момент времени я вдруг обнаружил, что опрос приостановился, т.е. в истории полученных результатов начиная со времени "Х" виден перерыв, минут на 40 (интервал опроса- 300 секунд), до следующего полученного результата опроса, "У". Причём что самое странное, одновременно (примерно, учитывая сдвиги между поллами) на обоих серверах. Я не могу пока понять что это. И это не очень приятно, так как именно на этот самый промежуток пришлось падение www-сервиса на одном из этих серверов...
U ob'ekta servera monitoringa dolzen bit' DCI pod nazvaniem "Average length of data collection poller's request queue for last minute" - kak on menjalsja v eto vremja?
хмм... снова те же симптомы.
попробую описать более подробно.конфиг (немного урезанный) сервера NetXMS (Win2008):
DBSyntax PGSQL EnableZoning 0 SyncInterval 60 RoutingTableUpdateInterval 300 ConditionPollingInterval 60 ResolveNodeNames 1 NumberOfEventProcessors 1 ClientListenerPort 4701 NumberOfDiscoveryPollers 1 NumberOfRoutingTablePollers 5 ActiveNetworkDiscovery 0 ActiveDiscoveryInterval 7200 DiscoveryFilterFlags 0 DiscoveryFilter none HouseKeepingInterval 3600 EnableSNMPTraps 1 AgentUpgradeWaitTime 600 KeepAliveInterval 60 DefaultEncryptionPolicy 1 AllowedCiphers 15 EnableMultipleDBConnections 1 NumberOfDatabaseWriters 1 IcmpPingSize 46 SyslogListenPort 514 StatusCalculationAlgorithm 1 StatusPropagationAlgorithm 1 FixedStatusValue 0 StatusShift 0 CapabilityExpirationTime 604800 DefaultCommunityString public DisableVacuum 0 LockTimeout 60000 InternalCA 0 SNMPRequestTimeout 2000 AgentCommandTimeout 2000 TopologyExpirationTime 900 TopologyDiscoveryRadius 3 EnableAuditLog 1 ThresholdRepeatInterval 0 PollCountForStatusChange 1 AllowDirectSMS 0 EnableEventStormDetection 0 EventStormEventsPerSecond 100 EventStormDuration 15 BeaconTimeout 1000 BeaconPollingInterval 1000 CheckTrustedNodes 1 RunNetworkDiscovery 0 DiscoveryPollingInterval 14400 StatusPollingInterval 60 ConfigurationPollingInterval 3600 EnableAdminInterface 1 DBFormatVersion 83 EnableSyslogDaemon 1 LogAllSNMPTraps 1 SyncNodeNamesWithDNS 1 UseInterfaceAliases 1 SyslogRetentionTime 180 EventLogRetentionTime 90 AuditLogRetentionTime 90 DeleteEmptySubnets 0 NumberOfConditionPollers 10 NumberOfConfigurationPollers 5 NumberOfDataCollectors 15 NumberOfStatusPollers 15 NumberOfUpgradeThreads 52 одинаковых сервера (Win2003).
конфиги агентов:
MasterServers = monitoring.test.ru, 127.0.0.1 LogFile = {syslog} FileStore = C:\Program Files\NetXMS\var SubAgent = ecs.nsm SubAgent = winperf.nsm SubAgent = wmi.nsm SubAgent = ups.nsm SubAgent = portcheck.nsmмониторим сервис "Yandex.server" (http://company.yandex.ru/technology/server/, локальная поисковая машина, поиск в проиндексированном контенте).
сервис откликается на порту 17000, отдаёт web-контент.
интервал опроса = 300 секунд (12 запросов в час).
строка запроса:ServiceCheck.HTTP(10.100.122.133,17000,/IOLib.XBook?text=%F5%E0%EC%E5%EB%E5%EE%ED,localyandex.test.ru,"^HTTP/1\.[01] 200.*<html.*green.*")
(%F5%E0%EC%E5%EB%E5%EE%ED = хамелеон)
DCI находятся на обоих серверах.в основном всё вроде выглядит хорошо, НО только до какого-то определённого момента.
вот и вчера опять приключилась фигня =(всё те же симптомы, что я описывал ранее: вдруг обнаруживается, что результаты запросов не попадают в Базу мониторинга. и примерно в это время сервис, который мы мониторим, падает. я сделал экспорт результатов ответа Агента за тот проблемный день (5 окт. с 14 до 21) и вот что получилось (проблемные участки выделены --->
сервер 1
05-Oct-2008 16:56:13 3 05-Oct-2008 16:51:13 3 05-Oct-2008 16:46:12 3 05-Oct-2008 16:41:12 3 05-Oct-2008 16:36:12 3 05-Oct-2008 16:31:12 3 05-Oct-2008 16:26:12 3 05-Oct-2008 16:21:12 3 05-Oct-2008 16:16:12 3 05-Oct-2008 16:11:12 3 05-Oct-2008 16:06:11 3 05-Oct-2008 16:01:11 3 05-Oct-2008 15:56:11 3 05-Oct-2008 15:51:11 3 05-Oct-2008 15:46:11 3 05-Oct-2008 15:41:10 3 05-Oct-2008 15:36:10 3 05-Oct-2008 15:31:10 3 ---> 05-Oct-2008 15:26:10 3 ---> 05-Oct-2008 14:00:29 0 05-Oct-2008 13:55:29 0 05-Oct-2008 13:50:29 0 05-Oct-2008 13:45:29 0 05-Oct-2008 13:40:29 0 05-Oct-2008 13:35:29 0 05-Oct-2008 13:30:29 0 05-Oct-2008 13:25:29 0 05-Oct-2008 13:20:29 0 05-Oct-2008 13:15:29 0 05-Oct-2008 13:10:29 0 05-Oct-2008 13:05:29 0 05-Oct-2008 13:00:29 0сервер 2
05-Oct-2008 21:57:00 0 05-Oct-2008 21:52:00 0 05-Oct-2008 21:47:00 0 05-Oct-2008 21:42:00 0 05-Oct-2008 21:37:00 0 05-Oct-2008 21:32:00 0 05-Oct-2008 21:27:00 0 05-Oct-2008 21:22:00 0 05-Oct-2008 21:17:00 0 05-Oct-2008 21:12:00 0 05-Oct-2008 21:07:00 0 05-Oct-2008 21:02:00 0 05-Oct-2008 20:57:00 0 05-Oct-2008 20:52:00 0 05-Oct-2008 20:47:00 0 ---> 05-Oct-2008 20:42:00 0 ---> 05-Oct-2008 14:19:13 0 05-Oct-2008 14:14:13 0 05-Oct-2008 14:09:13 0 05-Oct-2008 14:04:12 0 05-Oct-2008 13:59:11 0 05-Oct-2008 13:54:11 0 05-Oct-2008 13:49:11 0 05-Oct-2008 13:44:11 0 05-Oct-2008 13:39:11 0 05-Oct-2008 13:34:11 0 05-Oct-2008 13:29:11 0 05-Oct-2008 13:24:11 0 05-Oct-2008 13:19:11 0 05-Oct-2008 13:14:11 0 05-Oct-2008 13:09:11 0 05-Oct-2008 13:04:11 0обратите внимание на разрыв в цепи полученных данных.
как мне было сказано ранее, сразу полез в логи сервера, смотреть показатели...вот данные за этот подозрительный период:
Average length of configuration poller queue for last minute
все полученные значения - "0.000000".Average length of data collection poller's request queue for last minute
все полученные значения типа "0.000000" мной удалены для уменьшения текста... 05-Oct-2008 20:47:30 7.416667 05-Oct-2008 19:30:27 2.166667 05-Oct-2008 18:27:27 3.916667 05-Oct-2008 18:17:22 2.166667 05-Oct-2008 16:37:20 0.666667 05-Oct-2008 15:38:16 4.000000 05-Oct-2008 15:22:14 5.750000 05-Oct-2008 14:32:11 0.166667 ...Average length of database writer's request queue for last minute
почти все полученные значения типа "0.000000" мной удалены для уменьшения текста... 05-Oct-2008 20:44:28 0.000000 05-Oct-2008 20:43:28 1.750000 05-Oct-2008 20:42:28 1.333333 05-Oct-2008 20:11:28 1.333333 05-Oct-2008 20:10:28 1.000000 05-Oct-2008 20:09:28 4.666667 05-Oct-2008 20:08:28 9.083333 05-Oct-2008 20:05:27 970.583333 05-Oct-2008 20:04:27 1639.750000 05-Oct-2008 20:03:27 1374.416667 05-Oct-2008 20:02:27 1022.916667 05-Oct-2008 20:01:27 725.000000 05-Oct-2008 20:00:27 203.416667 05-Oct-2008 19:30:27 0.250000 05-Oct-2008 19:29:27 6.916667 05-Oct-2008 19:28:27 6.166667 05-Oct-2008 19:27:27 3.416667 05-Oct-2008 19:26:27 5.666667 05-Oct-2008 19:25:27 3.000000 05-Oct-2008 19:23:27 0.666667 05-Oct-2008 19:20:27 4.833333 05-Oct-2008 19:18:27 1.166667 05-Oct-2008 19:10:27 7.250000 05-Oct-2008 19:09:27 2.166667 05-Oct-2008 19:08:27 5.666667 05-Oct-2008 19:05:27 890.916667 05-Oct-2008 19:04:27 1613.583333 05-Oct-2008 19:03:27 1354.250000 05-Oct-2008 19:02:27 1010.083333 05-Oct-2008 19:01:27 706.083333 05-Oct-2008 19:00:27 202.750000 05-Oct-2008 18:18:22 0.083333 05-Oct-2008 18:17:22 0.166667 05-Oct-2008 18:16:22 6.666667 05-Oct-2008 18:15:22 5.416667 05-Oct-2008 18:14:22 4.500000 05-Oct-2008 18:13:22 2.666667 05-Oct-2008 18:12:22 2.500000 05-Oct-2008 18:11:22 5.750000 05-Oct-2008 18:10:22 5.583333 05-Oct-2008 18:09:22 6.583333 05-Oct-2008 18:08:22 6.500000 05-Oct-2008 18:05:22 875.250000 05-Oct-2008 18:04:22 1592.666667 05-Oct-2008 18:03:22 1337.000000 05-Oct-2008 18:02:22 990.583333 05-Oct-2008 18:01:21 696.166667 05-Oct-2008 18:00:21 163.000000 05-Oct-2008 17:55:21 0.416667 05-Oct-2008 17:54:21 5.750000 05-Oct-2008 17:45:21 0.250000 05-Oct-2008 17:44:21 0.583333 05-Oct-2008 17:11:21 9.333333 05-Oct-2008 17:05:21 1331.916667 05-Oct-2008 17:04:21 1642.166667 05-Oct-2008 17:03:21 1358.833333 05-Oct-2008 17:02:21 1004.500000 05-Oct-2008 17:01:21 716.000000 05-Oct-2008 17:00:21 167.166667 05-Oct-2008 16:37:20 0.500000 05-Oct-2008 16:36:20 0.416667 05-Oct-2008 16:11:20 0.916667 05-Oct-2008 16:10:20 0.666667 05-Oct-2008 16:09:20 1.750000 05-Oct-2008 16:08:20 0.500000 05-Oct-2008 16:06:19 8.166667 05-Oct-2008 16:05:19 1003.083333 05-Oct-2008 16:04:19 1608.333333 05-Oct-2008 16:03:19 1344.166667 05-Oct-2008 16:02:19 988.500000 05-Oct-2008 16:01:19 700.000000 05-Oct-2008 16:00:19 124.500000 05-Oct-2008 15:56:19 10.250000 05-Oct-2008 15:38:16 10.250000 05-Oct-2008 15:25:16 0.250000 05-Oct-2008 15:05:11 1326.166667 05-Oct-2008 15:04:11 1654.166667 05-Oct-2008 15:03:11 1387.000000 05-Oct-2008 15:02:11 1023.750000 05-Oct-2008 15:01:11 735.083333 05-Oct-2008 15:00:11 85.500000 05-Oct-2008 14:52:11 5.583333 05-Oct-2008 14:51:11 5.833333 05-Oct-2008 14:50:11 5.750000 05-Oct-2008 14:49:11 3.583333 05-Oct-2008 14:48:11 2.166667 05-Oct-2008 14:46:11 4.666667 05-Oct-2008 14:45:11 3.833333 05-Oct-2008 14:44:11 0.000000 05-Oct-2008 14:43:11 1.666667 05-Oct-2008 14:26:11 0.083333 05-Oct-2008 14:11:11 18.000000 05-Oct-2008 14:10:11 5.583333 05-Oct-2008 14:09:11 4.250000 05-Oct-2008 14:08:11 4.500000 05-Oct-2008 14:07:11 9.166667 05-Oct-2008 14:05:11 1300.333333 05-Oct-2008 14:04:11 1661.916667 05-Oct-2008 14:03:11 1390.750000 05-Oct-2008 14:02:11 1024.833333 05-Oct-2008 14:01:11 735.750000 05-Oct-2008 14:00:11 84.250000 05-Oct-2008 13:59:11 0.000000 ...Average length of status poller queue for last minute
все полученные значения - "0.000000".Average time to queue DCI for polling for last minute
почти все полученные значения типа "0.000000" мной удалены для уменьшения текста... 05-Oct-2008 20:45:28 0 05-Oct-2008 20:44:28 1 05-Oct-2008 20:35:28 1 05-Oct-2008 20:34:28 1 05-Oct-2008 20:24:28 1 05-Oct-2008 20:14:28 1 05-Oct-2008 20:07:28 5 05-Oct-2008 19:56:27 1 05-Oct-2008 19:47:27 1 05-Oct-2008 19:46:27 1 05-Oct-2008 19:34:27 1 05-Oct-2008 19:27:27 1 05-Oct-2008 19:25:27 1 05-Oct-2008 19:24:27 1 05-Oct-2008 19:14:27 2 05-Oct-2008 19:07:27 36 05-Oct-2008 18:56:27 1 05-Oct-2008 18:54:27 1 05-Oct-2008 18:44:27 2 05-Oct-2008 18:34:27 1 05-Oct-2008 18:27:27 1 05-Oct-2008 18:14:22 1 05-Oct-2008 18:07:22 27 05-Oct-2008 17:54:21 1 05-Oct-2008 17:34:21 1 05-Oct-2008 17:26:21 1 05-Oct-2008 17:24:21 1 05-Oct-2008 17:14:21 1 05-Oct-2008 17:07:21 3 05-Oct-2008 16:54:21 1 05-Oct-2008 16:46:20 1 05-Oct-2008 16:44:20 1 05-Oct-2008 16:36:20 1 05-Oct-2008 16:34:20 1 05-Oct-2008 16:24:20 1 05-Oct-2008 16:16:20 1 05-Oct-2008 16:14:20 1 05-Oct-2008 16:07:20 40 05-Oct-2008 15:56:19 1 05-Oct-2008 15:54:19 1 05-Oct-2008 15:35:16 1 05-Oct-2008 15:24:14 1 05-Oct-2008 15:07:12 33 05-Oct-2008 14:45:11 1 05-Oct-2008 14:40:11 1 05-Oct-2008 14:38:11 1 05-Oct-2008 14:26:11 1 05-Oct-2008 14:07:11 37 05-Oct-2008 14:00:11 0 ...что не понятно:
- почему сервер NetXMS не генерирует никаких системных оповещений в случае, если запрос отправлен, а результат запроса не получен?
- если сервисы валятся на обоих серверах в разное время, точно не одновременно, то почему проблема с неполучением данных возникает на обоих серверах приблизительно в одно время?
что сейчас делается:
- для проверки на обоих клиентах включён "--debug=7" и складирование выходных данных в локальный лог-файл.
- созданы дополнительные 2 DCI, которые вынесены на сам сервер мониторинга (на самих серверах с сервисом Yandex'а DCI тоже оставлены). чтобы посмотреть есть ли зависимость глюка от расположения DCI.
надеюсь, я дал исчерпывающую информацию
готов ответить на наводящие вопросы. -
Буду сегодня вечером все это анализировать. Очень жду логи...
-
-
Виктор, обнаружил дополнительную информацию, которая возможно объясняет возникновение ранее описанной проблемы с перерывами в получении данных!
Просмотрел системный лог сервера, Агент которого ЯКОБЫ не отвечал. И обнаружил тьму однотипных записей (причём что ОЧЕНЬ интересно: ВСЕ записи представлены по ДВА раза), которые приходятся как раз на этот проблемный период и я так подозреваю что КАЖДАЯ ЗАПИСЬ = 1 ЦИКЛУ ОПРОСА (парные записи иду с одинаковым временем и интервалом ровно в 1 минуту):
Event Type: Warning Event Source: NetXMS Win32 Agent Event Category: None Event ID: 13 Date: 05.10.2008 Time: 20:22:01 User: N/A Computer: MYSERVER1 Description: Too many communication sessions open - unable to accept new connectionМожет быть мы имеем дело со своеобразным переполнением буфера в Агенте?
Если опрашиваемый мной сервис по какой-то причине начинает отвечать с бОльшими задержками, чем может переварить Агент и все последующие запросы (включая ежеминутные запросы о статусе Агента) начинают накапливаться в очереди, возможен такой эффект?Т.е. не прошедшие запросы создают своего рода "пробку".
При этом Агент считается Сервером вполне работающим. -
получено ещё одно подтверждение: мне сообщили что сервис Яндекса обделался ~20 минут назад, я проверил консоль мониторинга- всё ок. НО в архиве ответов агента серверу образовался провал, который как раз начинается с момента падения сервиса Яндекса и длился он (я специально проверил) до тех пор, пока я вручную не рестартовал этот сервис...
интересно вот что: сервис Яндекса зависает не полностью, а как бы чего-то ждёт... т.е. сразу отлупа при заходе на порт сервиса не происходит, а появляется стандартное Page loading, please wait... но запрошенная страница так и не появляется.
и в таком состоянии он и считается упавшим... но сам-то сервис не остановился.
и запросы на соединение принимает..=(
т.е. в этом случае, я так думаю, нужно очевидно применить какой-то из вариантов стандартного ServiceCheck.HTTP но ждать не конкретного ответа, а любого ответа и ТОЛЬКО НЕ БОЛЕЕ ЧЕМ за указанный период времени (таймаут).
это возможно реализовать?
-
Teper' ponjatno. Pohoze chto na connect timeout dovol'no bol'shoj, poetomu soedinenija visjat, t.e. s tochki zrenija agenta zapros na znachenie parametra do konca ne obrabotan. Po umolchaniju agent prinimaet ne bolee 32 odnovremennih zaprosov. Ja k sledujuschemu relizu razberus' s timeout'ami pri proverke servisov, poka chto v kachestve workaround mozno sdelat' dve veschi:
- Na agente, gde zagruzen portCheck.nsm, dobavit' parametr MaxSessions = 256 (ili drugoe bol'shoe chislo vplot' do 1024).
- Dobavit' esche odin threshold na parametr ServiceCheck.HTTP na oshibku sbora dannih - togda mozno budet uznavat' o takih problemah. Ponjatno chto oshibka sbora DCI ne oznachaet chto service ne rabotaet, mogut bit' i drugie prichini, no po krajnej mere budet vidno chto kakie-to problemi est'.
-
-
1 - боюсь, что увеличение MaxSessions не приведёт к желаемому результату, ведь если я рассуждаю правильно, все сессии на таком проблемном сервере будут заняты зомби-запросами... которые будут висеть в незаконченном состоянии вплоть до того момента, пока не перезагрузят проблемный сервис. или он окончательно обделается... на что мало надежды...
2 - имеется в виду Condition типа "Data collection error"?
т.е. если я выставлю Data collection error = 2 consecutive samples, то при двух ушедших и не вернувших значения запросах я получу срабатывание трешолда? -
@anth0ny said in Thread "Item Poller" does not respond to watchdog thread:
1 - боюсь, что увеличение MaxSessions не приведёт к желаемому результату, ведь если я рассуждаю правильно, все сессии на таком проблемном сервере будут заняты зомби-запросами... которые будут висеть в незаконченном состоянии вплоть до того момента, пока не перезагрузят проблемный сервис. или он окончательно обделается... на что мало надежды...
Не совсем так плохо. Тайм-аут на подключение все-таки есть, просто он большой. Постепенно эти зомби-сессии будут завершаться. Ну и в любом случае это временное решение.
@anth0ny said in Thread "Item Poller" does not respond to watchdog thread:
2 - имеется в виду Condition типа "Data collection error"?
т.е. если я выставлю Data collection error = 2 consecutive samples, то при двух ушедших и не вернувших значения запросах я получу срабатывание трешолда?Да.
-
@isherim said in Thread "Item Poller" does not respond to watchdog thread:
За время работы в режиме дебага(сутки) данное сообщение не появлялось. Может поискать что-то конкретное в логе-он очень объемный?
Если таких сообщений не было, то и искать нечего - меня интересуют сообщения за период начиная с 5-10 минут перед появлением сообщений "thread not responding...".
Старые логи можно смело стирать. -
Hello! It looks like you're interested in this conversation, but you don't have an account yet.
Getting fed up of having to scroll through the same posts each visit? When you register for an account, you'll always come back to exactly where you were before, and choose to be notified of new replies (either via email, or push notification). You'll also be able to save bookmarks and upvote posts to show your appreciation to other community members.
With your input, this post could be even better 💗
Register Login