[dev.icinga.com #2195] host_check, last_check == next_check; services scheduled too often

[icinga-migration]

This issue has been migrated from Redmine: https://dev.icinga.com/issues/2195

Created by mfriedrich on 2011-12-13 22:27:11 +00:00

Assignee: mfriedrich
Status: Resolved (closed on 2013-03-10 15:56:12 +00:00)
Target Version: 1.9
Last Update: 2013-03-10 15:56:12 +00:00 (in Redmine)

Icinga Version: 1.6.0
OS Version: Debian

---

host check stays at top of scheduling queue (see screenshot). Check interval is set to 240 minutes, but hostcheck runs every 5 Minutes. In fact, every one of this host checks have the same last_check and next_check time. 


Information from file /var/cache/nagios3/status.dat
        last_check=1321354502
        next_check=1321354502
and
     check_interval=240.000000
        retry_interval=40.000000

issue is solved.

the error is in base/checks.c It's a side effect of the following code snippet

int run_async_host_check_3x(
        [...]
        /* set check time for on-demand checks, so they're not incorrectly detected as being orphaned - Luke Ross 5/16/08 */
        /* NOTE: 06/23/08 EG not sure if there will be side effects to this or not.... */
        if(scheduled_check == FALSE)
                hst->next_check = start_time.tv_sec;


for explanation see my forum post (german)
http://www.nagios-portal.org/wbb/index.php?page=Thread&postID=161763#post161763

http://tracker.nagios.org/view.php?id=270

[gelöst] Again: Scheduling Queue und last_check=next_check
Hallo,

wir haben nach wie vor das Problem, dass in unserer Scheduling Queue Host Checks drin sind, bei denen wie im Subject beschrieben last_check=next_check.
Siehe auch:
http://www.nagios-portal.org/wbb/index.p…&threadID=24289
http://tracker.nagios.org/bug_view_page.php?bug_id=270 
http://support.nagios.com/forum/viewtopic.php?f=7&t=4165 

Ob es sich nun um ein Konfigurationsproblem oder einen Bug handelt ist uns nach wie vor unklar, wir suchen halt nach einem Ansatz, das Verhalten zu beseitigen (im Quellcode sind wir bislang leider auch noch nicht fündig geworden).

Wir sind für jeden Hinweis dankbar,
weiter hoffend,
Stefan

wir haben das Problem gefunden. Es besteht aus zwei Teilen.

1. Der Dummy Service, unerreichbare Hosts werden alle 5 Minute gepingt

Da wir in unsere Nagios Konfiguration Hosts hatten, an denen kein Service hing, hat ein "/etc/init.d/nagios3 reload", viele Warnings produziert. Um dies zu vermeiden, gibt es einen Dummyservice, der an jedem Host hängt und immer 'OK' ist.

Quellcode
define service {
    use generic-service
    host_name * ; match all hosts
    service_description Dummy Service
    check_command check_none
    notification_interval   0 ; set > 0 if you want to be renotified
}

Dabei haben wir kein check_interval eingestellt. Der Service wurde also defaultmäßig alle 5 Minuten aufgerufen. 

Nach jedem Servicecheck wird überprüft, ob der Host UP oder DOWN ist. Im Fall DOWN wird ein Hostcheck ausgeführt. Da einige Hosts nur zweitweiße erreichbar sind, waren sie häufig down. Sie wurde also alle 5 Minuten gepingt, obwohl das host check_interval auf 240 Minuten gesetzt war. Das hatten wir beobachtet.

Das Problem hier war also die Konfiguration. Mit einem checkinterval von 1 Monat für den Dummy service ist das Problem der häufigen Hostchecks beseitigt.

2. Hosts bleiben oben in der Scheduling Queue hängen.

Dies ist eigentlich nur ein optisches Problem. 

In der Funktion run_async_host_check_3x() in base/checks.c ist der Auslöser. Dort wird zwischen scheduled (im check_interval) und nicht scheduled (bei Bedarf) Hostchecks unterschieden.

Quellcode
int run_async_host_check_3x(
         ...
        /* set check time for on-demand checks, so they're not incorrectly detected as being orphaned - Luke Ross 5/16/08 */
        /* NOTE: 06/23/08 EG not sure if there will be side effects to this or not.... */
        if(scheduled_check == FALSE)
                hst->next_check = start_time.tv_sec;
        ...


Normalerweise werden bei einem Host nur 'scheduled' Checks ausgeführt. In Zeitabstände wie für eine Host im 'check_interval' definiert ist. 'hst->last_check' und 'hst->next_check' sind auf die richtigen Werten gesetzt. Es werden aber auch Hostchecks zwischen 'scheduled' Checks ausgeführt, z. B. wenn ein Host DOWN und ein Servicecheck (wie oben beim Dummy Service) verarbeitet wird. Dabei wird in der Funktion 'run_async_host_check_3x' Funktion der 'hst->next_check' auf die Startzeit des Hostchecks gesetzt (Siehe Code). Später wird auch noch 'hst->last_check' auf die Startzeit des Hostchecks gesetzt. Die beiden Zeit sind jetzt gleich. 
Diese Werte beeinflussen aber _nicht_ die Ausführung von Hostchecks in Nagios. Also aufgrund der falschen 'hst->next_check' werden keine weitern Hostchecks ausgeführt.
 Zitat
NOTE: 06/23/08 EG not sure if there will be side effects to this or not
Doch es gibt welche.

Es beeinflusst nämlich die Darstellung in der Scheduling Queue. Dort sind die Einträge nach der next_check-Zeit sortiert. Da diese Zeit aber im Code falsch gesetzt wird, ist auch die Darstellung falsch. Da die next_check-Zeit in der Vergangenheit liegt, bleiben diese Einträge immer oben. Erst wenn wieder ein richtiger scheduled Check ausgeführt wird, werden next_check und last_check wieder richtig gesetzt. Die Einträge verschwinden oben aus der Liste. Die flaschen Werte beeinflussen aber _nicht_ die Ausführung von Hostchecks in Nagios. Also aufgrund der falschen 'hst->next_check' Zeit wird kein weiterer Hostcheck ausgeführt.

Der Fix wäre die 'hst->next_check' Zeit nach der Ausführungen der Hostchecks in der Funktion handle_async_host_check_result_3x() wieder auf den Wert des nächsten scheduled checks zu setzten.

Attachments

• Screenshot2.png mfriedrich - 2011-12-13 22:27:11 +00:00

Changesets

2013-03-10 13:33:24 +00:00 by (unknown) 5074e8d

core: fix host_check, last_check == next_check wrong in scheduling queue

this is one of those side effects when detecting orphaned checks, so in
order to solve the issue, remove workaround for the next_check of on
demand hosts, and look our if they occur on the orphaned checks again.

fixes #2195

[icinga-migration]

Updated by ricardo on 2011-12-13 23:03:04 +00:00

Another solution would be:
hide entries for hosts where last and next check are the same timestamp and these timestamps are in the past.

[icinga-migration]

Updated by mfriedrich on 2012-01-27 20:31:42 +00:00

• Target Version deleted 1.7

[icinga-migration]

Updated by skysurferjh on 2012-02-05 12:34:25 +00:00

Nach einem Update von Icinga 1.5.1 auf 1.6. inklusive der IDO-Utils und Icinga-Web haben wir den gleichen Fehler. In der Classic-GUI (in der Scheduling Queue) stehen die gleichen Uhrzeiten bei "Last Check" und "Next Check". Allerdings sind wir nicht davon betroffen, das auch bestimmte Host Checks in der "Scheduling Queue" hängen bleiben. Klickt man auf einen einzelnen Host- oder Service-Check, stehen dort die korrekten Zeiten.

[icinga-migration]

Updated by mfriedrich on 2012-05-05 14:43:11 +00:00

within

/* check for hosts that never returned from a check... */
void check_for_orphaned_hosts(void) {

happens the logic to determine the freshness of the checkresults.

                /* determine the time at which the check results should have come in (allow 10 minutes slack time) */
                expected_time = (time_t)(temp_host->next_check + temp_host->latency + host_check_timeout + check_reaper_interval + 600);

mainly for that reason the next_check attribute is set to start_time when invoking a non-scheduled on demand check, and not somewhere undeterministic in the future, between regular scheduling intervals.

probably it would be better to mark a host check as non scheduled and check that flag, rather than passing strange time values around, marking wrong next_check values.

orphaned checks are scheduled by event id EVENT_ORPHAN_CHECK

        /* add an orphaned check event */
        if (check_orphaned_services == TRUE || check_orphaned_hosts == TRUE)
                schedule_new_event(EVENT_ORPHAN_CHECK, TRUE, current_time + DEFAULT_ORPHAN_CHECK_INTERVAL, TRUE, DEFAULT_ORPHAN_CHECK_INTERVAL, NULL, TRUE, NULL, NULL, 0);

after scheduled host checks are put into the execution queue.

when actually executing a host check, which could be on-demand as well....

/* perform an asynchronous check of a host */
/* scheduled host checks will use this, as will some checks that result from on-demand checks... */
int run_async_host_check_3x(host *hst, int check_options, double latency, int scheduled_check, int reschedule_check, int *time_is_valid, time_t *preferred_time) {

you will then run into the next_check reset in order to bypass the orphaned check logic.

        /* get the command start time */
        gettimeofday(&start_time, NULL);

        /* set check time for on-demand checks, so they're not incorrectly detected as being orphaned - Luke Ross 5/16/08 */
        /* NOTE: 06/23/08 EG not sure if there will be side effects to this or not.... */
        if (scheduled_check == FALSE)
                hst->next_check = start_time.tv_sec;

given that calculations, an on demand host check will trigger the following time

start_time + latency + timeout + reaper_interval + 600s
instead of
next_check + latency + timeout + reaper_interval + 600s

which will of course never reach the if condition match, as this is being reaped after running the check, and not having a future check somewhere.

there are 2 options i can see:

• fix it in the core, adding a new host attribute "scheduled_check", being set to 0 if running that as on demand check, and to 1 if the async scheduled check happens. currently this flag is directly passed to the functions as "int scheduled_check" but won't last into the orphaned checker. other than resetting next_check time, check the scheduled_check flag in the orphaned check logic, and bail early if not scheduled. requires extensive testing then.

• fix it in the gui, removing scheduled checks which has last_check == next_check

the more simply solution is gui, the more clean is core.

[icinga-migration]

Updated by mfriedrich on 2012-05-13 17:30:28 +00:00

• Status changed from Feedback to Assigned
• Assigned to set to mfriedrich

[icinga-migration]

Updated by mfriedrich on 2012-09-18 12:11:17 +00:00

• Target Version set to 1.9
• Icinga Version set to 1
• OS Version set to Debian

guess, a short time removal to be tested could be safe. though, consider it for 1.9 tree then.

http://tracker.nagios.org/view.php?id=270

https://github.com/dnsmichi/nagios-svn/commit/3c5e689fc12df4e8f3f2b5a7b726e8ca49c13612

[icinga-migration]

Updated by Anonymous on 2013-03-10 15:56:12 +00:00

• Status changed from Assigned to Resolved
• Done % changed from 0 to 100

Applied in changeset 5074e8d.