Delay service notification bei Socket timeout funktioniert nicht richtig

Hallo Leute

Ich habe einen HTTP Check und eine Delay service notifications for host, die aber irgendwie nicht greift:

|Date / Time|Wed May 26 10:05:27 CEST 2021|
|Summary|CRITICAL - Socket timeout after 10 seconds|

und dann

|Date / Time|Wed May 26 10:08:17 CEST 2021|
| --- | --- |
|Summary|HTTP OK: HTTP/1.1 200 OK - 357534 bytes in 0.495 second response time|

Wie ist das 5 Minuten Delay zu verstehen? Laut meiner Auffassung:

-Problem entsteht → Timer startet
-Problem bleibt länger als 5 Minuten bestehen → Mail geht raus
-Problem wird innerhalb von 5 Minuten gelöst oder verschwindet → Keine Mail und Timer wird resettet

Greetz
Ovrld

Hi @Overlord,

so soll das auch sein. Was sagt das notify.log denn dazu?

Gruß
Anastasios

Zu einem anderem Fall folgendes:

2021-05-27 15:57:10,799 [20] [cmk.base.notify] Got raw notification (AP_WLAN;PING) context with 52 variables
19866 2021-05-27 15:57:10,801 [20] [cmk.base.notify] Global rule 'Netzwerk'...
19867 2021-05-27 15:57:10,801 [20] [cmk.base.notify]  -> matches!
19868 2021-05-27 15:57:10,801 [20] [cmk.base.notify]    - adding notification of username via mail
19873 2021-05-27 15:57:10,803 [20] [cmk.base.notify] Executing 1 notifications:
19874 2021-05-27 15:57:10,803 [20] [cmk.base.notify]   * notifying username via mail, parameters: graphs_per_notification, notifications_with_graphs, bulk: no
19875 2021-05-27 15:57:10,803 [20] [cmk.base.notify]      executing /omd/sites/site/share/check_mk/notifications/mail
19876 2021-05-27 15:57:11,978 [20] [cmk.base.notify]      Output: Spooled mail to local mail transmission agent

Laut Service Check für PING ist ein Delay von 2:30 Sekunden eingestellt (die Regel wird auch als grün angezeigt, soll matchen und ist auch die einzige Regel unter Delay, die einen grünen Punkt hat:

Die E-Mail ging genau raus und ins Postfach, als der Service Ping Critical festgestellt hat. Nach 59 Sekunden war er wieder da.

Edit
Auch bei dem anderen Check ist es identisch - er wendet die Regel irgendwie nicht an mit dem Delay.

Ich erhalte immer noch einige Mails ohne Delay. In der notify.log ist nichts drin, was auf einen Delay verweist. Kann es sein, dass das Delay davor schon greift und er die Zeit in der E-Mail anpasst - also so in etwa:

-00:00:00 Problem tritt auf
Delay von 2 Minuten
-00:02:01 Problem besteht immer noch → Mail wird versendet (Zeitstempel in E-Mail 00:02:01 und nicht 00:00:00)

Heute Morgen gerade wieder gehabt:

|Service|Check_MK|
|Event|**OK** → **CRITICAL**|
|Date / Time|Tue Jun 1 07:01:11 CEST 2021|
|Summary|(Service Check Timed Out)|

und dann

|Service|Check_MK|
|Event|**CRITICAL** → **OK**|
|Date / Time|Tue Jun 1 07:01:18 CEST 2021|
|Summary|[agent] Version: 2.0.0p3, OS: linux, execution time 2.7 sec|

Das Delay ist eigentlich für Check_MK Checks des Services auf 2 Minuten.

Greetz
Ovrld

Auch in der neuen CheckMK Version funktioniert das Feature irgendwie nicht so richtig wie gedacht:

Mail1: Tue Jun 29 04:37:29 CEST 2021
Mail2: Tue Jun 29 04:39:29 CEST 2021

Delay ist auf 3 Minuten eingestellt, laut Service Parameter greift die Regel auch. Im Notify Log ist nichts mit Delay erkennbar.

Greift das Delay nicht richtig oder funktioniert es anders als gedacht?

Laut meiner Auffassung:

-Problem entsteht → Timer startet
-Problem bleibt länger als 5 Minuten bestehen → Mail geht raus
-Problem wird innerhalb von 5 Minuten gelöst oder verschwindet → Keine Mail und Timer wird resettet

Das Delay ist wenn überhaupt nur im Core Log sichtbar. Das Notification System weiß davon nix da der Core erst nach deinem eingestellten Delay halt die initiale Notification triggert.

Ich würde hier mir einfach mal die Zeilen zum Beispiel von heute Morgen anschauen was da steht.

Heute Nacht gab es Host Meldungen die nicht sein dürften - Delay ist 1:30 Minuten:

|Event|**UP** → **DOWN**|
|Date / Time|Thu Jul 8 02:54:47 CEST 2021|
|Event|**DOWN** → **UP**|
|Date / Time|Thu Jul 8 02:55:23 CEST 2021|

Meinst du mit Core Log die “nagios.log”? Wenn ja, folgendes hab ich aus der Log:

[1625705640] HOST ALERT: server;DOWN;SOFT;1;CRITICAL - 1.1.1.1: rta nan, lost 100%
[1625705687] HOST ALERT: server;DOWN;HARD;2;CRITICAL - 1.1.1.1: rta nan, lost 100%
[1625705687] HOST NOTIFICATION: check-mk-notify;server;DOWN;check-mk-notify;CRITICAL - 1.1.1.1: rta nan, lost 100%
[1625705688] EXTERNAL COMMAND: _LOG;HOST NOTIFICATION: admin@domain.tld;server;DOWN;mail;CRITICAL - 1.1.1.1: rta nan, lost 100%
[1625705688] HOST NOTIFICATION: admin@domain.tld;server;DOWN;mail;CRITICAL - 1.1.1.1: rta nan, lost 100%
[1625695200] CURRENT HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.616ms, lost 0%
[1625705723] HOST ALERT: server;UP;HARD;1;OK - 1.1.1.1: rta 20.617ms, lost 0%
[1625705723] HOST NOTIFICATION: check-mk-notify;server;UP;check-mk-notify;OK - 1.1.1.1: rta 20.617ms, lost 0%
[1625705724] EXTERNAL COMMAND: _LOG;HOST NOTIFICATION: admin@domain.tld;server;UP;mail;OK - 1.1.1.1: rta 20.617ms, lost 0%
[1625705724] HOST NOTIFICATION: admin@domain.tld;server;UP;mail;OK - 1.1.1.1: rta 20.617ms, lost 0%
[1625729233] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 21.096ms, lost 0%
[1625730793] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.807ms, lost 0%
[1625731166] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.881ms, lost 0%
[1625731652] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.845ms, lost 0%
[1625731813] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.930ms, lost 0%
[1625731890] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.876ms, lost 0%
[1625735640] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.815ms, lost 0%
[1625736275] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.669ms, lost 0%
[1625738844] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.774ms, lost 0%
[1625739079] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.679ms, lost 0%
[1625740318] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.773ms, lost 0%
[1625740716] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.746ms, lost 0%
[1625741011] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.792ms, lost 0%
[1625741113] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.768ms, lost 0%
[1625743830] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.758ms, lost 0%
[1625745376] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.714ms, lost 0%
[1625745422] INITIAL HOST STATE: server;UP;HARD;1;OK - 1.1.1.1: rta 20.714ms, lost 0%

Das ist jetzt eine Host-Notification, bis jetzt ging es ja nur um Service Notifications.
Um Host-Notifications zu verzögern gibt es eine extra Regel, unabhängig von der Service Notification Delay Regel.
Ist da eine Regel angelegt, bzw. sind das die 1:30 Minuten die du erwähnst?

1 Like

Hey lkoenig
Natürlich hab ich dafür eine Host Regel angelegt - welche auch greifen sollte (grüner Punkt).
Greetz

Etwas seltsames im Log sind die “External Commands” welche direkt zur Störung getriggert werden.
Was ist das? Oder besser von welcher Config kommt das?
Warum frage ich - dieses External Command triggert im Endeffekt auch eine Notification. Nicht das diese dann der Grund ist für deine Mails.

Das sind die Mails die raus gehen - da stehen dann natürlich andere E-Mail Adressen drin und auch die Server IP ist anders.

Das ist keine normale Notification. Hier kommt ein External Command und der nächste Eintrag im Log ist eine Notification welche auch nicht vom Notification System kommt.

Ich habe das mal in meiner Testumgebung nachgestellt und das scheint normal zu sein. Im CMK Kernel gibt es nur einen Eintrag, im Nagios Kernel gibt es zwei Einträge:

[1626421853] HOST NOTIFICATION: overlord;Win10;DOWN;mail;CRITICAL - 10.30.1.26: Host unreachable @ 10.30.1.180. rta nan, lost 100%
[1626421856] EXTERNAL COMMAND: _LOG;HOST NOTIFICATION RESULT: overlord;Win10;OK;mail;Spooled mail to local mail transmission agent;Spooled mail to local mail transmission agent

Allerdings komme ich meinem Problem immer noch nicht näher - ich bekomme immer wieder E-Mails, egal ob Host oder Service Mails die eigentlich laut Delay nicht rausgehen dürften. Gestern z. B.

Event OKCRITICAL
Date / Time Thu Jul 15 11:09:37 CEST 2021
Summary CRITICAL - Socket timeout after 10 seconds

In meinem Mail Postfach um 11:10

Event CRITICALOK
Date / Time Thu Jul 15 11:10:27 CEST 2021
Summary HTTP OK: HTTP/1.1 200 OK - 3913 bytes in 0.328 second response time

In meinem Mail Postfach um 11:11

Das sind 50 Sekunden Unterschied - Delay ist eingestellt auf 3 Minuten (Regel hat einen grünen Punkt und soll matchen).

Also wenn es im den Nagios Core geht dann kannst ganz einfach in der Nagios Config schauen ob die Delays dort auch richtig drin stehen.

Das wäre das Einzige was ich finden konnte dazu:

root@server:/opt/omd/sites/Test/var/log# grep -r "DEL" nagios.log
[1626421172] EXTERNAL COMMAND: DEL_HOST_DOWNTIME;76
[1626422235] EXTERNAL COMMAND: DEL_SVC_DOWNTIME;75

Ist es der Eintrag?

Nicht im Log. Hier musst in die generierte Config für die Host und Service Objekte schauen.
→ ~/etc/nagios/conf.d/

cat check_mk_objects.cfg |grep delay
  first_notification_delay      1.5
  first_notification_delay      5.0
  first_notification_delay      1.5

Da steht eine ganze Menge in der Art drin. Die Regeln sind angelegt und sollten auch matchen. Nur ergeben einige E-Mails keinen Sinn. Oder das Delay funktioniert anders als gedacht (und oben beschrieben).

Event OKCRITICAL
Date / Time Wed Jul 21 10:05:29 CEST 2021
Summary CRITICAL - Socket timeout after 10 seconds

Delay von 5 Minuten ist eingestellt, Regel hat einen grünen Punkt und sollte greifen. Aber:

Event CRITICALOK
Date / Time Wed Jul 21 10:06:20 CEST 2021
Summary HTTP OK: HTTP/1.1 200 OK - 361023 bytes in 0.495 second response time
define service {   
active_checks_enabled 1      
check_interval 1.0   
first_notification_delay 5.0   
max_check_attempts 3   
 service_groups HTTP-Sites
use check_mk_perf,check_mk_default
}

Ist mit “first_notification_delay” vllt. gemeint, dass nur der allererste Wechsel ein Delay hat, alle weiteren Wechsel danach aber nicht? Also wenn der Tag anfängt und der Check das erste mal von OK auf z. B. WARN geht - aber beim zweiten mal dann nicht?

Zu dem Service hier wäre nun das Core Log relevant.
Also vom ersten Soft State des Service bis zur Notification.
Am besten noch mit mehr Meldungen dazu falls noch was relevantes passiert.

[1626904800] CURRENT SERVICE STATE: server;HTTP Website;OK;HARD;1;HTTP OK: HTTP/1.1 200 OK - 361023 bytes in 0.569 second response time
[1626904832] SERVICE ALERT: server;HTTP Website;CRITICAL;SOFT;1;CRITICAL - Socket timeout after 10 seconds
[1626904892] SERVICE ALERT: server;HTTP Website;CRITICAL;SOFT;2;CRITICAL - Socket timeout after 10 seconds
[1626904942] SERVICE ALERT: server;HTTP Website;OK;SOFT;3;HTTP OK: HTTP/1.1 200 OK - 361023 bytes in 0.641 second response time
[1626926491] SERVICE ALERT: server;HTTP Website;CRITICAL;SOFT;1;CRITICAL - Socket timeout after 10 seconds
[1626926542] SERVICE ALERT: server;HTTP Website;OK;SOFT;2;HTTP OK: HTTP/1.1 200 OK - 361023 bytes in 0.671 second response time
[1626933692] SERVICE ALERT: server;HTTP Website;CRITICAL;SOFT;1;CRITICAL - Socket timeout after 10 seconds
[1626933752] SERVICE ALERT: server;HTTP Website;CRITICAL;SOFT;2;CRITICAL - Socket timeout after 10 seconds
[1626933802] SERVICE ALERT: server;HTTP Website;OK;SOFT;3;HTTP OK: HTTP/1.1 200 OK - 361023 bytes in 0.683 second response time