diff --git a/cmd/zed/zed.d/all-syslog.sh b/cmd/zed/zed.d/all-syslog.sh index cb9286500136..270b1bc67e5c 100755 --- a/cmd/zed/zed.d/all-syslog.sh +++ b/cmd/zed/zed.d/all-syslog.sh @@ -1,14 +1,50 @@ #!/bin/sh +# +# Copyright (C) 2013-2014 Lawrence Livermore National Security, LLC. +# Copyright (c) 2020 by Delphix. All rights reserved. +# + # # Log the zevent via syslog. +# [ -f "${ZED_ZEDLET_DIR}/zed.rc" ] && . "${ZED_ZEDLET_DIR}/zed.rc" . "${ZED_ZEDLET_DIR}/zed-functions.sh" zed_exit_if_ignoring_this_event -zed_log_msg "eid=${ZEVENT_EID}" "class=${ZEVENT_SUBCLASS}" \ - "${ZEVENT_POOL_GUID:+"pool_guid=${ZEVENT_POOL_GUID}"}" \ - "${ZEVENT_VDEV_PATH:+"vdev_path=${ZEVENT_VDEV_PATH}"}" \ - "${ZEVENT_VDEV_STATE_STR:+"vdev_state=${ZEVENT_VDEV_STATE_STR}"}" +# build a string of name=value pairs for this event +msg="eid=${ZEVENT_EID} class=${ZEVENT_SUBCLASS}" + +if [ "${ZED_SYSLOG_DISPLAY_GUIDS}" = "1" ]; then + [ -n "${ZEVENT_POOL_GUID}" ] && msg="${msg} pool_guid=${ZEVENT_POOL_GUID}" + [ -n "${ZEVENT_VDEV_GUID}" ] && msg="${msg} vdev_guid=${ZEVENT_VDEV_GUID}" +else + [ -n "${ZEVENT_POOL}" ] && msg="${msg} pool='${ZEVENT_POOL}'" + [ -n "${ZEVENT_VDEV_PATH}" ] && msg="${msg} vdev=$(basename "${ZEVENT_VDEV_PATH}")" +fi + +# log pool state if state is anything other than 'ACTIVE' +[ -n "${ZEVENT_POOL_STATE_STR}" ] && [ "$ZEVENT_POOL_STATE" -ne 0 ] && \ + msg="${msg} pool_state=${ZEVENT_POOL_STATE_STR}" + +# Log the following payload nvpairs if they are present +[ -n "${ZEVENT_VDEV_STATE_STR}" ] && msg="${msg} vdev_state=${ZEVENT_VDEV_STATE_STR}" +[ -n "${ZEVENT_CKSUM_ALGORITHM}" ] && msg="${msg} algorithm=${ZEVENT_CKSUM_ALGORITHM}" +[ -n "${ZEVENT_ZIO_SIZE}" ] && msg="${msg} size=${ZEVENT_ZIO_SIZE}" +[ -n "${ZEVENT_ZIO_OFFSET}" ] && msg="${msg} offset=${ZEVENT_ZIO_OFFSET}" +[ -n "${ZEVENT_ZIO_PRIORITY}" ] && msg="${msg} priority=${ZEVENT_ZIO_PRIORITY}" +[ -n "${ZEVENT_ZIO_ERR}" ] && msg="${msg} err=${ZEVENT_ZIO_ERR}" +[ -n "${ZEVENT_ZIO_FLAGS}" ] && msg="${msg} flags=$(printf '0x%x' "${ZEVENT_ZIO_FLAGS}")" + +# log delays that are >= 10 milisec +[ -n "${ZEVENT_ZIO_DELAY}" ] && [ "$ZEVENT_ZIO_DELAY" -gt 10000000 ] && \ + msg="${msg} delay=$((ZEVENT_ZIO_DELAY / 1000000))ms" + +# list the bookmark data together +[ -n "${ZEVENT_ZIO_OBJSET}" ] && \ + msg="${msg} bookmark=${ZEVENT_ZIO_OBJSET}:${ZEVENT_ZIO_OBJECT}:${ZEVENT_ZIO_LEVEL}:${ZEVENT_ZIO_BLKID}" + +zed_log_msg "${msg}" + exit 0 diff --git a/cmd/zed/zed.d/zed.rc b/cmd/zed/zed.d/zed.rc index 1b220d28db20..df560f921e60 100644 --- a/cmd/zed/zed.d/zed.rc +++ b/cmd/zed/zed.d/zed.rc @@ -1,122 +1,127 @@ ## # zed.rc # # This file should be owned by root and permissioned 0600. ## ## # Absolute path to the debug output file. # #ZED_DEBUG_LOG="/tmp/zed.debug.log" ## # Email address of the zpool administrator for receipt of notifications; # multiple addresses can be specified if they are delimited by whitespace. # Email will only be sent if ZED_EMAIL_ADDR is defined. # Disabled by default; uncomment to enable. # #ZED_EMAIL_ADDR="root" ## # Name or path of executable responsible for sending notifications via email; # the mail program must be capable of reading a message body from stdin. # Email will only be sent if ZED_EMAIL_ADDR is defined. # #ZED_EMAIL_PROG="mail" ## # Command-line options for ZED_EMAIL_PROG. # The string @ADDRESS@ will be replaced with the recipient email address(es). # The string @SUBJECT@ will be replaced with the notification subject; # this should be protected with quotes to prevent word-splitting. # Email will only be sent if ZED_EMAIL_ADDR is defined. # #ZED_EMAIL_OPTS="-s '@SUBJECT@' @ADDRESS@" ## # Default directory for zed lock files. # #ZED_LOCKDIR="/var/lock" ## # Minimum number of seconds between notifications for a similar event. # #ZED_NOTIFY_INTERVAL_SECS=3600 ## # Notification verbosity. # If set to 0, suppress notification if the pool is healthy. # If set to 1, send notification regardless of pool health. # #ZED_NOTIFY_VERBOSE=0 ## # Send notifications for 'ereport.fs.zfs.data' events. # Disabled by default, any non-empty value will enable the feature. # #ZED_NOTIFY_DATA= ## # Pushbullet access token. # This grants full access to your account -- protect it accordingly! # # # Disabled by default; uncomment to enable. # #ZED_PUSHBULLET_ACCESS_TOKEN="" ## # Pushbullet channel tag for push notification feeds that can be subscribed to. # # If not defined, push notifications will instead be sent to all devices # associated with the account specified by the access token. # Disabled by default; uncomment to enable. # #ZED_PUSHBULLET_CHANNEL_TAG="" ## # Slack Webhook URL. # This allows posting to the given channel and includes an access token. # # Disabled by default; uncomment to enable. # #ZED_SLACK_WEBHOOK_URL="" ## # Default directory for zed state files. # #ZED_RUNDIR="/var/run" ## # Turn on/off enclosure LEDs when drives get DEGRADED/FAULTED. This works for # device mapper and multipath devices as well. Your enclosure must be # supported by the Linux SES driver for this to work. # ZED_USE_ENCLOSURE_LEDS=1 ## # Run a scrub after every resilver # Disabled by default, 1 to enable and 0 to disable. #ZED_SCRUB_AFTER_RESILVER=0 ## # The syslog priority (e.g., specified as a "facility.level" pair). # #ZED_SYSLOG_PRIORITY="daemon.notice" ## # The syslog tag for marking zed events. # #ZED_SYSLOG_TAG="zed" ## # Which set of event subclasses to log # By default, events from all subclasses are logged. # If ZED_SYSLOG_SUBCLASS_INCLUDE is set, only subclasses # matching the pattern are logged. Use the pipe symbol (|) # or shell wildcards (*, ?) to match multiple subclasses. # Otherwise, if ZED_SYSLOG_SUBCLASS_EXCLUDE is set, the # matching subclasses are excluded from logging. #ZED_SYSLOG_SUBCLASS_INCLUDE="checksum|scrub_*|vdev.*" -#ZED_SYSLOG_SUBCLASS_EXCLUDE="statechange|config_*|history_event" +ZED_SYSLOG_SUBCLASS_EXCLUDE="history_event" + +## +# Use GUIDs instead of names when logging pool and vdevs +# Disabled by default, 1 to enable and 0 to disable. +#ZED_SYSLOG_DISPLAY_GUIDS=1 diff --git a/tests/zfs-tests/tests/functional/events/events_001_pos.ksh b/tests/zfs-tests/tests/functional/events/events_001_pos.ksh index 5121f66b78b0..189cf435e88e 100755 --- a/tests/zfs-tests/tests/functional/events/events_001_pos.ksh +++ b/tests/zfs-tests/tests/functional/events/events_001_pos.ksh @@ -1,153 +1,153 @@ #!/bin/ksh -p # # CDDL HEADER START # # The contents of this file are subject to the terms of the # Common Development and Distribution License (the "License"). # You may not use this file except in compliance with the License. # # You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE # or http://www.opensolaris.org/os/licensing. # See the License for the specific language governing permissions # and limitations under the License. # # When distributing Covered Code, include this CDDL HEADER in each # file and include the License file at usr/src/OPENSOLARIS.LICENSE. # If applicable, add the following below this CDDL HEADER, with the # fields enclosed by brackets "[]" replaced with your own identifying # information: Portions Copyright [yyyy] [name of copyright owner] # # CDDL HEADER END # # # Copyright (c) 2017 by Lawrence Livermore National Security, LLC. # Use is subject to license terms. # # DESCRIPTION: # Verify zpool events command logs events. # # STRATEGY: # 1. Execute zpool sub-commands on a pool. # 2. Verify the expected events are logged in 'zpool events'. # 3. Verify the expected events are logged by the ZED. . $STF_SUITE/include/libtest.shlib . $STF_SUITE/tests/functional/events/events_common.kshlib verify_runnable "both" function cleanup { if poolexists $MPOOL; then destroy_pool $MPOOL fi for file in $VDEV1 $VDEV2 $VDEV3 $VDEV4; do [[ -f $file ]] && rm -f $file done log_must zed_stop } log_assert "Verify zpool sub-commands generate expected events" log_onexit cleanup log_must truncate -s $MINVDEVSIZE $VDEV1 $VDEV2 $VDEV3 $VDEV4 log_must zpool events -c log_must zed_start # Create a mirrored pool with two devices. run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.pool_create" \ -e "sysevent.fs.zfs.history_event" \ -e "sysevent.fs.zfs.config_sync" \ "zpool create $MPOOL mirror $VDEV1 $VDEV2" # Set a pool property. run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.history_event" \ "zpool set comment=string $MPOOL" # Add a cache device then remove it. run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.config_sync" \ -e "sysevent.fs.zfs.vdev_add" \ "zpool add -f $MPOOL spare $VDEV3" run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.vdev_remove_aux" \ "zpool remove $MPOOL $VDEV3" # Add a log device then remove it. run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.config_sync" \ -e "sysevent.fs.zfs.vdev_add" \ "zpool add -f $MPOOL log $VDEV3" run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.vdev_remove_dev" \ "zpool remove $MPOOL $VDEV3" # Offline then online a device. run_and_verify -p "$MPOOL"\ -e "resource.fs.zfs.statechange" \ -e "sysevent.fs.zfs.config_sync" \ "zpool offline $MPOOL $VDEV1" -run_and_verify -p "$MPOOL" -d 10 \ +run_and_verify -p "$MPOOL" \ -e "resource.fs.zfs.statechange" \ -e "sysevent.fs.zfs.vdev_online" \ + -e "sysevent.fs.zfs.config_sync" \ -e "sysevent.fs.zfs.resilver_start" \ - -e "sysevent.fs.zfs.resilver_finish" \ -e "sysevent.fs.zfs.history_event" \ - -e "sysevent.fs.zfs.config_sync" \ + -e "sysevent.fs.zfs.resilver_finish" \ "zpool online $MPOOL $VDEV1" # Attach then detach a device from the mirror. -run_and_verify -p "$MPOOL" -d 10 \ +run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.vdev_attach" \ -e "sysevent.fs.zfs.resilver_start" \ - -e "sysevent.fs.zfs.resilver_finish" \ - -e "sysevent.fs.zfs.history_event" \ -e "sysevent.fs.zfs.config_sync" \ + -e "sysevent.fs.zfs.history_event" \ + -e "sysevent.fs.zfs.resilver_finish" \ "zpool attach $MPOOL $VDEV1 $VDEV4" run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.vdev_remove" \ -e "sysevent.fs.zfs.config_sync" \ "zpool detach $MPOOL $VDEV4" # Replace a device -run_and_verify -p "$MPOOL" -d 10 \ +run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.vdev_attach" \ -e "sysevent.fs.zfs.resilver_start" \ + -e "sysevent.fs.zfs.config_sync" \ + -e "sysevent.fs.zfs.history_event" \ -e "sysevent.fs.zfs.resilver_finish" \ -e "sysevent.fs.zfs.vdev_remove" \ - -e "sysevent.fs.zfs.history_event" \ - -e "sysevent.fs.zfs.config_sync" \ "zpool replace -f $MPOOL $VDEV1 $VDEV4" # Scrub a pool. -run_and_verify -p "$MPOOL" -d 10 \ +run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.scrub_start" \ - -e "sysevent.fs.zfs.scrub_finish" \ -e "sysevent.fs.zfs.history_event" \ + -e "sysevent.fs.zfs.scrub_finish" \ "zpool scrub $MPOOL" # Export then import a pool run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.pool_export" \ -e "sysevent.fs.zfs.config_sync" \ "zpool export $MPOOL" run_and_verify -p "$MPOOL" \ - -e "sysevent.fs.zfs.pool_import" \ - -e "sysevent.fs.zfs.history_event" \ -e "sysevent.fs.zfs.config_sync" \ + -e "sysevent.fs.zfs.history_event" \ + -e "sysevent.fs.zfs.pool_import" \ "zpool import -d $TEST_BASE_DIR $MPOOL" # Destroy the pool run_and_verify -p "$MPOOL" \ -e "sysevent.fs.zfs.pool_destroy" \ -e "sysevent.fs.zfs.config_sync" \ "zpool destroy $MPOOL" log_pass "Verify zpool sub-commands generate expected events" diff --git a/tests/zfs-tests/tests/functional/events/events_002_pos.ksh b/tests/zfs-tests/tests/functional/events/events_002_pos.ksh index 76ad6237fc23..7a78d93a8438 100755 --- a/tests/zfs-tests/tests/functional/events/events_002_pos.ksh +++ b/tests/zfs-tests/tests/functional/events/events_002_pos.ksh @@ -1,103 +1,103 @@ #!/bin/ksh -p # # CDDL HEADER START # # The contents of this file are subject to the terms of the # Common Development and Distribution License (the "License"). # You may not use this file except in compliance with the License. # # You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE # or http://www.opensolaris.org/os/licensing. # See the License for the specific language governing permissions # and limitations under the License. # # When distributing Covered Code, include this CDDL HEADER in each # file and include the License file at usr/src/OPENSOLARIS.LICENSE. # If applicable, add the following below this CDDL HEADER, with the # fields enclosed by brackets "[]" replaced with your own identifying # information: Portions Copyright [yyyy] [name of copyright owner] # # CDDL HEADER END # # # Copyright (c) 2017 by Lawrence Livermore National Security, LLC. # Use is subject to license terms. # # DESCRIPTION: # Verify ZED handles missed events from a pool when starting. # # STRATEGY: # 1. Clear the events and create a pool to generate some events. # 2. Start the ZED and verify it handles missed events. # 3. Stop the ZED # 4. Generate additional events. # 5. Start the ZED and verify it only handles the new missed events. . $STF_SUITE/include/libtest.shlib . $STF_SUITE/tests/functional/events/events_common.kshlib verify_runnable "both" function cleanup { if poolexists $MPOOL; then destroy_pool $MPOOL fi for file in $VDEV1 $VDEV2; do [[ -f $file ]] && rm -f $file done log_must rm -f $TMP_EVENTS_ZED $TMP_EVENTS_ZED log_must zed_stop } log_assert "Verify ZED handles missed events on when starting" log_onexit cleanup log_must truncate -s $MINVDEVSIZE $VDEV1 $VDEV2 # 1. Create a pool and generate some events. log_must truncate -s 0 $ZED_DEBUG_LOG log_must zpool events -c log_must zpool create $MPOOL mirror $VDEV1 $VDEV2 # 2. Start the ZED and verify it handles missed events. log_must zed_start log_must file_wait $ZED_DEBUG_LOG log_must cp $ZED_DEBUG_LOG $TMP_EVENTS_ZED awk -v event="sysevent.fs.zfs.pool_create" \ 'BEGIN{FS="\n"; RS=""} $0 ~ event { print $0 }' \ $TMP_EVENTS_ZED >$TMP_EVENT_ZED log_must grep -q "^ZEVENT_POOL=$MPOOL" $TMP_EVENT_ZED # 3. Stop the ZED zed_stop log_must truncate -s 0 $ZED_DEBUG_LOG # 4. Generate additional events. log_must zpool offline $MPOOL $VDEV1 log_must zpool online $MPOOL $VDEV1 log_must zpool wait -t resilver $MPOOL log_must zpool scrub $MPOOL # Wait for the scrub to wrap, or is_healthy will be wrong. while ! is_pool_scrubbed $MPOOL; do sleep 1 done # 5. Start the ZED and verify it only handled the new missed events. log_must zed_start -log_must file_wait $ZED_DEBUG_LOG 15 +log_must file_wait $ZED_DEBUG_LOG 35 log_must cp $ZED_DEBUG_LOG $TMP_EVENTS_ZED log_mustnot grep -q "sysevent.fs.zfs.pool_create" $TMP_EVENTS_ZED log_must grep -q "sysevent.fs.zfs.vdev_online" $TMP_EVENTS_ZED log_must grep -q "sysevent.fs.zfs.resilver_start" $TMP_EVENTS_ZED log_must grep -q "sysevent.fs.zfs.resilver_finish" $TMP_EVENTS_ZED log_pass "Verify ZED handles missed events on when starting" diff --git a/tests/zfs-tests/tests/functional/events/events_common.kshlib b/tests/zfs-tests/tests/functional/events/events_common.kshlib index 26afc109174f..5f4c629dca47 100644 --- a/tests/zfs-tests/tests/functional/events/events_common.kshlib +++ b/tests/zfs-tests/tests/functional/events/events_common.kshlib @@ -1,130 +1,161 @@ # # CDDL HEADER START # # The contents of this file are subject to the terms of the # Common Development and Distribution License (the "License"). # You may not use this file except in compliance with the License. # # You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE # or http://www.opensolaris.org/os/licensing. # See the License for the specific language governing permissions # and limitations under the License. # # When distributing Covered Code, include this CDDL HEADER in each # file and include the License file at usr/src/OPENSOLARIS.LICENSE. # If applicable, add the following below this CDDL HEADER, with the # fields enclosed by brackets "[]" replaced with your own identifying # information: Portions Copyright [yyyy] [name of copyright owner] # # CDDL HEADER END # # # Copyright (c) 2017 by Lawrence Livermore National Security, LLC. # Use is subject to license terms. # +# Copyright (c) 2020 by Delphix. All rights reserved. +# . $STF_SUITE/include/libtest.shlib . $STF_SUITE/tests/functional/events/events.cfg +# +# wait for 'event' to show up in the log 'file' +function file_wait_event # file event timeout +{ + file=$1 + event=$2 + timeout=${3:-120} + + SECONDS=0 + + until grep -q "^ZEVENT_CLASS=$event" $ZED_DEBUG_LOG ; do + if [[ $SECONDS -gt $timeout ]]; then + echo file_wait_event exceeded $SECONDS seconds + return 1 + fi + + sleep 1 + done + + return 0; +} + # # Wait for up to 'timeout' seconds for the 'file' to settle, i.e. # not be updated for a period of 'delay' seconds. # function file_wait # file delay timeout { file=$1 delay=${2:-3} timeout=${3:-120} SECONDS=0 while [ $(( $(date +%s) - $(stat -c %Y $file) )) -lt $delay ]; do if [[ $SECONDS -gt $timeout ]]; then + echo file_wait exceeded $SECONDS seconds return 1 fi sleep 1 done return 0; } function run_and_verify { - typeset delay event pool zedlog + typeset event pool set -A events - while getopts "d:e:p:z:" opt; do + while getopts "e:p:" opt; do case $opt in - d) - delay=$OPTARG - ;; e) - events[${#events[*]}+1]=$OPTARG + events+=("$OPTARG") ;; p) pool=$OPTARG ;; - z) - zedlog=$OPTARG - ;; esac done shift $(($OPTIND - 1)) pool=${pool:-$TESTPOOL} - delay=${delay:-3} - zedlog=${zedlog:-$ZED_DEBUG_LOG} fullcmd="$1" cmd=$(echo $fullcmd | awk '{print $1}') # If we aren't running zpool or zfs, something is wrong [[ $cmd == "zpool" || $cmd == "zfs" ]] || \ log_fail "run_and_verify called with \"$cmd ($fullcmd)\"" log_note "Checking events for command: '$fullcmd'" # Remove any previous events from the logs. log_must zpool events -c - log_must truncate -s 0 $zedlog + log_must truncate -s 0 $ZED_DEBUG_LOG # Run the command as provided. log_must eval "$fullcmd" # Collect the new events and verify there are some. log_must zpool sync -f - log_must file_wait $zedlog $delay - log_must cp $zedlog $TMP_EVENTS_ZED log_must eval "zpool events >$TMP_EVENTS 2>/dev/null" log_must eval "zpool events -v > $TMP_EVENTS_FULL 2>/dev/null" log_must test -s $TMP_EVENTS log_must test -s $TMP_EVENTS_FULL - log_must test -s $TMP_EVENTS_ZED + + # If the only event is history then we don't observe zed debug log + if [[ "${events[0]}" != "sysevent.fs.zfs.history_event" ]]; then + # wait for the last event to show up in the debug log + log_must file_wait_event $ZED_DEBUG_LOG ${events[-1]} + + log_must cp $ZED_DEBUG_LOG $TMP_EVENTS_ZED + log_must test -s $TMP_EVENTS_ZED + + log_note "Events logged:" + grep "^ZEVENT_CLASS" $TMP_EVENTS_ZED + fi log_note "Events generated:" cat $TMP_EVENTS # Verify all the expected events appear in the log. for event in ${events[*]}; do # Verify the event is in in the short output. log_must grep -q "$event" $TMP_EVENTS # Verify the event is in the verbose output with pool name. awk -v event="$event" \ 'BEGIN{FS="\n"; RS=""} $0 ~ event { print $0 }' \ $TMP_EVENTS_FULL >$TMP_EVENT_FULL log_must grep -q "pool = \"$pool\"" $TMP_EVENT_FULL + # all-debug.sh filters history events (seen in ZED_DEBUG_LOG) + if [[ "$event" == "sysevent.fs.zfs.history_event" ]]; then + continue + fi + # Verify the event was received by the ZED and logged. awk -v event="$event" \ 'BEGIN{FS="\n"; RS=""} $0 ~ event { print $0 }' \ $TMP_EVENTS_ZED >$TMP_EVENT_ZED log_must grep -q "^ZEVENT_POOL=$pool" $TMP_EVENT_ZED done rm -f $TMP_EVENTS $TMP_EVENTS_FULL $TMP_EVENT_FULL \ $TMP_EVENTS_ZED $TMP_EVENT_ZED }