From 50c44d8cdd4ca698349143e3294cc71cb30d6822 Mon Sep 17 00:00:00 2001 From: Mateusz Majewski Date: Mon, 17 Aug 2020 13:01:04 +0200 Subject: [PATCH] Add quick mode to the integration tests "Ok, here we go. Focus. Speed. I am speed. 1 winner. 42 losers. I eat losers for breakfast. Breakfast? Ah, maybe I should've had breakfast? Uh, brekkie could be good for me. No no no, stay focused. Speed. I'm faster than fast, quicker than quick! I am Lightning." -- intro of Cars by Pixar Animation Studios Change-Id: If82241fa670c53882735aff1daaa373c81ae0dac --- tests/dlog_test.in | 523 ++++++++++++++++++++++++++++------------------------- 1 file changed, 274 insertions(+), 249 deletions(-) diff --git a/tests/dlog_test.in b/tests/dlog_test.in index cfe4914..fb88f3d 100644 --- a/tests/dlog_test.in +++ b/tests/dlog_test.in @@ -89,17 +89,27 @@ ok() { # supress stderr messages from subcommands exec 2> /dev/null +USAGE_MESSAGE="usage: $0 pipe|logger|pipe_quick|logger_quick" + if [ $# -ne 1 ]; then - echo "usage: $0 pipe|logger" + echo $USAGE_MESSAGE exit 1 fi if [ "$1" == "pipe" ]; then type="pipe" + quick=0 elif [ "$1" == "logger" ]; then type="logger" + quick=0 +elif [ "$1" == "pipe_quick" ]; then + type="pipe" + quick=1 +elif [ "$1" == "logger_quick" ]; then + type="logger" + quick=1 else - echo "usage: $0 pipe|logger" + echo $USAGE_MESSAGE exit 1 fi @@ -335,41 +345,43 @@ dlogutil -gb main &> /dev/null && ok || fail LOG_DETAILS="testing if writing all entries to single file works (-f)" dlogutil -f $TESTDIR/dlog_test_file -d &> /dev/null && ok || fail -LOG_DETAILS="testing if the continuous mode works as expected (1/2)" -dlogutil -b main -f $TESTDIR/dlog_continuous1_file & -UTIL_PID=$! -sleep 1 -kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0 -UTIL_PID=-1 -[[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_continuous1_file` -eq 10 ]] && ok || fail +if [ $quick -ne 1 ]; then + LOG_DETAILS="testing if the continuous mode works as expected (1/2)" + dlogutil -b main -f $TESTDIR/dlog_continuous1_file & + UTIL_PID=$! + sleep 1 + kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0 + UTIL_PID=-1 + [[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_continuous1_file` -eq 10 ]] && ok || fail -LOG_DETAILS="testing if the continuous mode works as expected (2/2)" -dlogutil -b main -f $TESTDIR/dlog_continuous2_file & -UTIL_PID=$! -sleep 1 -dlogsend -b main "Hi!" -sleep 1 -kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0 -UTIL_PID=-1 -[[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_continuous2_file` -eq 11 ]] && ok || fail + LOG_DETAILS="testing if the continuous mode works as expected (2/2)" + dlogutil -b main -f $TESTDIR/dlog_continuous2_file & + UTIL_PID=$! + sleep 1 + dlogsend -b main "Hi!" + sleep 1 + kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0 + UTIL_PID=-1 + [[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_continuous2_file` -eq 11 ]] && ok || fail -LOG_DETAILS="testing if the monitor mode works as expected (1/2)" -dlogutil -mb main -f $TESTDIR/dlog_monitor1_file & -UTIL_PID=$! -sleep 1 -kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0 -UTIL_PID=-1 -[[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_monitor1_file` -eq 0 ]] && ok || fail + LOG_DETAILS="testing if the monitor mode works as expected (1/2)" + dlogutil -mb main -f $TESTDIR/dlog_monitor1_file & + UTIL_PID=$! + sleep 1 + kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0 + UTIL_PID=-1 + [[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_monitor1_file` -eq 0 ]] && ok || fail -LOG_DETAILS="testing if the monitor mode works as expected (2/2)" -dlogutil -mb main -f $TESTDIR/dlog_monitor2_file & -UTIL_PID=$! -sleep 1 -dlogsend -b main "Hi!" -sleep 1 -kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0 -UTIL_PID=-1 -[[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_monitor2_file` -eq 1 ]] && ok || fail + LOG_DETAILS="testing if the monitor mode works as expected (2/2)" + dlogutil -mb main -f $TESTDIR/dlog_monitor2_file & + UTIL_PID=$! + sleep 1 + dlogsend -b main "Hi!" + sleep 1 + kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0 + UTIL_PID=-1 + [[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_monitor2_file` -eq 1 ]] && ok || fail +fi LOG_DETAILS="testing if writing entries to rotating files works (-r/-n)" dlogutil -f $TESTDIR/dlog_rotating_file -r 12 -n 3 & # 3 files at 12 KB each @@ -402,8 +414,10 @@ UTIL_PID=-1 LOG_DETAILS="testing if libdlogutil works correctly in the dump mode" test_libdlogutil dump $LIBDLOGUTIL_CORRECT_PID $type && ok || fail -LOG_DETAILS="testing if libdlogutil works correctly if processing the logs takes some time" -test_libdlogutil timer $LIBDLOGUTIL_CORRECT_PID $type && ok || fail +if [ $quick -ne 1 ]; then + LOG_DETAILS="testing if libdlogutil works correctly if processing the logs takes some time" + test_libdlogutil timer $LIBDLOGUTIL_CORRECT_PID $type && ok || fail +fi LOG_DETAILS="testing if libdlogutil works correctly in the continuous mode" test_libdlogutil continuous $LIBDLOGUTIL_CORRECT_PID $type && ok || fail LOG_DETAILS="testing if libdlogutil skips all the logs in the monitor mode correctly" @@ -576,14 +590,16 @@ dlogsend -b main -t DLOG_TESTSUITE rawformatTEST line=`$cmd_prefix $format` [[ "$line" == "rawformatTEST" ]] && ok || fail -LOG_DETAILS="testing if dlogsend -d works" -dlogutil -c -dlogsend -b main -c 9999 -d 4 -f 7 -t DLOG_TESTSUITE "hi" & -DLOGSEND_PID=$! -sleep 10 -kill $DLOGSEND_PID -# In 10 seconds, 3 cycles 7 logs each should have happened. -[[ "$(dlogutil -d DLOG_TESTSUITE | wc -l)" -eq 21 ]] && ok || fail +if [ $quick -ne 1 ]; then + LOG_DETAILS="testing if dlogsend -d works" + dlogutil -c + dlogsend -b main -c 9999 -d 4 -f 7 -t DLOG_TESTSUITE "hi" & + DLOGSEND_PID=$! + sleep 10 + kill $DLOGSEND_PID + # In 10 seconds, 3 cycles 7 logs each should have happened. + [[ "$(dlogutil -d DLOG_TESTSUITE | wc -l)" -eq 21 ]] && ok || fail +fi if [ $type == "pipe" ]; then for format in raw brief long; do @@ -617,45 +633,47 @@ LOG_DETAILS="testing if KMSG works in the default format" # Feel free to change it to a reasonable yet lower value if the test happens to fail otherwise. [[ "$(dlogutil -db kmsg | wc -l)" -gt 100 ]] && ok || fail -LOG_DETAILS="testing if KMSG works in the raw format" -last_dmesg=`dmesg | tail -n1 | sed -re "s/^\[[ 0-9]{5,}\.[0-9]{6}\] (.*)$/\1/g"` -sleep 1 # To make sure dlog has already parsed the log -dlogutil -db kmsg -v raw | grep -Fm1 "$last_dmesg" >/dev/null && ok || fail +if [ $quick -ne 1 ]; then + LOG_DETAILS="testing if KMSG works in the raw format" + last_dmesg=`dmesg | tail -n1 | sed -re "s/^\[[ 0-9]{5,}\.[0-9]{6}\] (.*)$/\1/g"` + sleep 1 # To make sure dlog has already parsed the log + dlogutil -db kmsg -v raw | grep -Fm1 "$last_dmesg" >/dev/null && ok || fail -LOG_DETAILS="testing if pid filtering works" -dlogsend -b main -t DLOG_TESTSUITE pidTEST & -sleep 1 -line=`dlogutil -v raw -d --pid $!` -[[ "$line" == "pidTEST" ]] && ok || fail - -LOG_DETAILS="testing if tid filtering works" -dlogsend -b main -t DLOG_TESTSUITE tidTEST & -sleep 1 -line=`dlogutil -v raw -d --tid $!` #dlogsend is a single threaded app so tid is the same as pid -[[ "$line" == "tidTEST" ]] && ok || fail + LOG_DETAILS="testing if pid filtering works" + dlogsend -b main -t DLOG_TESTSUITE pidTEST & + sleep 1 + line=`dlogutil -v raw -d --pid $!` + [[ "$line" == "pidTEST" ]] && ok || fail -mv $DLOG_CONFIG_PATH $DLOG_CONFIG_PATH.1 -LOG_DETAILS="testing if secure logging works (1/2)" -grep -v enable_secure_logs $DLOG_CONFIG_PATH.1 > $DLOG_CONFIG_PATH -echo "enable_secure_logs=1" >> $DLOG_CONFIG_PATH -dlogutil -c -dlogsend -zb main -t DLOG_TESTSUITE secure & -sleep 1 -dlogsend -b main -t DLOG_TESTSUITE insecure & -sleep 1 -line=`dlogutil -v raw -d | head -n1` -[[ "$line" == "secure" ]] && ok || fail -LOG_DETAILS="testing if secure logging works (2/2)" -grep -v enable_secure_logs $DLOG_CONFIG_PATH.1 > $DLOG_CONFIG_PATH -echo "enable_secure_logs=0" >> $DLOG_CONFIG_PATH -dlogutil -c -dlogsend -zb main -t DLOG_TESTSUITE secure & -sleep 1 -dlogsend -b main -t DLOG_TESTSUITE insecure & -sleep 1 -line=`dlogutil -v raw -d | head -n1` -[[ "$line" == "insecure" ]] && ok || fail -mv $DLOG_CONFIG_PATH.1 $DLOG_CONFIG_PATH + LOG_DETAILS="testing if tid filtering works" + dlogsend -b main -t DLOG_TESTSUITE tidTEST & + sleep 1 + line=`dlogutil -v raw -d --tid $!` #dlogsend is a single threaded app so tid is the same as pid + [[ "$line" == "tidTEST" ]] && ok || fail + + mv $DLOG_CONFIG_PATH $DLOG_CONFIG_PATH.1 + LOG_DETAILS="testing if secure logging works (1/2)" + grep -v enable_secure_logs $DLOG_CONFIG_PATH.1 > $DLOG_CONFIG_PATH + echo "enable_secure_logs=1" >> $DLOG_CONFIG_PATH + dlogutil -c + dlogsend -zb main -t DLOG_TESTSUITE secure & + sleep 1 + dlogsend -b main -t DLOG_TESTSUITE insecure & + sleep 1 + line=`dlogutil -v raw -d | head -n1` + [[ "$line" == "secure" ]] && ok || fail + LOG_DETAILS="testing if secure logging works (2/2)" + grep -v enable_secure_logs $DLOG_CONFIG_PATH.1 > $DLOG_CONFIG_PATH + echo "enable_secure_logs=0" >> $DLOG_CONFIG_PATH + dlogutil -c + dlogsend -zb main -t DLOG_TESTSUITE secure & + sleep 1 + dlogsend -b main -t DLOG_TESTSUITE insecure & + sleep 1 + line=`dlogutil -v raw -d | head -n1` + [[ "$line" == "insecure" ]] && ok || fail + mv $DLOG_CONFIG_PATH.1 $DLOG_CONFIG_PATH +fi dlogsend -b main -t DLOG_TESTSUITE_TAG0 -pI tagTEST0 dlogsend -b main -t DLOG_TESTSUITE_TAG1 -pI tagTEST1 @@ -688,197 +706,198 @@ if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then ORIG_FILTERS_DIR=$(cat $ORIGINAL_CONFIG_PATH | grep dynamic_config_path | awk -F "=" '{print $2}') [ $(ls -dZ $ORIG_FILTERS_DIR | awk -F " " '{print $1}') == "System::Shared" ] && ok || fail - # This creates a process which will wait for SIGCONT and then spam logs. We know its PID, so we can add - # PID-based limits and see what happens. - sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' & - DLOGSEND_PID=$! - while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done - dlogctl --pid $DLOGSEND_PID -s deny - kill -s CONT $DLOGSEND_PID - wait $DLOGSEND_PID - LOG_DETAILS="testing if PID limiting works (1/10)" - [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 0 ]] && ok || fail - LOG_DETAILS="testing if PID limiting works (2/10)" - [[ $(dlogctl --pid $DLOGSEND_PID -g) == "Denied" ]] && ok || fail - LOG_DETAILS="testing if PID limiting works (3/10)" - dlogctl -g | grep -q "Denied for $DLOGSEND_PID" && ok || fail - - sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' & - DLOGSEND_PID=$! - while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done - dlogctl --pid $DLOGSEND_PID -s 25 - kill -s CONT $DLOGSEND_PID - wait $DLOGSEND_PID - LOG_DETAILS="testing if PID limiting works (4/10)" - [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 25 ]] && ok || fail - LOG_DETAILS="testing if PID limiting works (5/10)" - [[ $(dlogctl --pid $DLOGSEND_PID -g) == '25 logs/min' ]] && ok || fail - LOG_DETAILS="testing if PID limiting works (6/10)" - dlogctl -g | grep -q "25 logs/min for $DLOGSEND_PID" && ok || fail - - sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' & - DLOGSEND_PID=$! - while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done - dlogctl --pid $DLOGSEND_PID -s allow - kill -s CONT $DLOGSEND_PID - wait $DLOGSEND_PID - LOG_DETAILS="testing if PID limiting works (7/10)" - [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 100 ]] && ok || fail - LOG_DETAILS="testing if PID limiting works (8/10)" - [[ $(dlogctl --pid $DLOGSEND_PID -g) == 'Unlimited' ]] && ok || fail - LOG_DETAILS="testing if PID limiting works (9/10)" - dlogctl -g | grep -q "Unlimited for $DLOGSEND_PID" && ok || fail - - echo "qos_refresh_rate_s=5" > "$RUNTIME_FILTERS_DIR/69-refresh-rate.conf" - sh -c 'kill -s STOP $$; exec dlogsend -b main -c 15 -d 1 "Pid test"' & - DLOGSEND_PID=$! - while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done - dlogctl --pid $DLOGSEND_PID -s 2 - kill -s CONT $DLOGSEND_PID - wait $DLOGSEND_PID - rm "$RUNTIME_FILTERS_DIR/69-refresh-rate.conf" - LOG_DETAILS="testing if PID limiting works (10/10)" - # In each 5 second period, 5 logs are sent, so there are 3 periods. - # 2 logs from each period are allowed. - [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 6 ]] && ok || fail - - if [ $type == "pipe" ]; then - PREQOS_CONFIG_PATH=$DLOG_CONFIG_PATH - DLOG_CONFIG_PATH="$TESTDIR/qos.conf" - cat $PREQOS_CONFIG_PATH "@datadir@/qos-additions" > $DLOG_CONFIG_PATH - kill $LOGGER > /dev/null - sleep 1 - dlog_logger -b 99 -t 0 & - LOGGER=$! - sleep 1 - - dlogsend -b main -t DLOG_QOS_TEST0 -c 60 -d 1 -f 4 "A normal app that just wants to log" - LOG_DETAILS="testing if QoS works (1/4)" - [[ $(dlogutil -d DLOG_QOS_TEST0 | wc -l) -eq 60 ]] && ok || fail - - dlogsend -b main -t DLOG_QOS_TEST1 -c 300 -d 1 -f 20 "Some log spam" - LOG_DETAILS="testing if QoS works (2/4)" - [[ $(dlogutil -d DLOG_QOS_TEST1 | wc -l) -le 180 ]] && ok || fail - - dlogsend -b main -t DLOG_QOS_TEST2 -c 60 -d 1 -f 4 "A normal app that just wants to log" & + if [ $quick -ne 1 ]; then + # This creates a process which will wait for SIGCONT and then spam logs. We know its PID, so we can add + # PID-based limits and see what happens. + sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' & DLOGSEND_PID=$! - dlogsend -b main -t DLOG_QOS_TEST3 -c 240 -d 1 -f 16 "Some log spam" + while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done + dlogctl --pid $DLOGSEND_PID -s deny + kill -s CONT $DLOGSEND_PID wait $DLOGSEND_PID - LOG_DETAILS="testing if QoS works (3/4)" - [[ $(dlogutil -d DLOG_QOS_TEST2 DLOG_QOS_TEST3 | wc -l) -le 180 ]] && ok || fail - LOG_DETAILS="testing if QoS works (4/4)" - [[ $(dlogutil -d DLOG_QOS_TEST2 | wc -l) -gt 40 ]] && ok || fail - - DLOG_CONFIG_PATH=$PREQOS_CONFIG_PATH - kill $LOGGER > /dev/null - sleep 1 - dlog_logger -b 99 -t 0 & - LOGGER=$! - sleep 1 + LOG_DETAILS="testing if PID limiting works (1/10)" + [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 0 ]] && ok || fail + LOG_DETAILS="testing if PID limiting works (2/10)" + [[ $(dlogctl --pid $DLOGSEND_PID -g) == "Denied" ]] && ok || fail + LOG_DETAILS="testing if PID limiting works (3/10)" + dlogctl -g | grep -q "Denied for $DLOGSEND_PID" && ok || fail + + sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' & + DLOGSEND_PID=$! + while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done + dlogctl --pid $DLOGSEND_PID -s 25 + kill -s CONT $DLOGSEND_PID + wait $DLOGSEND_PID + LOG_DETAILS="testing if PID limiting works (4/10)" + [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 25 ]] && ok || fail + LOG_DETAILS="testing if PID limiting works (5/10)" + [[ $(dlogctl --pid $DLOGSEND_PID -g) == '25 logs/min' ]] && ok || fail + LOG_DETAILS="testing if PID limiting works (6/10)" + dlogctl -g | grep -q "25 logs/min for $DLOGSEND_PID" && ok || fail + + sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' & + DLOGSEND_PID=$! + while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done + dlogctl --pid $DLOGSEND_PID -s allow + kill -s CONT $DLOGSEND_PID + wait $DLOGSEND_PID + LOG_DETAILS="testing if PID limiting works (7/10)" + [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 100 ]] && ok || fail + LOG_DETAILS="testing if PID limiting works (8/10)" + [[ $(dlogctl --pid $DLOGSEND_PID -g) == 'Unlimited' ]] && ok || fail + LOG_DETAILS="testing if PID limiting works (9/10)" + dlogctl -g | grep -q "Unlimited for $DLOGSEND_PID" && ok || fail + + echo "qos_refresh_rate_s=5" > "$RUNTIME_FILTERS_DIR/69-refresh-rate.conf" + sh -c 'kill -s STOP $$; exec dlogsend -b main -c 15 -d 1 "Pid test"' & + DLOGSEND_PID=$! + while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done + dlogctl --pid $DLOGSEND_PID -s 2 + kill -s CONT $DLOGSEND_PID + wait $DLOGSEND_PID + rm "$RUNTIME_FILTERS_DIR/69-refresh-rate.conf" + LOG_DETAILS="testing if PID limiting works (10/10)" + # In each 5 second period, 5 logs are sent, so there are 3 periods. + # 2 logs from each period are allowed. + [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 6 ]] && ok || fail + + if [ $type == "pipe" ]; then + PREQOS_CONFIG_PATH=$DLOG_CONFIG_PATH + DLOG_CONFIG_PATH="$TESTDIR/qos.conf" + cat $PREQOS_CONFIG_PATH "@datadir@/qos-additions" > $DLOG_CONFIG_PATH + kill $LOGGER > /dev/null + sleep 1 + dlog_logger -b 99 -t 0 & + LOGGER=$! + sleep 1 + + dlogsend -b main -t DLOG_QOS_TEST0 -c 60 -d 1 -f 4 "A normal app that just wants to log" + LOG_DETAILS="testing if QoS works (1/4)" + [[ $(dlogutil -d DLOG_QOS_TEST0 | wc -l) -eq 60 ]] && ok || fail + + dlogsend -b main -t DLOG_QOS_TEST1 -c 300 -d 1 -f 20 "Some log spam" + LOG_DETAILS="testing if QoS works (2/4)" + [[ $(dlogutil -d DLOG_QOS_TEST1 | wc -l) -le 180 ]] && ok || fail + + dlogsend -b main -t DLOG_QOS_TEST2 -c 60 -d 1 -f 4 "A normal app that just wants to log" & + LOG_DETAILS="testing if QoS works (3/4)" + [[ $(dlogutil -d DLOG_QOS_TEST2 DLOG_QOS_TEST3 | wc -l) -le 180 ]] && ok || fail + LOG_DETAILS="testing if QoS works (4/4)" + [[ $(dlogutil -d DLOG_QOS_TEST2 | wc -l) -gt 40 ]] && ok || fail + + DLOG_CONFIG_PATH=$PREQOS_CONFIG_PATH + kill $LOGGER > /dev/null + sleep 1 + dlog_logger -b 99 -t 0 & + LOGGER=$! + sleep 1 + fi fi fi LOG_DETAILS="testing if libdlogutil clears the buffer correctly" test_libdlogutil clear $LIBDLOGUTIL_CORRECT_PID $type && ok || fail -LOG_DETAILS="testing if the library works with multithreaded app" -dlogutil -f $TESTDIR/dlog_mt_test & -MT_TEST=$! -test_libdlog && ok || fail - -sleep 1 -kill $MT_TEST -MT_TEST=-1 +if [ $quick -ne 1 ]; then + LOG_DETAILS="testing if the library works with multithreaded app" + dlogutil -f $TESTDIR/dlog_mt_test & + MT_TEST=$! + test_libdlog && ok || fail -dlogutil -c -SPAWN_CNT=1000 - -# Spawn logging scripts and wait for them to finish. -# We launch all the $SPAWN_CNT scripts in a subshell, and then use the wait command in order to -# wait for all the jobs of the subshell, which means all the logging scripts. -# Each of the logging scripts is a new subsubshell which waits a random amount of seconds and then logs -# a single message. This gets us 5 groups of logs separated by a second; there are about 200 logs in each -# group, sent about at the same time. -( - for i in `seq 1 $SPAWN_CNT`; do - delay=$(( (RANDOM) % 5 )) - ( sleep $delay && dlogsend -b main -t DLOG_TESTSUITE $delay ) & - done - wait -) + sleep 1 + kill $MT_TEST + MT_TEST=-1 + + dlogutil -c + SPAWN_CNT=1000 + + # Spawn logging scripts and wait for them to finish. + # We launch all the $SPAWN_CNT scripts in a subshell, and then use the wait command in order to + # wait for all the jobs of the subshell, which means all the logging scripts. + # Each of the logging scripts is a new subsubshell which waits a random amount of seconds and then logs + # a single message. This gets us 5 groups of logs separated by a second; there are about 200 logs in each + # group, sent about at the same time. + ( + for i in `seq 1 $SPAWN_CNT`; do + delay=$(( (RANDOM) % 5 )) + ( sleep $delay && dlogsend -b main -t DLOG_TESTSUITE $delay ) & + done + wait + ) -LOG_DETAILS="testing if libdlogutil sorts by the timestamp correctly" + LOG_DETAILS="testing if libdlogutil sorts by the timestamp correctly" -test_libdlogutil sorting $LIBDLOGUTIL_CORRECT_PID $type && ok || fail + test_libdlogutil sorting $LIBDLOGUTIL_CORRECT_PID $type && ok || fail -sort_formats="kerneltime time recv_realtime rwtime threadtime long" + sort_formats="kerneltime time recv_realtime rwtime threadtime long" -for format in $sort_formats; do - LOG_DETAILS="testing if sorting by timestamp from random sources on heavy load works ($format format)" - prev_ts=0 - unsorted="" - prev_line="" + for format in $sort_formats; do + LOG_DETAILS="testing if sorting by timestamp from random sources on heavy load works ($format format)" + prev_ts=0 + unsorted="" + prev_line="" - # collect data and analyze timestamps - lines=`dlogutil -b main -d -v $format` - while read line; do - # filter out empty lines in "long" format - [ -z "$line" ] && continue - # filter out non-timestamp lines in "long" format - if [ $format == "long" ] && [ "`echo "$line" | sed -re 's/^\[[[:print:]]*\]$/line_ok/g'`" != "line_ok" ]; then - continue - fi + # collect data and analyze timestamps + lines=`dlogutil -b main -d -v $format` + while read line; do + # filter out empty lines in "long" format + [ -z "$line" ] && continue + # filter out non-timestamp lines in "long" format + if [ $format == "long" ] && [ "`echo "$line" | sed -re 's/^\[[[:print:]]*\]$/line_ok/g'`" != "line_ok" ]; then + continue + fi - [ "$line" -eq "$line" ] 2>/dev/null && continue + [ "$line" -eq "$line" ] 2>/dev/null && continue - ts=$(extract_timestamp "$format" "$line") + ts=$(extract_timestamp "$format" "$line") - if [ "$ts" -ge "$prev_ts" ]; then - prev_ts=$ts - else - printf -v unsorted '%s\n\n%s\n%s' "$unsorted" "$prev_line" "$line" - break - fi - prev_line=$line - done <<< "$lines" + if [ "$ts" -ge "$prev_ts" ]; then + prev_ts=$ts + else + printf -v unsorted '%s\n\n%s\n%s' "$unsorted" "$prev_line" "$line" + break + fi + prev_line=$line + done <<< "$lines" - [ -z "$unsorted" ] && ok || fail -done + [ -z "$unsorted" ] && ok || fail + done -sleep 3 + sleep 3 -if [ $type == "pipe" ]; then + if [ $type == "pipe" ]; then - # spawn a new daemon with limited FDs for the FD checks - kill $LOGGER > /dev/null - sleep 1 - ULIMIT_CURRENT=`ulimit -n` - ulimit -n 30 - dlog_logger -b 99 -t 600 &> /dev/null & - LOGGER=$! - ulimit -n $ULIMIT_CURRENT + # spawn a new daemon with limited FDs for the FD checks + kill $LOGGER > /dev/null + sleep 1 + ULIMIT_CURRENT=`ulimit -n` + ulimit -n 30 + dlog_logger -b 99 -t 600 &> /dev/null & + LOGGER=$! + ulimit -n $ULIMIT_CURRENT - LOG_DETAILS="checking if the daemon closes util connections without logs stored" - run_utils - sleep 3 - [ `ls -la /proc/$LOGGER/fd | grep fifo | wc -l` -eq 0 -a `ls -la /proc/$LOGGER/fd | grep pipe | wc -l` -eq 0 ] && ok || fail + LOG_DETAILS="checking if the daemon closes util connections without logs stored" + run_utils + sleep 3 + [ `ls -la /proc/$LOGGER/fd | grep fifo | wc -l` -eq 0 -a `ls -la /proc/$LOGGER/fd | grep pipe | wc -l` -eq 0 ] && ok || fail - LOG_DETAILS="checking if the daemon closes libdlog connections" - for i in {1..30}; do - dlogsend -c $i -b main -p e -t FOO BAR BAZ & - done - dlogsend -c 99999 -b main -p e -t FOO BAR BAZ & - sleep 0.5 - kill $! - sleep 1.5 - [ `ls -la /proc/$LOGGER/fd | grep fifo | wc -l` -eq 0 -a `ls -la /proc/$LOGGER/fd | grep pipe | wc -l` -eq 0 ] && ok || fail - - LOG_DETAILS="checking if the daemon closes util connections with logs stored" - run_utils - sleep 0.5 - killall dlogutil &> /dev/null - sleep 1.5 - [ `ls -la /proc/$LOGGER/fd | grep fifo | wc -l` -eq 0 -a `ls -la /proc/$LOGGER/fd | grep pipe | wc -l` -eq 0 ] && ok || fail + LOG_DETAILS="checking if the daemon closes libdlog connections" + for i in {1..30}; do + dlogsend -c $i -b main -p e -t FOO BAR BAZ & + done + dlogsend -c 99999 -b main -p e -t FOO BAR BAZ & + sleep 0.5 + kill $! + sleep 1.5 + [ `ls -la /proc/$LOGGER/fd | grep fifo | wc -l` -eq 0 -a `ls -la /proc/$LOGGER/fd | grep pipe | wc -l` -eq 0 ] && ok || fail + + LOG_DETAILS="checking if the daemon closes util connections with logs stored" + run_utils + sleep 0.5 + killall dlogutil &> /dev/null + sleep 1.5 + [ `ls -la /proc/$LOGGER/fd | grep fifo | wc -l` -eq 0 -a `ls -la /proc/$LOGGER/fd | grep pipe | wc -l` -eq 0 ] && ok || fail + fi fi # show results, clean up and return an exit code @@ -886,6 +905,12 @@ fi echo "$OKS / $TOTAL tests passed" echo "$FAILS / $TOTAL tests failed" +if [ $quick -eq 1 ]; then + echo "WARNING: quick mode!" + echo "About 20% slowest running tests are disabled. Some functionality might be untested." + echo "Rerun with '$type' instead of '${type}_quick' to run all tests." +fi + [[ "$FAILS" -eq 0 ]] # THE LINE ABOVE MUST STAY THE LAST COMMAND IN THE FILE! # This is because it is used to pass the exit code. If another command -- 2.7.4