do not log failed expressions - fix for hibernation delay
Costa Tsaousis (ktsaou) committed
Feb 23, 2017 at 21:33 UTC
28a441fb4034d81ce9e0cebad354199ac5b8250a
1 file changed
+169
-81
src/health.c
+169
-81
@@ -333,20 +333,28 @@ void *health_main(void *ptr) {
333
334
BUFFER *wb = buffer_create(100);
335
336
+ time_t now = now_realtime_sec();
337
+ time_t now_boottime = now_boottime_sec();
338
+ time_t last_now = now;
339
+ time_t last_now_boottime = now_boottime;
340
+ time_t hibernation_delay = config_get_number("health", "postpone alarms during hibernation for seconds", 60);
341
+
342
unsigned int loop = 0;
343
while(!netdata_exit) {
344
loop++;
345
debug(D_HEALTH, "Health monitoring iteration no %u started", loop);
346
341
- int oldstate, runnable = 0;
342
- time_t now = now_realtime_sec();
343
- time_t now_boot = now_boottime_sec();
347
+ int oldstate, runnable = 0, apply_hibernation_delay = 0;
348
time_t next_run = now + min_run_every;
349
RRDCALC *rc;
350
347
- time_t last_now = now;
348
- time_t last_now_boot = now_boot;
349
- time_t hibernation_delay = config_get_number("health", "postpone alarms during hibernation for seconds", 60);
351
+ // detect if boottime and realtime have twice the difference
352
+ // in which case we assume the system was just waken from hibernation
353
+ if(unlikely(now - last_now > 2 * (now_boottime - last_now_boottime)))
354
+ apply_hibernation_delay = 1;
355
+
356
+ last_now = now;
357
+ last_now_boottime = now_boottime;
358
359
if(unlikely(pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldstate) != 0))
360
error("Cannot set pthread cancel state to DISABLE.");
@@ -355,15 +363,20 @@ void *health_main(void *ptr) {
363
364
RRDHOST *host;
365
rrdhost_foreach_read(host) {
358
- if(now - last_now > 2 * (now_boot - last_now_boot)) {
359
- info("Postponing alarm checks for %ld seconds, on host '%s', due to boottime discrepancy (realtime dt: %ld, boottime dt: %ld).",
360
- hibernation_delay, host->hostname, (long)(now - last_now), (long)(now_boot - last_now_boot));
366
+ if(unlikely(apply_hibernation_delay)) {
367
+
368
+ info("Postponing alarm checks for %ld seconds, on host '%s', due to boottime discrepancy (realtime dt: %ld, boottime dt: %ld)."
369
+ , hibernation_delay
370
+ , host->hostname
371
+ , (long)(now - last_now)
372
+ , (long)(now_boottime - last_now_boottime)
373
+ );
374
+
375
host->health_delay_up_to = now + hibernation_delay;
376
}
363
- last_now = now;
364
- last_now_boot = now_boot;
377
366
- if(unlikely(!host->health_enabled || now < host->health_delay_up_to)) continue;
378
+ if(unlikely(!host->health_enabled || now < host->health_delay_up_to))
379
+ continue;
380
381
rrdhost_rdlock(host);
382
@@ -379,27 +392,41 @@ void *health_main(void *ptr) {
392
rc->old_value = rc->value;
393
rc->rrdcalc_flags |= RRDCALC_FLAG_RUNNABLE;
394
382
- // 1. if there is database lookup, do it
383
- // 2. if there is calculation expression, run it
395
+ // ------------------------------------------------------------
396
+ // if there is database lookup, do it
397
398
if(unlikely(RRDCALC_HAS_DB_LOOKUP(rc))) {
399
/* time_t old_db_timestamp = rc->db_before; */
400
int value_is_null = 0;
401
389
- int ret = rrd2value(rc->rrdset, wb, &rc->value, rc->dimensions, 1, rc->after, rc->before, rc->group, rc->options, &rc->db_after, &rc->db_before, &value_is_null);
402
+ int ret = rrd2value(rc->rrdset
403
+ , wb
404
+ , &rc->value
405
+ , rc->dimensions
406
+ , 1
407
+ , rc->after
408
+ , rc->before
409
+ , rc->group
410
+ , rc->options
411
+ , &rc->db_after
412
+ , &rc->db_before
413
+ , &value_is_null
414
+ );
415
416
if(unlikely(ret != 200)) {
417
// database lookup failed
418
rc->value = NAN;
394
-
395
- debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': database lookup returned error %d", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name, ret);
396
-
397
- if(unlikely(!(rc->rrdcalc_flags & RRDCALC_FLAG_DB_ERROR))) {
398
- rc->rrdcalc_flags |= RRDCALC_FLAG_DB_ERROR;
399
- error("Health on host '%s', alarm '%s.%s': database lookup returned error %d", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name, ret);
400
- }
419
+ rc->rrdcalc_flags |= RRDCALC_FLAG_DB_ERROR;
420
+
421
+ debug(D_HEALTH
422
+ , "Health on host '%s', alarm '%s.%s': database lookup returned error %d"
423
+ , host->hostname
424
+ , rc->chart ? rc->chart : "NOCHART"
425
+ , rc->name
426
+ , ret
427
+ );
428
}
402
- else if(unlikely(rc->rrdcalc_flags & RRDCALC_FLAG_DB_ERROR))
429
+ else
430
rc->rrdcalc_flags &= ~RRDCALC_FLAG_DB_ERROR;
431
432
/* - RRDCALC_FLAG_DB_STALE not currently used
@@ -419,44 +446,57 @@ void *health_main(void *ptr) {
446
447
if(unlikely(value_is_null)) {
448
// collected value is null
422
-
449
rc->value = NAN;
450
+ rc->rrdcalc_flags |= RRDCALC_FLAG_DB_NAN;
451
425
- debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': database lookup returned empty value (possibly value is not collected yet)", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name);
426
-
427
- if(unlikely(!(rc->rrdcalc_flags & RRDCALC_FLAG_DB_NAN))) {
428
- rc->rrdcalc_flags |= RRDCALC_FLAG_DB_NAN;
429
- error("Health on host '%s', alarm '%s.%s': database lookup returned empty value (possibly value is not collected yet)", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name);
430
- }
452
+ debug(D_HEALTH
453
+ , "Health on host '%s', alarm '%s.%s': database lookup returned empty value (possibly value is not collected yet)"
454
+ , host->hostname
455
+ , rc->chart ? rc->chart : "NOCHART"
456
+ , rc->name
457
+ );
458
}
432
- else if(unlikely(rc->rrdcalc_flags & RRDCALC_FLAG_DB_NAN))
459
+ else
460
rc->rrdcalc_flags &= ~RRDCALC_FLAG_DB_NAN;
461
435
- debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': database lookup gave value " CALCULATED_NUMBER_FORMAT, host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name, rc->value);
462
+ debug(D_HEALTH
463
+ , "Health on host '%s', alarm '%s.%s': database lookup gave value " CALCULATED_NUMBER_FORMAT
464
+ , host->hostname
465
+ , rc->chart ? rc->chart : "NOCHART"
466
+ , rc->name
467
+ , rc->value
468
+ );
469
}
470
471
+ // ------------------------------------------------------------
472
+ // if there is calculation expression, run it
473
+
474
if(unlikely(rc->calculation)) {
475
if(unlikely(!expression_evaluate(rc->calculation))) {
476
// calculation failed
441
-
477
rc->value = NAN;
443
-
444
- debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': expression '%s' failed: %s", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name, rc->calculation->parsed_as, buffer_tostring(rc->calculation->error_msg));
445
-
446
- if(unlikely(!(rc->rrdcalc_flags & RRDCALC_FLAG_CALC_ERROR))) {
447
- rc->rrdcalc_flags |= RRDCALC_FLAG_CALC_ERROR;
448
- error("Health on host '%s', alarm '%s.%s': expression '%s' failed: %s", rc->chart ? rc->chart : "NOCHART", host->hostname, rc->name, rc->calculation->parsed_as, buffer_tostring(rc->calculation->error_msg));
449
- }
478
+ rc->rrdcalc_flags |= RRDCALC_FLAG_CALC_ERROR;
479
+
480
+ debug(D_HEALTH
481
+ , "Health on host '%s', alarm '%s.%s': expression '%s' failed: %s"
482
+ , host->hostname
483
+ , rc->chart ? rc->chart : "NOCHART"
484
+ , rc->name
485
+ , rc->calculation->parsed_as
486
+ , buffer_tostring(rc->calculation->error_msg)
487
+ );
488
}
489
else {
452
- if(unlikely(rc->rrdcalc_flags & RRDCALC_FLAG_CALC_ERROR))
453
- rc->rrdcalc_flags &= ~RRDCALC_FLAG_CALC_ERROR;
454
-
455
- debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': expression '%s' gave value "
456
- CALCULATED_NUMBER_FORMAT
457
- ": %s (source: %s)", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name
458
- , rc->calculation->parsed_as, rc->calculation->result,
459
- buffer_tostring(rc->calculation->error_msg), rc->source
490
+ rc->rrdcalc_flags &= ~RRDCALC_FLAG_CALC_ERROR;
491
+
492
+ debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': expression '%s' gave value " CALCULATED_NUMBER_FORMAT ": %s (source: %s)"
493
+ , host->hostname
494
+ , rc->chart ? rc->chart : "NOCHART"
495
+ , rc->name
496
+ , rc->calculation->parsed_as
497
+ , rc->calculation->result
498
+ , buffer_tostring(rc->calculation->error_msg)
499
+ , rc->source
500
);
501
502
rc->value = rc->calculation->result;
@@ -472,51 +512,74 @@ void *health_main(void *ptr) {
512
if(unlikely(!(rc->rrdcalc_flags & RRDCALC_FLAG_RUNNABLE)))
513
continue;
514
475
- int warning_status = RRDCALC_STATUS_UNDEFINED;
515
+ int warning_status = RRDCALC_STATUS_UNDEFINED;
516
int critical_status = RRDCALC_STATUS_UNDEFINED;
517
518
+ // --------------------------------------------------------
519
+ // check the warning expression
520
+
521
if(likely(rc->warning)) {
522
if(unlikely(!expression_evaluate(rc->warning))) {
523
// calculation failed
481
-
482
- debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': warning expression failed with error: %s", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name, buffer_tostring(rc->warning->error_msg));
483
-
484
- if(unlikely(!(rc->rrdcalc_flags & RRDCALC_FLAG_WARN_ERROR))) {
485
- rc->rrdcalc_flags |= RRDCALC_FLAG_WARN_ERROR;
486
- error("Health on host '%s', alarm '%s.%s': warning expression failed with error: %s", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name, buffer_tostring(rc->warning->error_msg));
487
- }
524
+ rc->rrdcalc_flags |= RRDCALC_FLAG_WARN_ERROR;
525
+
526
+ debug(D_HEALTH
527
+ , "Health on host '%s', alarm '%s.%s': warning expression failed with error: %s"
528
+ , host->hostname
529
+ , rc->chart ? rc->chart : "NOCHART"
530
+ , rc->name
531
+ , buffer_tostring(rc->warning->error_msg)
532
+ );
533
}
534
else {
490
- if(unlikely(rc->rrdcalc_flags & RRDCALC_FLAG_WARN_ERROR))
491
- rc->rrdcalc_flags &= ~RRDCALC_FLAG_WARN_ERROR;
492
-
493
- debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': warning expression gave value " CALCULATED_NUMBER_FORMAT ": %s (source: %s)", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name, rc->warning->result, buffer_tostring(rc->warning->error_msg), rc->source);
494
-
535
+ rc->rrdcalc_flags &= ~RRDCALC_FLAG_WARN_ERROR;
536
+ debug(D_HEALTH
537
+ , "Health on host '%s', alarm '%s.%s': warning expression gave value " CALCULATED_NUMBER_FORMAT ": %s (source: %s)"
538
+ , host->hostname
539
+ , rc->chart ? rc->chart : "NOCHART"
540
+ , rc->name
541
+ , rc->warning->result
542
+ , buffer_tostring(rc->warning->error_msg)
543
+ , rc->source
544
+ );
545
warning_status = rrdcalc_value2status(rc->warning->result);
546
}
547
}
548
549
+ // --------------------------------------------------------
550
+ // check the critical expression
551
+
552
if(likely(rc->critical)) {
553
if(unlikely(!expression_evaluate(rc->critical))) {
554
// calculation failed
502
-
503
- debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': critical expression failed with error: %s", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name, buffer_tostring(rc->critical->error_msg));
504
-
505
- if(unlikely(!(rc->rrdcalc_flags & RRDCALC_FLAG_CRIT_ERROR))) {
506
- rc->rrdcalc_flags |= RRDCALC_FLAG_CRIT_ERROR;
507
- error("Health on host '%s', alarm '%s.%s': critical expression failed with error: %s", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name, buffer_tostring(rc->critical->error_msg));
508
- }
555
+ rc->rrdcalc_flags |= RRDCALC_FLAG_CRIT_ERROR;
556
+
557
+ debug(D_HEALTH
558
+ , "Health on host '%s', alarm '%s.%s': critical expression failed with error: %s"
559
+ , host->hostname
560
+ , rc->chart ? rc->chart : "NOCHART"
561
+ , rc->name
562
+ , buffer_tostring(rc->critical->error_msg)
563
+ );
564
}
565
else {
511
- if(unlikely(rc->rrdcalc_flags & RRDCALC_FLAG_CRIT_ERROR))
512
- rc->rrdcalc_flags &= ~RRDCALC_FLAG_CRIT_ERROR;
513
-
514
- debug(D_HEALTH, "Health on host '%s', alarm '%s.%s': critical expression gave value " CALCULATED_NUMBER_FORMAT ": %s (source: %s)", host->hostname, rc->chart ? rc->chart : "NOCHART", rc->name , rc->critical->result, buffer_tostring(rc->critical->error_msg), rc->source);
515
-
566
+ rc->rrdcalc_flags &= ~RRDCALC_FLAG_CRIT_ERROR;
567
+ debug(D_HEALTH
568
+ , "Health on host '%s', alarm '%s.%s': critical expression gave value " CALCULATED_NUMBER_FORMAT ": %s (source: %s)"
569
+ , host->hostname
570
+ , rc->chart ? rc->chart : "NOCHART"
571
+ , rc->name
572
+ , rc->critical->result
573
+ , buffer_tostring(rc->critical->error_msg)
574
+ , rc->source
575
+ );
576
critical_status = rrdcalc_value2status(rc->critical->result);
577
}
578
}
579
580
+ // --------------------------------------------------------
581
+ // decide the final alarm status
582
+
583
int status = RRDCALC_STATUS_UNDEFINED;
584
585
switch(warning_status) {
@@ -546,9 +609,14 @@ void *health_main(void *ptr) {
609
break;
610
}
611
612
+ // --------------------------------------------------------
613
+ // check if the new status and the old differ
614
+
615
if(status != rc->status) {
616
int delay = 0;
617
618
+ // apply trigger hysteresis
619
+
620
if(now > rc->delay_up_to_timestamp) {
621
rc->delay_up_current = rc->delay_up_duration;
622
rc->delay_down_current = rc->delay_down_duration;
@@ -576,13 +644,31 @@ void *health_main(void *ptr) {
644
645
rc->delay_last = delay;
646
rc->delay_up_to_timestamp = now + delay;
647
+
648
+ // add the alarm into the log
649
+
650
health_alarm_log(
580
- host, rc->id, rc->next_event_id++, now, rc->name, rc->rrdset->id
581
- , rc->rrdset->family, rc->exec, rc->recipient, now - rc->last_status_change
582
- , rc->old_value, rc->value, rc->status, status, rc->source, rc->units, rc->info
583
- , rc->delay_last, (rc->options & RRDCALC_FLAG_NO_CLEAR_NOTIFICATION)
584
- ? HEALTH_ENTRY_FLAG_NO_CLEAR_NOTIFICATION : 0
651
+ host
652
+ , rc->id
653
+ , rc->next_event_id++
654
+ , now
655
+ , rc->name
656
+ , rc->rrdset->id
657
+ , rc->rrdset->family
658
+ , rc->exec
659
+ , rc->recipient
660
+ , now - rc->last_status_change
661
+ , rc->old_value
662
+ , rc->value
663
+ , rc->status
664
+ , status
665
+ , rc->source
666
+ , rc->units
667
+ , rc->info
668
+ , rc->delay_last
669
+ , (rc->options & RRDCALC_FLAG_NO_CLEAR_NOTIFICATION) ? HEALTH_ENTRY_FLAG_NO_CLEAR_NOTIFICATION : 0
670
);
671
+
672
rc->last_status_change = now;
673
rc->status = status;
674
}
@@ -607,7 +693,7 @@ void *health_main(void *ptr) {
693
if(unlikely(netdata_exit))
694
break;
695
610
- } /* host loop */
696
+ } /* rrdhost_foreach */
697
698
rrd_unlock();
699
@@ -621,12 +707,14 @@ void *health_main(void *ptr) {
707
if(now < next_run) {
708
debug(D_HEALTH, "Health monitoring iteration no %u done. Next iteration in %d secs", loop, (int) (next_run - now));
709
sleep_usec(USEC_PER_SEC * (usec_t) (next_run - now));
710
+ now = now_realtime_sec();
711
}
712
else
713
debug(D_HEALTH, "Health monitoring iteration no %u done. Next iteration now", loop);
714
628
- now_boot = now_boottime_sec();
629
- }
715
+ now_boottime = now_boottime_sec();
716
+
717
+ } // forever
718
719
buffer_free(wb);
720