ctdb-scripts: Support periodic printing of warnings

In the case where a failcount only produces warnings (not
errors/unhealthy), the warnings could continue forever.  A constant
stream of warnings could dominate the logs, possibly obscuring other
useful messages.

To avoid this, add interval-based printing of warnings.  It can be set
to "hourly", "daily", any number of seconds (up to 4 digits) or
"none" (no periodic warning, use current behaviour).  The default is
"hourly".

Generally, the same interval will apply to all failcounts in a script.
However, multiple carefully placed calls to
failcount_set_warning_interval() can cause different intervals to be
used for different counters.

Add an extra unit test for vsftp monitoring to test this.

Signed-off-by: Martin Schwenke <mschwenke@ddn.com>
Reviewed-by: Amitay Isaacs <amitay@gmail.com>

diff --git a/ctdb/config/functions b/ctdb/config/functions
index 99b2905d142be9bd3704646977460e74eb096ed9..fd1b8c2db1ddf433fb9d4bcb5d97ed6b0e37e660 100755 (executable)
--- a/ctdb/config/functions
+++ b/ctdb/config/functions
@@ -965,8 +965,45 @@ _failcount_common()
        _thing="$1"
 
        _counter=$(echo "$_thing" | sed -e 's@/@_SLASH_@g' -e 's@ @_@g')
+       _failcount_warn_stamp="${script_state_dir}/${_counter}.last-warning"
 }
 
+case "$CTDB_PLATFORM_STYLE" in
+freebsd)
+       _stat_mtime_seconds()
+       {
+               stat -f '%m' -t '%s' "$@" 2>/dev/null
+       }
+       ;;
+*)
+       _stat_mtime_seconds()
+       {
+               stat -c '%Y' "$@" 2>/dev/null
+       }
+       ;;
+esac
+
+failcount_set_warning_interval()
+{
+       _interval="$1"
+
+       case "$_interval" in
+       none)
+               failcount_interval=""
+               ;;
+       daily)
+               failcount_interval=$((24 * 60 * 60))
+               ;;
+       hourly)
+               failcount_interval=$((60 * 60))
+               ;;
+       [0-9] | [0-9][0-9] | [0-9][0-9][0-9] | [0-9][0-9][0-9][0-9])
+               failcount_interval="$_interval"
+               ;;
+       esac
+}
+failcount_set_warning_interval "hourly"
+
 failcount_init()
 {
        _thing="$1"
@@ -989,6 +1026,7 @@ failcount_reset()
 
        printf 'NOTICE: %s: no longer failing\n' "$_thing"
        ctdb_counter_init "$_counter"
+       rm -f "$_failcount_warn_stamp"
 }
 
 failcount_incr()
@@ -1039,12 +1077,32 @@ failcount_incr()
                fi
        fi
 
+       _print_output=false
+       # If warnings could be issued forever because this situation
+       # will never make the node unhealthy, then issue warnings
+       # according to failcount interval.  In this case, also print
+       # the output.
+       if [ -z "$_unhealthy_threshold" ] && [ -n "$failcount_interval" ]; then
+               if _mtime=$(_stat_mtime_seconds "$_failcount_warn_stamp"); then
+                       _now=$(date '+%s')
+                       if [ $((_now - _mtime)) -lt "$failcount_interval" ]; then
+                               return
+                       fi
+               fi
+               _print_output=true
+       fi
+
+       touch "$_failcount_warn_stamp"
+
        printf 'WARNING: %s: fail count %d >= threshold %d\n' \
                "$_thing" \
                "$_failcount" \
                "$_warn_threshold"
        if [ "$_failcount" -eq "$_warn_threshold" ] && [ -n "$_output" ]; then
-               # Only print output when reaching the warning threshold
+               # Also print output when reaching the warning threshold
+               _print_output=true
+       fi
+       if $_print_output; then
                echo "$_output"
        fi
 }

diff --git a/ctdb/doc/ctdb-script.options.5.xml b/ctdb/doc/ctdb-script.options.5.xml
index f2a7d34e1fd9fbfe10f35b734d9360cd0b65b0f8..988a82599059d85de74094b57d9234641152c054 100644 (file)
--- a/ctdb/doc/ctdb-script.options.5.xml
+++ b/ctdb/doc/ctdb-script.options.5.xml
@@ -144,10 +144,13 @@
            <listitem>
              <para>
                A warning message is logged when failcount is
-               initially ≥ WARNING_THRESHOLD.  No additional warnings
-               are logged (until failcount ≥ ERROR_THRESHOLD).  The
-               intention is to avoid flooding the log with warnings.
-               The event script continues when a warning is logged.
+               initially ≥ WARNING_THRESHOLD.  If ERROR_THRESHOLD is
+               provided then no additional warnings are logged (until
+               failcount ≥ ERROR_THRESHOLD).  If ERROR_THRESHOLD is
+               not provided then additional warning are logged at
+               intervals of 1 hour.  The intention is to avoid
+               flooding the log with warnings.  The event script
+               continues when a warning is logged.
              </para>
            </listitem>
          </itemizedlist>

diff --git a/ctdb/tests/UNIT/eventscripts/40.vsftpd.monitor.003.sh b/ctdb/tests/UNIT/eventscripts/40.vsftpd.monitor.003.sh
new file mode 100755 (executable)
index 0000000..cd1c1f4
--- /dev/null
+++ b/ctdb/tests/UNIT/eventscripts/40.vsftpd.monitor.003.sh
@@ -0,0 +1,73 @@
+#!/bin/sh
+
+. "${TEST_SCRIPTS_DIR}/unit.sh"
+
+define_test "periodic warnings, up once, down several times, back up, down again"
+
+setup "up"
+
+setup_script_options <<EOF
+CTDB_VSFTPD_MONITOR_THRESHOLDS=1
+EOF
+
+ok_null
+simple_test
+
+setup "down"
+
+ok <<EOF
+WARNING: vsftpd listening on TCP port 21: fail count 1 >= threshold 1
+vsftpd not listening on TCP port 21
+EOF
+simple_test
+
+ok_null
+simple_test
+
+setup_date_one_hour_from_now
+
+ok <<EOF
+WARNING: vsftpd listening on TCP port 21: fail count 3 >= threshold 1
+vsftpd not listening on TCP port 21
+EOF
+simple_test
+
+setup "up"
+
+ok <<EOF
+NOTICE: vsftpd listening on TCP port 21: no longer failing
+EOF
+simple_test
+
+# Above fake date change doesn't affect touch/stat used for upcoming
+# periodic warnings, so reset now to be able to jump forward an hour
+# again later.  The main point is to confirm that there is no
+# remaining warning timestamp file that could stop the next warning
+# from being shown.
+setup_date
+
+setup "down"
+
+ok <<EOF
+WARNING: vsftpd listening on TCP port 21: fail count 1 >= threshold 1
+vsftpd not listening on TCP port 21
+EOF
+simple_test
+
+ok_null
+simple_test
+
+setup_date_one_hour_from_now
+
+ok <<EOF
+WARNING: vsftpd listening on TCP port 21: fail count 3 >= threshold 1
+vsftpd not listening on TCP port 21
+EOF
+simple_test
+
+setup "up"
+
+ok <<EOF
+NOTICE: vsftpd listening on TCP port 21: no longer failing
+EOF
+simple_test

diff --git a/ctdb/tests/UNIT/eventscripts/scripts/local.sh b/ctdb/tests/UNIT/eventscripts/scripts/local.sh
index 1332aa55381fe297dd5c1d29329b7478c9b794a9..007baf5d12db9e0d7305db8f4fa76f0a45ddeea5 100644 (file)
--- a/ctdb/tests/UNIT/eventscripts/scripts/local.sh
+++ b/ctdb/tests/UNIT/eventscripts/scripts/local.sh
@@ -96,6 +96,13 @@ setup_date()
        export FAKE_DATE_OUTPUT="$1"
 }
 
+setup_date_one_hour_from_now()
+{
+       _now=$(date '+%s')
+       _one_hour_from_now=$((_now + 60 * 60))
+       setup_date "$_one_hour_from_now"
+}
+
 setup_tcp_listen()
 {
        export FAKE_TCP_LISTEN="$*"