Suddelny poller takes longer time

Help
1

Hello,
I have about 80 devices in my LNMS. Suddelny something strange happened 29.07.2022 around 8pm.

Total Poller Time Per Module graph looks like that:

poller time
poller time1791×393 47.4 KB

In LNMS logs I found that polling one device tooks about 4-5s around 8:15pm and more than 100s after:

/srv/librenms/poller.php 160 2022-07-29 20:15:35 - 1 devices polled in 5.342 secs
/srv/librenms/poller.php 120 2022-07-29 20:15:36 - 1 devices polled in 4.263 secs
/srv/librenms/poller.php 164 2022-07-29 20:15:36 - 1 devices polled in 5.142 secs
/srv/librenms/poller.php 147 2022-07-29 20:15:37 - 1 devices polled in 34.42 secs
/srv/librenms/poller.php 165 2022-07-29 20:15:38 - 1 devices polled in 5.175 secs
/srv/librenms/poller.php 125 2022-07-29 20:15:38 - 1 devices polled in 5.365 secs
/srv/librenms/poller.php 139 2022-07-29 20:15:38 - 1 devices polled in 5.333 secs
/srv/librenms/poller.php 162 2022-07-29 20:15:38 - 1 devices polled in 5.415 secs
/srv/librenms/poller.php 16 2022-07-29 20:15:39 - 1 devices polled in 5.504 secs
/srv/librenms/poller.php 104 2022-07-29 20:15:39 - 1 devices polled in 4.096 secs
/srv/librenms/poller.php 145 2022-07-29 20:15:39 - 1 devices polled in 5.254 secs
/srv/librenms/poller.php 19 2022-07-29 20:15:40 - 1 devices polled in 5.272 secs
/srv/librenms/poller.php 28 2022-07-29 20:15:40 - 1 devices polled in 5.365 secs
/srv/librenms/poller.php 142 2022-07-29 20:15:40 - 1 devices polled in 4.436 secs
/srv/librenms/poller.php 88 2022-07-29 20:15:40 - 1 devices polled in 4.399 secs
/srv/librenms/poller.php 95 2022-07-29 20:15:41 - 1 devices polled in 4.262 secs
/srv/librenms/poller.php 87 2022-07-29 20:15:41 - 1 devices polled in 4.429 secs
/srv/librenms/poller.php 143 2022-07-29 20:15:42 - 1 devices polled in 3.851 secs
/srv/librenms/poller.php 136 2022-07-29 20:15:42 - 1 devices polled in 4.255 secs
/srv/librenms/poller.php 144 2022-07-29 20:15:42 - 1 devices polled in 3.885 secs
/srv/librenms/poller.php 27 2022-07-29 20:15:43 - 1 devices polled in 4.435 secs
/srv/librenms/poller.php 137 2022-07-29 20:15:43 - 1 devices polled in 4.240 secs
/srv/librenms/poller.php 114 2022-07-29 20:15:43 - 1 devices polled in 4.168 secs
/srv/librenms/poller.php 132 2022-07-29 20:15:44 - 1 devices polled in 4.124 secs
/srv/librenms/poller.php 163 2022-07-29 20:15:44 - 1 devices polled in 3.859 secs
/srv/librenms/poller.php 24 2022-07-29 20:15:44 - 1 devices polled in 4.218 secs
/srv/librenms/poller.php 21 2022-07-29 20:15:44 - 1 devices polled in 4.005 secs
/srv/librenms/poller.php 169 2022-07-29 20:15:45 - 1 devices polled in 1.659 secs
/srv/librenms/poller.php 89 2022-07-29 20:15:45 - 1 devices polled in 4.066 secs
/srv/librenms/poller.php 149 2022-07-29 20:15:45 - 1 devices polled in 4.117 secs
/srv/librenms/poller.php 170 2022-07-29 20:15:45 - 1 devices polled in 1.609 secs
/srv/librenms/poller.php 168 2022-07-29 20:15:45 - 1 devices polled in 1.700 secs
/srv/librenms/poller.php 124 2022-07-29 20:15:45 - 1 devices polled in 4.128 secs
/srv/librenms/poller.php 1 2022-07-29 20:15:46 - 1 devices polled in 42.49 secs
/srv/librenms/poller.php 159 2022-07-29 20:15:46 - 1 devices polled in 4.774 secs
/srv/librenms/poller.php 85 2022-07-29 20:15:46 - 1 devices polled in 3.778 secs
/srv/librenms/poller.php 127 2022-07-29 20:15:46 - 1 devices polled in 3.922 secs
/srv/librenms/poller.php 150 2022-07-29 20:15:46 - 1 devices polled in 1.828 secs
/srv/librenms/poller.php 138 2022-07-29 20:15:47 - 1 devices polled in 2.669 secs
/srv/librenms/poller.php 23 2022-07-29 20:15:47 - 1 devices polled in 2.344 secs
/srv/librenms/poller.php 22 2022-07-29 20:15:47 - 1 devices polled in 2.473 secs
/srv/librenms/poller.php 97 2022-07-29 20:15:50 - 1 devices polled in 7.181 secs
/srv/librenms/poller.php 133 2022-07-29 20:17:26 - 1 devices polled in 142.9 secs

/srv/librenms/poller.php 99 2022-07-29 20:22:17 - 1 devices polled in 133.5 secs
/srv/librenms/poller.php 91 2022-07-29 20:22:22 - 1 devices polled in 138.6 secs
/srv/librenms/poller.php 30 2022-07-29 20:22:25 - 1 devices polled in 7.841 secs
/srv/librenms/poller.php 155 2022-07-29 20:22:31 - 1 devices polled in 147.7 secs
/srv/librenms/poller.php 7 2022-07-29 20:22:45 - 1 devices polled in 162.5 secs
/srv/librenms/poller.php 157 2022-07-29 20:22:49 - 1 devices polled in 147.8 secs
/srv/librenms/poller.php 4 2022-07-29 20:22:50 - 1 devices polled in 166.7 secs
/srv/librenms/poller.php 153 2022-07-29 20:22:57 - 1 devices polled in 174.2 secs
/srv/librenms/poller.php 83 2022-07-29 20:23:01 - 1 devices polled in 11.60 secs
/srv/librenms/poller.php 158 2022-07-29 20:23:03 - 1 devices polled in 180.3 secs
/srv/librenms/poller.php 161 2022-07-29 20:23:07 - 1 devices polled in 6.225 secs
/srv/librenms/poller.php 118 2022-07-29 20:23:43 - 1 devices polled in 220.1 secs
/srv/librenms/poller.php 98 2022-07-29 20:23:52 - 1 devices polled in 229.2 secs
/srv/librenms/poller.php 141 2022-07-29 20:23:55 - 1 devices polled in 232.7 secs
/srv/librenms/poller.php 146 2022-07-29 20:23:58 - 1 devices polled in 200.9 secs
/srv/librenms/poller.php 1 2022-07-29 20:24:04 - 1 devices polled in 241.2 secs
/srv/librenms/poller.php 3 2022-07-29 20:24:35 - 1 devices polled in 272.1 secs

Device pooling example:
https://p.libren.ms/view/

$ ./validate.php

Component Version
LibreNMS 22.8.0-220-g7347fe0b7
DB Schema 2022_07_03_1947_add_app_data (244)
PHP 8.1.8
Python 3.7.3
Database MariaDB 10.6.8-MariaDB-1:10.6.8+maria~buster
RRDTool 1.7.1
SNMP 5.7.3
====================================

[OK] Composer Version: 2.4.1
[OK] Dependencies up-to-date.
[OK] Database connection successful
[OK] Database Schema is current
[OK] SQL Server meets minimum requirements
[OK] lower_case_table_names is enabled
[OK] MySQL engine is optimal
[OK]
[OK] Database schema correct
[OK] MySQl and PHP time match
[OK] Active pollers found
[OK] Dispatcher Service not detected
[OK] Locks are functional
[OK] Python poller wrapper is polling
[OK] Redis is unavailable
[OK] rrdtool version ok
[OK] Connected to rrdcached

Very long pooling causes many gaps in graphs :frowning:

lnms gaps
lnms gaps1713×310 46.3 KB

Of course I checked hardware first - everything looks fine. LNMS is running on VM with 16GB RAM, 4VC, load is ~1-2 and more then 10GB of RAM is free.

UPDATE: I found in daily log from 29.07.2022 when problem appears:

Illuminate\Foundation\ComposerScripts::postInstall
@php artisan vue-i18n:generate --multi-locales --format=umd
@php artisan view:cache
Compiled views cleared!
Blade templates cached successfully!
@php artisan optimize
Configuration cache cleared!
Configuration cached successfully!
Route cache cleared!
Routes cached successfully!
Files cached successfully!
@php artisan config:clear
Configuration cache cleared!
scripts/dynamic_check_requirements.py || pip3 install --user -r requirements.txt || :
Returned: 0
Updated from 069741141 to 970abb958
Returned: 0
Updating SQL-Schema
Nothing to migrate.
Returned: 0
Updating submodules
Returned: 0
Cleaning up DB
Refreshing alert rules queries
Clearing OS cache
Refreshing device group table relationships
Syslog cleared for entries over 30 days (about 0 rows)
Eventlog cleared for entries over 30 days
Device perf cleared for entries over 7 days
Deleting alert_logs more than 365 days that are not active
Deleting history of active alert_logs more than 365 days
Ports fdb cleared for entries over 10 days
All deleted ports now purged
Returned: 0
Fetching notifications
[ Fri, 29 Jul 2022 00:15:34 +0200 ] LibreNMS Notifications (48)
[ Fri, 29 Jul 2022 00:15:34 +0200 ] misc/notifications.rss (62)
[ Fri, 29 Jul 2022 00:15:34 +0200 ] Updating DB Done
Returned: 0

Any help would be appreciated :slight_smile:

2

daily.php usually runs at ~00.15 so an issue at 20:17 should not be related to daily.

Check if you have poller processes hanging up. Or maybe a raid/disk failure?

3

The poller output log is missing.

Try running lnms device:poll -vvv <hostname> and capturing the output to share again. It will probably indicate the problem.

4

Neither of those two commit SHAs or your current version (7347fe0b7) seem to exist in GitHub - librenms/librenms: Community-based GPL-licensed network monitoring system? Where are you pulling code from?

5

@TheGreatDoc storage in good condition.

@murrant sorry for the broken link, proper one: Untitled - LibreNMS

@murrant Trying to find a solution I performed an update to newest version

git remote get-url origin

“https://github.com/librenms/librenms.git”

6

How about git log?

7

git log -p --after=“2022-07-28” --before=“2022-07-30”

https://p.libren.ms/view/4b97031c

8

Any other suggestions? :slight_smile:

9

I’ve had similar issues when our primary DNS server stopped working.

Linux default timeout for dns queries to switch to secondary is insanely high.

1 Like
10

Thank you @TheGreatDoc, this is the solution to the problem :slight_smile:

11

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.