From a31814f47bf164e3d9b75dce9bf6319824af225f Mon Sep 17 00:00:00 2001 From: Brian Behlendorf Date: Fri, 20 Feb 2009 22:27:18 -0800 Subject: [PATCH] Further profile infrastructure --- scripts/zpios-profile/zpios-profile-post.sh | 138 ++++++++++++---- scripts/zpios-profile/zpios-profile-pre.sh | 174 +++++++++++++++----- scripts/zpios-profile/zpios-profile.sh | 2 + scripts/zpios.sh | 38 +++-- 4 files changed, 261 insertions(+), 91 deletions(-) diff --git a/scripts/zpios-profile/zpios-profile-post.sh b/scripts/zpios-profile/zpios-profile-post.sh index 9f53daa2b1..3a454ba045 100755 --- a/scripts/zpios-profile/zpios-profile-post.sh +++ b/scripts/zpios-profile/zpios-profile-post.sh @@ -4,50 +4,126 @@ PROG=zpios-profile-post.sh RUN_POST=${0} RUN_PHASE=${1} -RUN_LOG_DIR=${2} +RUN_DIR=${2} RUN_ID=${3} RUN_POOL=${4} RUN_CHUNK_SIZE=${5} RUN_REGION_SIZE=${6} -RUN_THREAD_COUNT=${7} +RUN_THRD_COUNT=${7} RUN_REGION_COUNT=${8} RUN_OFFSET=${9} RUN_REGION_NOISE=${10} RUN_CHUNK_NOISE=${11} -RUN_THREAD_DELAY=${12} +RUN_THRD_DELAY=${12} RUN_FLAGS=${13} RUN_RESULT=${14} -if [ "${RUN_PHASE}" != "post" ]; then - exit 1 -fi +# Summarize system time per process +zpios_profile_post_pids() { + ${PROFILE_PIDS} ${PROFILE_RUN_CR_PIDS_LOG} >${PROFILE_RUN_CR_PIDS_CSV} + ${PROFILE_PIDS} ${PROFILE_RUN_WR_PIDS_LOG} >${PROFILE_RUN_WR_PIDS_CSV} + ${PROFILE_PIDS} ${PROFILE_RUN_RD_PIDS_LOG} >${PROFILE_RUN_RD_PIDS_CSV} + ${PROFILE_PIDS} ${PROFILE_RUN_RM_PIDS_LOG} >${PROFILE_RUN_RM_PIDS_CSV} +} -. ${RUN_LOG_DIR}/zpios-config.sh -. ${RUN_LOG_DIR}/${RUN_ID}/zpios-config-run.sh - -#kill -s SIGHUP `cat ${PROFILE_PID}` -#rm -f ${PROFILE_PID} - -OPROFILE_SHORT_ARGS="-a -g -l -p ${KERNEL_BIN},${SPL_BIN},${ZFS_BIN}" -OPROFILE_LONG_ARGS="-d -a -g -l -p ${KERNEL_BIN},${SPL_BIN},${ZFS_BIN}" - -/usr/bin/opcontrol --stop >>${OPROFILE_LOG} 2>&1 -/usr/bin/opcontrol --dump >>${OPROFILE_LOG} 2>&1 -/usr/bin/opreport ${OPROFILE_SHORT_ARGS} >${OPROFILE_SHORT_LOG} 2>&1 -/usr/bin/opreport ${OPROFILE_LONG_ARGS} >${OPROFILE_LONG_LOG} 2>&1 - -if [ -f ${PROFILE_ARC_PROC} ]; then - cat ${PROFILE_ARC_PROC} >${PROFILE_ARC_LOG} -fi - -if [ -f ${PROFILE_VDEV_CACHE_PROC} ]; then - cat ${PROFILE_VDEV_CACHE_PROC} >${PROFILE_VDEV_CACHE_LOG} -fi - -# Summarize system time per pid -${PROFILE_ZPIOS_PIDS_BIN} ${RUN_LOG_DIR} ${RUN_ID} >${PROFILE_ZPIOS_PIDS_LOG} +zpios_profile_post_disk() { + ${PROFILE_DISK} ${PROFILE_RUN_CR_DISK_LOG} >${PROFILE_RUN_CR_DISK_CSV} + ${PROFILE_DISK} ${PROFILE_RUN_WR_DISK_LOG} >${PROFILE_RUN_WR_DISK_CSV} + ${PROFILE_DISK} ${PROFILE_RUN_RD_DISK_LOG} >${PROFILE_RUN_RD_DISK_CSV} + ${PROFILE_DISK} ${PROFILE_RUN_RM_DISK_LOG} >${PROFILE_RUN_RM_DISK_CSV} +} # Summarize per device performance -${PROFILE_ZPIOS_DISK_BIN} ${RUN_LOG_DIR} ${RUN_ID} >${PROFILE_ZPIOS_DISK_LOG} + +# Stop a user defined profiling script which is gathering additional data +zpios_profile_post_stop() { + local PROFILE_PID=$1 + + kill -s SIGHUP `cat ${PROFILE_PID}` + + + # Sleep waiting for profile script to exit + while [ -f ${PROFILE_PID} ]; do + sleep 0.01 + done +} + +zpios_profile_post_proc_stop() { + local PROC_DIR=$1 + + if [ -f ${PROFILE_ARC_PROC} ]; then + cat ${PROFILE_ARC_PROC} >${PROC_DIR}/arcstats.txt + fi + + if [ -f ${PROFILE_VDEV_CACHE_PROC} ]; then + cat ${PROFILE_VDEV_CACHE_PROC} >${PROC_DIR}/vdev_cache_stats.txt + fi +} + +zpios_profile_post_oprofile_stop() { + local OPROFILE_LOG=$1 + local OPROFILE_ARGS="-a -g -l -p ${OPROFILE_KERNEL_DIR},${OPROFILE_SPL_DIR},${OPROFILE_ZFS_DIR}" + + /usr/bin/opcontrol --stop >>${OPROFILE_LOG} 2>&1 + /usr/bin/opcontrol --dump >>${OPROFILE_LOG} 2>&1 + /usr/bin/opreport ${OPROFILE_ARGS} >${OPROFILE_LOG} 2>&1 + /usr/bin/oparchive +} + +zpios_profile_post_create() { + zpios_profile_post_oprofile_stop ${PROFILE_RUN_CR_OPROFILE_LOG} + zpios_profile_post_proc_stop ${PROFILE_RUN_CR_DIR} + zpios_profile_post_stop ${PROFILE_RUN_CR_PID} +} + +zpios_profile_post_write() { + zpios_profile_post_oprofile_stop ${PROFILE_RUN_WR_OPROFILE_LOG} + zpios_profile_post_proc_stop ${PROFILE_RUN_WR_DIR} + zpios_profile_post_stop ${PROFILE_RUN_WR_PID} +} + +zpios_profile_post_read() { + zpios_profile_post_oprofile_stop ${PROFILE_RUN_CR_RD_LOG} + zpios_profile_post_proc_stop ${PROFILE_RUN_RD_DIR} + zpios_profile_post_stop ${PROFILE_RUN_RD_PID} +} + +zpios_profile_post_remove() { + zpios_profile_post_oprofile_stop ${PROFILE_RUN_RM_OPROFILE_LOG} + zpios_profile_post_proc_stop ${PROFILE_RUN_RM_DIR} + zpios_profile_post_stop ${PROFILE_RUN_RM_PID} +} + +# Source global zpios test configuration +if [ -f ${RUN_DIR}/zpios-config.sh ]; then + . ${RUN_DIR}/zpios-config.sh +fi + +# Source global per-run test configuration +if [ -f ${RUN_DIR}/${RUN_ID}/zpios-config-run.sh ]; then + . ${RUN_DIR}/${RUN_ID}/zpios-config-run.sh +fi + +case "${RUN_PHASE}" in + post-run) + zpios_profile_post_pids + zpios_profile_post_disk + ;; + post-create) + zpios_profile_post_create + ;; + post-write) + zpios_profile_post_write + ;; + post-read) + zpios_profile_post_read + ;; + post-remove) + zpios_profile_post_remove + ;; + *) + echo "Usage: ${PROG} {post-run|post-create|post-write|post-read|post-remove}" + exit 1 +esac exit 0 diff --git a/scripts/zpios-profile/zpios-profile-pre.sh b/scripts/zpios-profile/zpios-profile-pre.sh index 09b4aba779..a2a885798d 100755 --- a/scripts/zpios-profile/zpios-profile-pre.sh +++ b/scripts/zpios-profile/zpios-profile-pre.sh @@ -2,93 +2,183 @@ PROG=zpios-profile-pre.sh -PROFILE_ZPIOS_READY=0 -trap "PROFILE_ZPIOS_READY=1" SIGHUP +PROFILE_RDY=0 +trap "PROFILE_RDY=1" SIGHUP RUN_PRE=${0} RUN_PHASE=${1} -RUN_LOG_DIR=${2} +RUN_DIR=${2} RUN_ID=${3} RUN_POOL=${4} RUN_CHUNK_SIZE=${5} RUN_REGION_SIZE=${6} -RUN_THREAD_COUNT=${7} +RUN_THRD_COUNT=${7} RUN_REGION_COUNT=${8} RUN_OFFSET=${9} RUN_REGION_NOISE=${10} RUN_CHUNK_NOISE=${11} -RUN_THREAD_DELAY=${12} +RUN_THRD_DELAY=${12} RUN_FLAGS=${13} RUN_RESULT=${14} -zpios_profile_run_cfg() { -cat > ${RUN_LOG_DIR}/${RUN_ID}/zpios-config-run.sh << EOF +zpios_profile_pre_run_cfg() { +cat > ${RUN_DIR}/${RUN_ID}/zpios-config-run.sh << EOF # # Zpios Profiling Configuration for Run ${RUN_ID} # -PROFILE_PID=${RUN_LOG_DIR}/${RUN_ID}/profile.pid +PROFILE_RUN_DIR=${RUN_DIR}/${RUN_ID} -PROFILE_ZPIOS_PIDS_LOG=${RUN_LOG_DIR}/${RUN_ID}/pids-summary.csv -PROFILE_ZPIOS_DISK_LOG=${RUN_LOG_DIR}/${RUN_ID}/disk-summary.csv +PROFILE_RUN_CR_DIR=${RUN_DIR}/${RUN_ID}/create +PROFILE_RUN_CR_PID=${RUN_DIR}/${RUN_ID}/create/profile.pid +PROFILE_RUN_CR_OPROFILE_LOG=${RUN_DIR}/${RUN_ID}/create/oprofile.txt +PROFILE_RUN_CR_PIDS_LOG=${RUN_DIR}/${RUN_ID}/create/pids.txt +PROFILE_RUN_CR_PIDS_CSV=${RUN_DIR}/${RUN_ID}/create/pids.csv +PROFILE_RUN_CR_DISK_LOG=${RUN_DIR}/${RUN_ID}/create/disk.txt +PROFILE_RUN_CR_DISK_CSV=${RUN_DIR}/${RUN_ID}/create/disk.csv -PROFILE_ARC_LOG=${RUN_LOG_DIR}/${RUN_ID}/arcstats -PROFILE_ARC_PROC=/proc/spl/kstat/zfs/arcstats +PROFILE_RUN_WR_DIR=${RUN_DIR}/${RUN_ID}/write +PROFILE_RUN_WR_PID=${RUN_DIR}/${RUN_ID}/write/profile.pid +PROFILE_RUN_WR_OPROFILE_LOG=${RUN_DIR}/${RUN_ID}/write/oprofile.txt +PROFILE_RUN_WR_PIDS_LOG=${RUN_DIR}/${RUN_ID}/write/pids.txt +PROFILE_RUN_WR_PIDS_CSV=${RUN_DIR}/${RUN_ID}/write/pids.csv +PROFILE_RUN_WR_DISK_LOG=${RUN_DIR}/${RUN_ID}/write/disk.txt +PROFILE_RUN_WR_DISK_CSV=${RUN_DIR}/${RUN_ID}/write/disk.csv -PROFILE_VDEV_CACHE_LOG=${RUN_LOG_DIR}/${RUN_ID}/vdev_cache_stats -PROFILE_VDEV_CACHE_PROC=/proc/spl/kstat/zfs/vdev_cache_stats +PROFILE_RUN_RD_DIR=${RUN_DIR}/${RUN_ID}/read +PROFILE_RUN_RD_PID=${RUN_DIR}/${RUN_ID}/read/profile.pid +PROFILE_RUN_RD_OPROFILE_LOG=${RUN_DIR}/${RUN_ID}/read/oprofile.txt +PROFILE_RUN_RD_PIDS_LOG=${RUN_DIR}/${RUN_ID}/read/pids.txt +PROFILE_RUN_RD_PIDS_CSV=${RUN_DIR}/${RUN_ID}/read/pids.csv +PROFILE_RUN_RD_DISK_LOG=${RUN_DIR}/${RUN_ID}/read/disk.txt +PROFILE_RUN_RD_DISK_CSV=${RUN_DIR}/${RUN_ID}/read/disk.csv -OPROFILE_LOG=${RUN_LOG_DIR}/${RUN_ID}/oprofile.txt -OPROFILE_SHORT_LOG=${RUN_LOG_DIR}/${RUN_ID}/oprofile-short.txt -OPROFILE_LONG_LOG=${RUN_LOG_DIR}/${RUN_ID}/oprofile-long.txt +PROFILE_RUN_RM_DIR=${RUN_DIR}/${RUN_ID}/remove +PROFILE_RUN_RM_PID=${RUN_DIR}/${RUN_ID}/remove/profile.pid +PROFILE_RUN_RM_OPROFILE_LOG=${RUN_DIR}/${RUN_ID}/remove/oprofile.txt +PROFILE_RUN_RM_PIDS_LOG=${RUN_DIR}/${RUN_ID}/remove/pids.txt +PROFILE_RUN_RM_PIDS_CSV=${RUN_DIR}/${RUN_ID}/remove/pids.csv +PROFILE_RUN_RM_DISK_LOG=${RUN_DIR}/${RUN_ID}/remove/disk.txt +PROFILE_RUN_RM_DISK_CSV=${RUN_DIR}/${RUN_ID}/remove/disk.csv +# PROFILE_PIDS_LOG=${RUN_DIR}/${RUN_ID}/pids-summary.csv +# PROFILE_DISK_LOG=${RUN_DIR}/${RUN_ID}/disk-summary.csv EOF } -zpios_profile_run_args() { -cat > ${RUN_LOG_DIR}/${RUN_ID}/zpios-args.txt << EOF +zpios_profile_pre_run_args() { +cat > ${RUN_DIR}/${RUN_ID}/zpios-args.txt << EOF # # Zpios Arguments for Run ${RUN_ID} # -LOG_DIR=${RUN_LOG_DIR} +DIR=${RUN_DIR} ID=${RUN_ID} POOL=${RUN_POOL} CHUNK_SIZE=${RUN_CHUNK_SIZE} REGION_SIZE=${RUN_REGION_SIZE} -THREAD_COUNT=${RUN_THREAD_COUNT} +THRD_COUNT=${RUN_THRD_COUNT} REGION_COUNT=${RUN_REGION_COUNT} OFFSET=${RUN_OFFSET} REGION_NOISE=${RUN_REGION_NOISE} CHUNK_NOISE=${RUN_CHUNK_NOISE} -THREAD_DELAY=${RUN_THREAD_DELAY} +THRD_DELAY=${RUN_THRD_DELAY} FLAGS=${RUN_FLAGS} RESULT=${RUN_RESULT} EOF } -if [ "${RUN_PHASE}" != "pre" ]; then - exit 1 +# Spawn a user defined profiling script to gather additional data +zpios_profile_pre_start() { + local PROFILE_PID=$1 + + ${PROFILE_USER} ${RUN_PHASE} ${RUN_DIR} ${RUN_ID} & + echo "$!" >${PROFILE_PID} + + # Sleep waiting for profile script to be ready, it will + # signal us via SIGHUP when it is ready to start profiling. + while [ ${PROFILE_RDY} -eq 0 ]; do + sleep 0.01 + done +} + +zpios_profile_post_proc_start() { + + if [ -f ${PROFILE_ARC_PROC} ]; then + echo 0 >${PROFILE_ARC_PROC} + fi + + if [ -f ${PROFILE_VDEV_CACHE_PROC} ]; then + echo 0 >${PROFILE_VDEV_CACHE_PROC} + fi +} + +zpios_profile_pre_oprofile_start() { + local OPROFILE_LOG=$1 + + /usr/bin/opcontrol --reset >>${OPROFILE_LOG} 2>&1 + /usr/bin/opcontrol --start >>${OPROFILE_LOG} 2>&1 +} + +zpios_profile_pre_create() { + mkdir ${PROFILE_RUN_CR_DIR} + zpios_profile_pre_start ${PROFILE_RUN_CR_PID} + zpios_profile_post_proc_start + zpios_profile_pre_oprofile_start ${PROFILE_RUN_CR_OPROFILE_LOG} +} + +zpios_profile_pre_write() { + mkdir ${PROFILE_RUN_WR_DIR} + zpios_profile_pre_start ${PROFILE_RUN_WR_PID} + zpios_profile_post_proc_start + zpios_profile_pre_oprofile_start ${PROFILE_RUN_WR_OPROFILE_LOG} +} + +zpios_profile_pre_read() { + mkdir ${PROFILE_RUN_RD_DIR} + zpios_profile_pre_start ${PROFILE_RUN_RD_PID} + zpios_profile_post_proc_start + zpios_profile_pre_oprofile_start ${PROFILE_RUN_CR_RD_LOG} +} + +zpios_profile_pre_remove() { + mkdir ${PROFILE_RUN_RM_DIR} + zpios_profile_pre_start ${PROFILE_RUN_RM_PID} + zpios_profile_post_proc_start + zpios_profile_pre_oprofile_start ${PROFILE_RUN_RM_OPROFILE_LOG} +} + +# Source global zpios test configuration +if [ -f ${RUN_DIR}/zpios-config.sh ]; then + . ${RUN_DIR}/zpios-config.sh fi -mkdir -p ${RUN_LOG_DIR}/${RUN_ID}/ -zpios_profile_run_cfg -zpios_profile_run_args +# Source global per-run test configuration +if [ -f ${RUN_DIR}/${RUN_ID}/zpios-config-run.sh ]; then + . ${RUN_DIR}/${RUN_ID}/zpios-config-run.sh +fi -. ${RUN_LOG_DIR}/zpios-config.sh -. ${RUN_LOG_DIR}/${RUN_ID}/zpios-config-run.sh - -# Start the profile script -#${PROFILE_ZPIOS_BIN} ${RUN_PHASE} ${RUN_LOG_DIR} ${RUN_ID} & -#echo "$!" >${PROFILE_PID} - -# Sleep waiting for profile script to be ready, it will -# signal us via SIGHUP when it is ready to start profiling. -#while [ ${PROFILE_ZPIOS_READY} -eq 0 ]; do -# sleep 0.1 -#done - -/usr/bin/opcontrol --reset >>${OPROFILE_LOG} 2>&1 -/usr/bin/opcontrol --start >>${OPROFILE_LOG} 2>&1 +case "${RUN_PHASE}" in + pre-run) + mkdir -p ${RUN_DIR}/${RUN_ID}/ + zpios_profile_pre_run_cfg + zpios_profile_pre_run_args + ;; + pre-create) + zpios_profile_pre_create + ;; + pre-write) + zpios_profile_pre_write + ;; + pre-read) + zpios_profile_pre_read + ;; + pre-remove) + zpios_profile_pre_remove + ;; + *) + echo "Usage: ${PROG} {pre-run|pre-create|pre-write|pre-read|pre-remove}" + exit 1 +esac exit 0 diff --git a/scripts/zpios-profile/zpios-profile.sh b/scripts/zpios-profile/zpios-profile.sh index d3ff779eac..f4f0ee97fd 100755 --- a/scripts/zpios-profile/zpios-profile.sh +++ b/scripts/zpios-profile/zpios-profile.sh @@ -221,4 +221,6 @@ log_pids() { aquire_pids log_pids +# rm ${PROFILE_PID} + exit 0 diff --git a/scripts/zpios.sh b/scripts/zpios.sh index ed7de35df0..fec44f57bb 100755 --- a/scripts/zpios.sh +++ b/scripts/zpios.sh @@ -112,39 +112,41 @@ check_test() { } zpios_profile_config() { -cat > ${PROFILE_ZPIOS_LOG}/zpios-config.sh << EOF +cat > ${PROFILE_DIR}/zpios-config.sh << EOF # # Zpios Profiling Configuration # -PROFILE_ZPIOS_LOG=/tmp/zpios/${ZPOOL_CONFIG}+${ZPIOS_TEST_ARG}+${DATE} -PROFILE_ZPIOS_PRE=${TOPDIR}/scripts/zpios-profile/zpios-profile-pre.sh -PROFILE_ZPIOS_POST=${TOPDIR}/scripts/zpios-profile/zpios-profile-post.sh -PROFILE_ZPIOS_USER=${TOPDIR}/scripts/zpios-profile/zpios-profile.sh -PROFILE_ZPIOS_PIDS=${TOPDIR}/scripts/zpios-profile/zpios-profile-pids.sh -PROFILE_ZPIOS_DISK=${TOPDIR}/scripts/zpios-/profile/zpios-profile-disk.sh +PROFILE_DIR=/tmp/zpios/${ZPOOL_CONFIG}+${ZPIOS_TEST_ARG}+${DATE} +PROFILE_PRE=${TOPDIR}/scripts/zpios-profile/zpios-profile-pre.sh +PROFILE_POST=${TOPDIR}/scripts/zpios-profile/zpios-profile-post.sh +PROFILE_USER=${TOPDIR}/scripts/zpios-profile/zpios-profile.sh +PROFILE_PIDS=${TOPDIR}/scripts/zpios-profile/zpios-profile-pids.sh +PROFILE_DISK=${TOPDIR}/scripts/zpios-/profile/zpios-profile-disk.sh +PROFILE_ARC_PROC=/proc/spl/kstat/zfs/arcstats +PROFILE_VDEV_CACHE_PROC=/proc/spl/kstat/zfs/vdev_cache_stats -OPROFILE_KERNEL_BIN="/boot/vmlinux-`uname -r`" -OPROFILE_KERNEL_BIN_DIR="/lib/modules/`uname -r`/kernel/" -OPROFILE_SPL_BIN_DIR="${SPLBUILD}/module/" -OPROFILE_ZFS_BIN_DIR="${TOPDIR}/module/" +OPROFILE_KERNEL="/boot/vmlinux-`uname -r`" +OPROFILE_KERNEL_DIR="/lib/modules/`uname -r`/kernel/" +OPROFILE_SPL_DIR="${SPLBUILD}/module/" +OPROFILE_ZFS_DIR="${TOPDIR}/module/" EOF } zpios_profile_start() { - PROFILE_ZPIOS_LOG=/tmp/zpios/${ZPOOL_CONFIG}+${ZPIOS_TEST_ARG}+${DATE} + PROFILE_DIR=/tmp/zpios/${ZPOOL_CONFIG}+${ZPIOS_TEST_ARG}+${DATE} - mkdir -p ${PROFILE_ZPIOS_LOG} + mkdir -p ${PROFILE_DIR} zpios_profile_config - . ${PROFILE_ZPIOS_LOG}/zpios-config.sh + . ${PROFILE_DIR}/zpios-config.sh - ZPIOS_OPTIONS="${ZPIOS_OPTIONS} --log=${PROFILE_ZPIOS_LOG}" - ZPIOS_OPTIONS="${ZPIOS_OPTIONS} --prerun=${PROFILE_ZPIOS_PRE}" - ZPIOS_OPTIONS="${ZPIOS_OPTIONS} --postrun=${PROFILE_ZPIOS_POST}" + ZPIOS_OPTIONS="${ZPIOS_OPTIONS} --log=${PROFILE_DIR}" + ZPIOS_OPTIONS="${ZPIOS_OPTIONS} --prerun=${PROFILE_PRE}" + ZPIOS_OPTIONS="${ZPIOS_OPTIONS} --postrun=${PROFILE_POST}" /usr/bin/opcontrol --init - /usr/bin/opcontrol --setup --vmlinux=${OPROFILE_KERNEL_BIN} + /usr/bin/opcontrol --setup --vmlinux=${OPROFILE_KERNEL} } zpios_profile_stop() {