tests/dlog_test.in

   1 #!/bin/sh
   2
   3 # stuff for tracking test case counts
   4 FAILS=0
   5 OKS=0
   6 TOTAL=0
   7 LOG_DETAILS=
   8
   9 #relevant pids default vals
  10 UTIL_PID=-1
  11 DLOGSEND_PID=-1
  12 MT_TEST=-1
  13 LOGGER=-1
  14
  15 TEST_DYNAMIC_FILTERS="@DYNAMIC_FILTERS@"
  16 TESTDIR=/var/lib/dlog-tests
  17
  18 extract_timestamp() {
  19         local ts=0
  20         case "$1" in
  21                 "threadtime")
  22                         time=`echo $2 | awk -F '[ +]' '{print $2}'`
  23                         ts=`date +%s%N -d $time`
  24                 ;;
  25                 "long")
  26                         time=`echo $2 | awk -F '[ +.]' '{print $3}'`
  27                         ms=`echo $2 | awk -F '[ +.]' '{print $4}'`
  28                         sec=`date +%s%N -d $time`
  29                         ns=$((10#$ms * 1000000))
  30                         ts=$(($sec + $ns))
  31                 ;;
  32                 "rwtime")
  33                         time=`echo $2 | awk -F '[ +.]' '{print $2}'`
  34                         ts=`date +%s%N -d $time`
  35                 ;;
  36                 "recv_realtime")
  37                         time=`echo $2 | awk -F '[ +.]' '{print $2}'`
  38                         ts=`date +%s%N -d $time`
  39                 ;;
  40                 "time")
  41                         time=`echo $2 | awk -F '[ +.]' '{print $2}'`
  42                         ts=`date +%s%N -d $time`
  43                 ;;
  44                 "kerneltime")
  45                         ts=`echo $2 | awk -F '[ +]' '{print $1}' | sed -e 's/\.//g'`
  46                 ;;
  47         esac
  48         echo "$ts"
  49 }
  50
  51 cleanup() {
  52         [ $UTIL_PID -ne -1 ] && kill $UTIL_PID > /dev/null 2>&1
  53         [ $MT_TEST  -ne -1 ] && kill $MT_TEST  > /dev/null 2>&1
  54         [ $LOGGER   -ne -1 ] && kill $LOGGER   > /dev/null 2>&1
  55         [ -d $TESTDIR ] && rm -rf $TESTDIR/*
  56         [ -d $RUNTIME_FILTERS_DIR ] && rm -rf $RUNTIME_FILTERS_DIR
  57 }
  58
  59 trap cleanup 0
  60
  61 check_daemon() {
  62         local ret=1
  63         if [ $LOGGER -ne -1 ] && [ -z "$(ps -o pid= -p $LOGGER)" ]; then
  64                 ret=0
  65         fi
  66         return $ret
  67 }
  68
  69 fail() {
  70         check_daemon
  71         [ $? -eq 0 ] && daemon_status="[logger daemon not running]"
  72
  73         FAILS=$(($FAILS + 1))
  74         TOTAL=$(($TOTAL + 1))
  75         printf "[%02d] FAILED: %s %s\n" $TOTAL "$LOG_DETAILS" "$daemon_status"
  76         LOG_DETAILS=
  77 }
  78
  79 ok() {
  80         check_daemon
  81         [ $? -eq 0 ] && daemon_status="[logger daemon not running]"
  82
  83         OKS=$(($OKS + 1))
  84         TOTAL=$(($TOTAL + 1))
  85         printf "[%02d] PASSED: %s %s\n" $TOTAL "$LOG_DETAILS" "$daemon_status"
  86         LOG_DETAILS=
  87 }
  88
  89 # supress stderr messages from subcommands
  90 exec 2> /dev/null
  91
  92 if [ $# -ne 1 ]; then
  93         echo "usage: $0 pipe|logger"
  94         exit 1
  95 fi
  96
  97 if [ "$1" == "pipe" ]; then
  98         type="pipe"
  99 elif [ "$1" == "logger" ]; then
 100         type="logger"
 101 else
 102         echo "usage: $0 pipe|logger"
 103         exit 1
 104 fi
 105
 106 NEEDS_TO_QUIT=0
 107 capsh --print | grep Current | grep cap_syslog > /dev/null || { echo "*** ERROR: cap_syslog missing"; NEEDS_TO_QUIT=1; }
 108 mount | grep ' / ' | grep rw > /dev/null || { echo "*** ERROR: root not mounted read-write"; NEEDS_TO_QUIT=1; }
 109 [[ $NEEDS_TO_QUIT -eq 0 ]] || exit 1
 110
 111 if [ -z "$DLOG_CONFIG_PATH" ]; then
 112         ORIGINAL_CONFIG_PATH="/etc/dlog.conf"
 113 else
 114         ORIGINAL_CONFIG_PATH="$DLOG_CONFIG_PATH"
 115 fi
 116
 117 export DLOG_CONFIG_PATH="@datadir@/dlog-$type.conf.test"
 118 PATH=$PATH:@libexecdir@/libdlog/
 119
 120 #create dir for runtime filters
 121 RUNTIME_FILTERS_DIR="/tmp/dlog-filters/"
 122 mkdir -p "$RUNTIME_FILTERS_DIR"
 123
 124 # Start the daemon
 125 if [ $type == "pipe" ]; then
 126         dlog_logger -b 99 -t 0 &
 127         LOGGER=$!
 128         sleep 1
 129 fi
 130
 131 if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then
 132         dlogctl -c
 133         dlogctl --enable
 134         dlogutil -c -b radio -b system -b main
 135         LOG_DETAILS="dlogctl --disable (no args)"
 136         dlogctl --disable
 137         [ `dlogctl -g | grep ENABLED | wc -l` -eq 0 ] && ok || fail
 138         LOG_DETAILS="testing if filters were applied"
 139         dlogsend -b system -t TEST test
 140         dlogsend -b main -t TEST test
 141         dlogsend -b radio -t TEST test
 142         [ `dlogutil -d -b radio -b system -b main | wc -l` -eq 0 ] && ok || fail
 143
 144         LOG_DETAILS="dlogctl --enable (no args)"
 145         dlogctl --enable
 146         [ `dlogctl -g | grep DISABLED | wc -l` -eq 0 ] && ok || fail
 147         LOG_DETAILS="testing if filters were applied"
 148         dlogutil -c -b radio -b system -b main
 149         dlogsend -b system -t TEST test
 150         dlogsend -b main -t TEST test
 151         dlogsend -b radio -t TEST test
 152         [ `dlogutil -d -b radio -b system -b main | wc -l` -eq 3 ] && ok || fail
 153
 154         LOG_DETAILS="dlogctl --disable (1 arg)"
 155         dlogctl --disable -b system
 156         [ `dlogctl -g | grep DISABLED | grep system | wc -l` -eq 1 ] &&
 157         [ `dlogctl -g | grep DISABLED               | wc -l` -eq 1 ] && ok || fail
 158         LOG_DETAILS="testing if filters were applied"
 159         dlogutil -c -b radio -b system -b main
 160         dlogsend -b system -t TEST test
 161         dlogsend -b main -t TEST test
 162         dlogsend -b radio -t TEST test
 163         [ `dlogutil -d -b radio -b system -b main | wc -l` -eq 2 ] && ok || fail
 164
 165         LOG_DETAILS="dlogctl --disable (multiple args)"
 166         dlogctl --disable -b main -b radio
 167         [ `dlogctl -g | grep DISABLED | grep -v system | wc -l` -eq 2 ] &&
 168         [ `dlogctl -g | grep DISABLED | grep     radio | wc -l` -eq 1 ] &&
 169         [ `dlogctl -g | grep DISABLED | grep      main | wc -l` -eq 1 ] && ok || fail
 170         LOG_DETAILS="testing if filters were applied"
 171         dlogutil -c -b radio -b system -b main
 172         dlogsend -b system -t TEST test
 173         dlogsend -b main -t TEST test
 174         dlogsend -b radio -t TEST test
 175         [ `dlogutil -d -b radio -b system -b main | wc -l` -eq 0 ] && ok || fail
 176
 177         LOG_DETAILS="dlogctl --enable (multiple args)"
 178         dlogctl --enable -b radio -b system
 179         [ `dlogctl -g | grep DISABLED               | wc -l` -eq 1 ] &&
 180         [ `dlogctl -g | grep DISABLED | grep   main | wc -l` -eq 1 ] &&
 181         [ `dlogctl -g | grep  ENABLED | grep system | wc -l` -eq 1 ] &&
 182         [ `dlogctl -g | grep  ENABLED | grep  radio | wc -l` -eq 1 ] && ok || fail
 183         LOG_DETAILS="testing if filters were applied"
 184         dlogutil -c -b radio -b system -b main
 185         dlogsend -b system -t TEST test
 186         dlogsend -b main -t TEST test
 187         dlogsend -b radio -t TEST test
 188         [ `dlogutil -d -b radio -b system -b main | wc -l` -eq 2 ] && ok || fail
 189
 190         LOG_DETAILS="dlogctl --enable (1 arg)"
 191         dlogctl --enable -b main
 192         [ `dlogctl -g | grep DISABLED | wc -l` -eq 0 ] && ok || fail
 193         LOG_DETAILS="testing if filters were applied"
 194         dlogutil -c -b radio -b system -b main
 195         dlogsend -b system -t TEST test
 196         dlogsend -b main -t TEST test
 197         dlogsend -b radio -t TEST test
 198         [ `dlogutil -d -b radio -b system -b main | wc -l` -eq 3 ] && ok || fail
 199
 200         LOG_DETAILS="dlogctl -s allow"
 201         dlogutil -c -b radio -b system -b main
 202         dlogctl -c
 203         dlogctl -s deny
 204         dlogctl -t TEST_TAG -s allow
 205         dlogsend -b main -t TEST_TAG test
 206         dlogsend -b main -t TEST test
 207         [ `dlogutil -d -b main | wc -l` -eq 1 ] && ok || fail
 208
 209         LOG_DETAILS="dlogctl -s [N]"
 210         dlogutil -c -b radio -b system -b main
 211         dlogctl -c
 212         dlogctl -s deny
 213         dlogctl -t TEST_TAG -s 3
 214         dlogsend -b main -c 10 -t TEST_TAG test
 215         dlogsend -b main -c 10 -t TEST test
 216         [ `dlogutil -d -b main | wc -l` -eq 4 ] && ok || fail
 217
 218         LOG_DETAILS="testing invalid parameters for dlogctl (1/13)"
 219         dlogctl -s invalid &> /dev/null && fail || ok
 220
 221         LOG_DETAILS="testing invalid parameters for dlogctl (2/13)"
 222         dlogctl -p X -g &> /dev/null && fail || ok
 223
 224         LOG_DETAILS="testing invalid parameters for dlogctl (3/13)"
 225         dlogctl -b invalid --disable &> /dev/null && fail || ok
 226
 227         LOG_DETAILS="testing invalid parameters for dlogctl (4/13)"
 228         dlogctl -s allow -g -t xyz -p E &> /dev/null && fail || ok
 229
 230         LOG_DETAILS="testing invalid parameters for dlogctl (5/13)"
 231         dlogctl -s allow -c &> /dev/null && fail || ok
 232
 233         LOG_DETAILS="testing invalid parameters for dlogctl (6/13)"
 234         dlogctl -c -g -t xyz -p E &> /dev/null && fail || ok
 235
 236         # -s out of range
 237         LOG_DETAILS="testing invalid parameters for dlogctl (7/13)"
 238         dlogctl -s -10 &> /dev/null && fail || ok
 239
 240         LOG_DETAILS="testing invalid parameters for dlogctl (8/13)"
 241         dlogctl -s 999999 &> /dev/null && fail || ok
 242
 243         # -s correctness
 244         LOG_DETAILS="testing invalid parameters for dlogctl (9/13)"
 245         dlogctl -s 100 && ok || fail
 246
 247         LOG_DETAILS="testing invalid parameters for dlogctl (10/13)"
 248         [ `cat $RUNTIME_FILTERS_DIR/05-logctl.conf | grep -E 'limiter\|\*\|\*=100' | wc -l` -eq 1 ] && ok || fail
 249
 250         # -g correctness
 251         LOG_DETAILS="testing invalid parameters for dlogctl (11/13)"
 252         [ `dlogctl -g | grep '*:*' | grep 100 | wc -l` -eq 1 ] && ok || fail
 253
 254         # -c correctness
 255         LOG_DETAILS="testing invalid parameters for dlogctl (12/13)"
 256         dlogctl -c -t '*' -p '*' && ok || fail
 257
 258         LOG_DETAILS="testing invalid parameters for dlogctl (13/13)"
 259         [ `cat $RUNTIME_FILTERS_DIR/05-logctl.conf | grep -E 'limiter\|\*\|\*=100' | wc -l` -eq 0 ] && ok || fail
 260         dlogctl -c
 261
 262         LOG_DETAILS="testing if the whole dynamic config directory is respected"
 263         dlogctl -s deny
 264         cp $RUNTIME_FILTERS_DIR/{05-logctl.conf,10-other.conf}
 265         dlogctl -c
 266         dlogutil -c -b radio -b system -b main
 267         dlogsend -b system -t TEST test
 268         dlogsend -b main -t TEST test
 269         dlogsend -b radio -t TEST test
 270         [ `dlogutil -d -b radio -b system -b main | wc -l` -eq 0 ] && ok || fail
 271         rm $RUNTIME_FILTERS_DIR/10-other.conf
 272 fi
 273
 274 # put 100 log entries in the "main" buffer
 275 dlogutil -c
 276 test_libdlog 100
 277 sleep 1
 278
 279
 280 LOG_DETAILS="testing if dlogutil -d exits with success after printing logs"
 281 dlogutil -d &> /dev/null && ok || fail
 282
 283 LOG_DETAILS="testing if -t argument is parsed properly"
 284 dlogutil -t dummy &> /dev/null && fail || ok
 285
 286 LOG_DETAILS="testing if -u argument is parsed properly"
 287 dlogutil -du dummy &> /dev/null && fail || ok
 288
 289 LOG_DETAILS="testing if limiting printed log entries to less than exists in the buffer returns proper value"
 290 [ $(dlogutil -b main -t  20 | wc -l) -eq  20 ] && ok || fail # less logs than currently in buffer
 291
 292 LOG_DETAILS="testing if limiting printed log entries to more than exists in the buffer returns proper value"
 293 [ $(dlogutil -b main -t 200 | wc -l) -eq 100 ] && ok || fail # more
 294
 295 LOG_DETAILS="testing if dlogutil returns exact amount of entries as there is in the buffer"
 296 [ $(dlogutil -b main -d     | wc -l) -eq 100 ] && ok || fail # exactly
 297
 298 LOG_DETAILS="testing if reading from  dummy buffer returns an error as expected"
 299 dlogutil -b nonexistent_buffer &> /dev/null && fail || ok
 300
 301 LOG_DETAILS="testing if reading from \"system\" buffer returns zero entries (logs are in the \"main\" buffer)"
 302 [ $(dlogutil -d -b system | wc -l) -eq 0 ] && ok || fail
 303
 304 LOG_DETAILS="testing if dlogutil -c empties all buffers"
 305 dlogutil -cb main && ok || fail
 306
 307 LOG_DETAILS="testing if writing entries to empty buffer and reading them returns proper amount of entries"
 308 test_libdlog 10
 309 [ $(dlogutil -b main -d | wc -l) -eq 10 ] && ok || fail # should be 10, not 110
 310
 311 LOG_DETAILS="testing if filters work (1/3)"
 312 [ $(dlogutil -b main -d *:E | wc -l) -eq 5 ] && ok || fail # half of current logs (test_libdlog alternates between error and info log levels)
 313
 314 LOG_DETAILS="testing if filters work (2/3)"
 315 [ $(dlogutil -b main -d *:W | wc -l) -eq 5 ] && ok || fail
 316
 317 LOG_DETAILS="testing if filters work (3/3)"
 318 [ $(dlogutil -b main -d *:I | wc -l) -eq 10 ] && ok || fail
 319
 320 LOG_DETAILS="testing if exact filters work (1/3)"
 321 [ $(dlogutil -b main -d *:=E | wc -l) -eq 5 ] && ok || fail
 322
 323 LOG_DETAILS="testing if exact filters work (2/3)"
 324 [ $(dlogutil -b main -d *:=W | wc -l) -eq 0 ] && ok || fail
 325
 326 LOG_DETAILS="testing if exact filters work (3/3)"
 327 [ $(dlogutil -b main -d *:=I | wc -l) -eq 5 ] && ok || fail
 328
 329 LOG_DETAILS="testing if adding \"silent\" filter works"
 330 [ $(dlogutil -b main -s -d | wc -l) -eq 0 ] && ok || fail
 331
 332 LOG_DETAILS="testing if reading buffer size returns proper exit code"
 333 dlogutil -gb main &> /dev/null && ok || fail
 334
 335 LOG_DETAILS="testing if writing all entries to single file works (-f)"
 336 dlogutil -f $TESTDIR/dlog_test_file -d &> /dev/null && ok || fail
 337
 338 LOG_DETAILS="testing if the continuous mode works as expected (1/2)"
 339 dlogutil -b main -f $TESTDIR/dlog_continuous1_file &
 340 UTIL_PID=$!
 341 sleep 1
 342 kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0
 343 UTIL_PID=-1
 344 [[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_continuous1_file` -eq 10 ]] && ok || fail
 345
 346 LOG_DETAILS="testing if the continuous mode works as expected (2/2)"
 347 dlogutil -b main -f $TESTDIR/dlog_continuous2_file &
 348 UTIL_PID=$!
 349 sleep 1
 350 dlogsend -b main "Hi!"
 351 sleep 1
 352 kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0
 353 UTIL_PID=-1
 354 [[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_continuous2_file` -eq 11 ]] && ok || fail
 355
 356 LOG_DETAILS="testing if the monitor mode works as expected (1/2)"
 357 dlogutil -mb main -f $TESTDIR/dlog_monitor1_file &
 358 UTIL_PID=$!
 359 sleep 1
 360 kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0
 361 UTIL_PID=-1
 362 [[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_monitor1_file` -eq 0 ]] && ok || fail
 363
 364 LOG_DETAILS="testing if the monitor mode works as expected (2/2)"
 365 dlogutil -mb main -f $TESTDIR/dlog_monitor2_file &
 366 UTIL_PID=$!
 367 sleep 1
 368 dlogsend -b main "Hi!"
 369 sleep 1
 370 kill $UTIL_PID && WAS_ALIVE=1 || WAS_ALIVE=0
 371 UTIL_PID=-1
 372 [[ $WAS_ALIVE -eq 1 && `wc -l < $TESTDIR/dlog_monitor2_file` -eq 1 ]] && ok || fail
 373
 374 LOG_DETAILS="testing if writing entries to rotating files works (-r/-n)"
 375 dlogutil -f $TESTDIR/dlog_rotating_file -r 12 -n 3 & # 3 files at 12 KB each
 376 UTIL_PID=$!
 377
 378 test_libdlog 100000 &
 379 LIBDLOGUTIL_CORRECT_PID=$!
 380 wait $LIBDLOGUTIL_CORRECT_PID
 381
 382 LOG_DETAILS="testing if single file is properly created"
 383 if [ -e $TESTDIR/dlog_test_file ]; then ok; else fail; fi
 384
 385 LOG_DETAILS="testing if rotating file is properly created (1/4)"
 386 if [ -e $TESTDIR/dlog_rotating_file.1 ]; then ok; else fail; fi
 387
 388 LOG_DETAILS="testing if rotating file is properly created (2/4)"
 389 if [ -e $TESTDIR/dlog_rotating_file.2 ]; then ok; else fail; fi
 390
 391 LOG_DETAILS="testing if rotating file is properly created (3/4)"
 392 if [ -e $TESTDIR/dlog_rotating_file.3 ]; then ok; else fail; fi
 393
 394 LOG_DETAILS="testing if rotating file is properly created (4/4)"
 395 if [ -e $TESTDIR/dlog_rotating_file.4 ]; then fail; else ok; fi
 396
 397 LOG_DETAILS="testing the size of log files"
 398 if [ $(du $TESTDIR/dlog_rotating_file.3 | sed "s#$TESTDIR/dlog_rotating_file.3##g") -eq 16 ]; then ok; else fail; fi # the actual size is one sector more (so 12 -> 16) because the limit is checked after reaching it, not before
 399
 400 kill $UTIL_PID
 401 UTIL_PID=-1
 402
 403 LOG_DETAILS="testing if libdlogutil works correctly in the dump mode"
 404 test_libdlogutil dump $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 405 LOG_DETAILS="testing if libdlogutil works correctly if processing the logs takes some time"
 406 test_libdlogutil timer $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 407 LOG_DETAILS="testing if libdlogutil works correctly in the continuous mode"
 408 test_libdlogutil continuous $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 409 LOG_DETAILS="testing if libdlogutil skips all the logs in the monitor mode correctly"
 410 test_libdlogutil monitor $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 411 LOG_DETAILS="testing if libdlogutil priority filter works correctly"
 412 test_libdlogutil priority $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 413 LOG_DETAILS="testing if libdlogutil exact priority filter works correctly"
 414 test_libdlogutil priority_exact $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 415 LOG_DETAILS="testing if libdlogutil limits the log amount correctly"
 416 test_libdlogutil limit $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 417 LOG_DETAILS="testing if libdlogutil PID filter works correctly (1/2)"
 418 test_libdlogutil pid_correct $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 419 LOG_DETAILS="testing if libdlogutil PID filter works correctly (2/2)"
 420 test_libdlogutil pid_wrong $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 421 LOG_DETAILS="testing if libdlogutil TID filter works correctly (1/2)"
 422 test_libdlogutil tid_correct $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 423 LOG_DETAILS="testing if libdlogutil TID filter works correctly (2/2)"
 424 test_libdlogutil tid_wrong $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 425 LOG_DETAILS="testing if libdlogutil tag filter works correctly (1/2)"
 426 test_libdlogutil tag_correct $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 427 LOG_DETAILS="testing if libdlogutil tag filter works correctly (2/2)"
 428 test_libdlogutil tag_wrong $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 429 LOG_DETAILS="testing if libdlogutil prefix filter works correctly (1/2)"
 430 test_libdlogutil prefix_correct $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 431 LOG_DETAILS="testing if libdlogutil prefix filter works correctly (2/2)"
 432 test_libdlogutil prefix_wrong $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 433 LOG_DETAILS="testing if libdlogutil returns the correct buffer traits"
 434 test_libdlogutil traits $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 435 LOG_DETAILS="testing if libdlogutil aliasing works"
 436 if [ $type == "pipe" ]; then
 437         test_libdlogutil alias $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 438 else
 439         DLOG_CONFIG_PATH="@datadir@/dlog-logger.conf.alias" test_libdlogutil alias $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 440 fi
 441 LOG_DETAILS="testing if libdlogutil errors out correctly if used improperly"
 442 test_libdlogutil negative $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 443
 444 cmd_prefix="dlogutil -t 1 -u 0 -v"
 445
 446 format="process"
 447 regex_prio="[VDIWEFS]{1}"
 448 regex_pidtid="P[0-9[:space:]]{5,},\s{1}T[0-9[:space:]]{5,}"
 449 regex_time="[0-9]{2}-[0-9]{2}\s{1}[0-9]{2}:[0-9]{2}:[0-9]{2}"
 450 regex_timezone="[\+-]{1}[0-9]{4}"
 451
 452 for PARAM in always auto none never; do
 453         for PRIO in info error; do
 454                 for OUTPUT in pipe tty; do
 455                         if [[ "$PARAM" == "always" ]]; then
 456                                 COLOR_EXPECTED=1
 457                         elif [[ "$PARAM" == "never" ]]; then
 458                                 COLOR_EXPECTED=0
 459                         elif [[ "$OUTPUT" == "tty" ]]; then
 460                                 COLOR_EXPECTED=1
 461                         else
 462                                 COLOR_EXPECTED=0
 463                         fi
 464
 465                         if [[ "$PRIO" == "info" ]]; then
 466                                 REGEX="s/^I\([0-9[:space:]]{5,}\)[[:print:]]*\([[:print:]]*\)@$/1/g"
 467                         elif [[ "$COLOR_EXPECTED" -eq 0 ]]; then
 468                                 REGEX="s/^E\([0-9[:space:]]{5,}\)[[:print:]]*\([[:print:]]*\)@$/1/g"
 469                         else
 470                                 REGEX="s/^~\[31;1mE\([0-9[:space:]]{5,}\) ~\[0m[[:print:]]*~\[31;1m  \([[:print:]]*\)@~\[0m$/1/g"
 471                         fi
 472
 473                         # -t 1 instead of | head -n 1 because the `script` command can't cope with SIGPIPE.
 474                         COMMAND="$cmd_prefix $format"
 475
 476                         if [[ "$PARAM" == "none" ]]; then
 477                                 LOG_DETAILS="testing if color output is correct (implicit --color=auto/$PRIO priority/$OUTPUT output)"
 478                         else
 479                                 COMMAND="$COMMAND --color=$PARAM"
 480                                 LOG_DETAILS="testing if color output is correct (--color=$PARAM/$PRIO priority/$OUTPUT output)"
 481                         fi
 482
 483                         if [[ "$PRIO" == "info" ]]; then
 484                                 COMMAND="$COMMAND '*:=I'"
 485                         else
 486                                 COMMAND="$COMMAND '*:=E'"
 487                         fi
 488
 489                         if [[ "$OUTPUT" == "tty" ]]; then
 490                                 # This emulates a TTY. The sed call is because `script` likes to mess up the output for some reason.
 491                                 COMMAND="script -qc\"$COMMAND\" /dev/null | sed 's/\r$//'"
 492                         fi
 493
 494                         # `eval` is needed since `$COMMAND` may contain `"`
 495                         line=`eval $COMMAND | tr '\033\n' '~@'`
 496                         [[ `echo "$line" | sed -re "$REGEX"` == "1" ]] && ok || fail
 497                 done
 498         done
 499 done
 500 # TODO: It would be cool to also test warning messages (which have a different color),
 501 # but this would require deeper changes to this script, which is already janky enough.
 502
 503 REGEX="s/^$regex_prio\([0-9[:space:]]{5,}\)[[:print:]]*\([[:print:]]*\)$/1/g"
 504 LOG_DETAILS="testing if \"$format\" print format works"
 505 line=`$cmd_prefix $format`
 506 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 507
 508 format="tag"
 509 REGEX="s/^$regex_prio\/[[:print:]]{9,}:\s{1}[[:print:]]*$/1/g"
 510 LOG_DETAILS="testing if \"$format\" print format works"
 511 line=`$cmd_prefix $format`
 512 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 513
 514 format="thread"
 515 REGEX="s/^$regex_prio\($regex_pidtid\)\s{1}[[:print:]]*$/1/g"
 516 LOG_DETAILS="testing if \"$format\" print format works"
 517 line=`$cmd_prefix $format`
 518 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 519
 520 format="time"
 521 REGEX="s/^$regex_time.[0-9]{3}$regex_timezone\s{1}$regex_prio\/[[:print:]]{8,}\([0-9[:space:]]{5,}\):\s{1}[[:print:]]*$/1/g"
 522 LOG_DETAILS="testing if \"$format\" print format works"
 523 line=`$cmd_prefix $format`
 524 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 525
 526 format="threadtime"
 527 REGEX="s/^$regex_time.[0-9]{3}$regex_timezone\s{1}$regex_prio\/[[:print:]]{8,}\($regex_pidtid\):\s{1}[[:print:]]*$/1/g"
 528 LOG_DETAILS="testing if \"$format\" print format works"
 529 line=`$cmd_prefix $format`
 530 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 531
 532 format="kerneltime"
 533 REGEX="s/^[0-9[:space:]]{1,}.[0-9]{3,}\s{1}$regex_prio\/[[:print:]]{8,}\($regex_pidtid\):\s{1}[[:print:]]*$/1/g"
 534 LOG_DETAILS="testing if \"$format\" print format works"
 535 line=`$cmd_prefix $format`
 536 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 537
 538 format="recv_realtime"
 539 REGEX="s/^$regex_time.[0-9]{3}\s{1}$regex_prio\/[[:print:]]{8,}\($regex_pidtid\):\s{1}[[:print:]]*$/1/g"
 540 LOG_DETAILS="testing if \"$format\" print format works"
 541 line=`$cmd_prefix $format`
 542 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 543
 544 format="rwtime"
 545 REGEX="s/^$regex_time\s{1}\[[0-9[:space:]]{3,}.[0-9[:space:]]{3,}\]\s{1}$regex_prio\/[[:print:]]{8,}\($regex_pidtid\):\s{1}[[:print:]]*$/1/g"
 546 LOG_DETAILS="testing if \"$format\" print format works"
 547 line=`$cmd_prefix $format`
 548 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 549
 550 format="long"
 551 REGEX="s/^\[\s{1}$regex_time.[0-9]{3,}\s{1}$regex_prio\/[[:print:]]{8,}\s{1}$regex_pidtid\]@[[:print:]]+@$/1/g"
 552 LOG_DETAILS="testing if \"$format\" print format works"
 553 line=`$cmd_prefix $format`
 554 [[ `echo "$line" | tr '\n' '@' | sed -re $REGEX` == "1" ]] && ok || fail
 555
 556 format="brief"
 557 REGEX="s/^$regex_prio\/[[:print:]]{8,}\([0-9[:space:]]{5,}\):\s{1}[[:print:]]*$/1/g"
 558 LOG_DETAILS="testing if \"$format\" print format works"
 559 line=`$cmd_prefix $format`
 560 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 561
 562 format="json"
 563 if [[ "$type" == "pipe" ]]; then
 564         REGEX="s/^\{\"priority\":\"(verbose|debug|info|warning|error|fatal|silent)\",\"pid\":[1-9][0-9]*,\"tid\":[1-9][0-9]*,\"recv_real\":\"[0-9]{4}-[0-9]{2}-[0-9]{2}T[0-9]{2}:[0-9]{2}:[0-9]{2}$regex_timezone\",\"recv_mono\":[1-9][0-9]+\.[0-9]{9},\"sent_real\":\"[0-9]{4}-[0-9]{2}-[0-9]{2}T[0-9]{2}:[0-9]{2}:[0-9]{2}$regex_timezone\",\"sent_mono\":[1-9][0-9]+\.[0-9]{9},\"tag\":\"[[:print:]]*\",\"msg\":\"[[:print:]]*\"\}$/1/g"
 565 else
 566         REGEX="s/^\{\"priority\":\"(verbose|debug|info|warning|error|fatal|silent)\",\"pid\":[1-9][0-9]*,\"tid\":[1-9][0-9]*,\"sent_real\":\"[0-9]{4}-[0-9]{2}-[0-9]{2}T[0-9]{2}:[0-9]{2}:[0-9]{2}$regex_timezone\",\"tag\":\"[[:print:]]*\",\"msg\":\"[[:print:]]*\"\}$/1/g"
 567 fi
 568 LOG_DETAILS="testing if \"$format\" print format works"
 569 line=`$cmd_prefix $format`
 570 [[ `echo "$line" | sed -re $REGEX` == "1" ]] && ok || fail
 571
 572 format="raw"
 573 LOG_DETAILS="testing if \"$format\" print format works"
 574 dlogutil -c
 575 dlogsend -b main -t DLOG_TESTSUITE rawformatTEST
 576 line=`$cmd_prefix $format`
 577 [[ "$line" == "rawformatTEST" ]] && ok || fail
 578
 579 LOG_DETAILS="testing if dlogsend -d works"
 580 dlogutil -c
 581 dlogsend -b main -c 9999 -d 4 -f 7 -t DLOG_TESTSUITE "hi" &
 582 DLOGSEND_PID=$!
 583 sleep 10
 584 kill $DLOGSEND_PID
 585 # In 10 seconds, 3 cycles 7 logs each should have happened.
 586 [[ "$(dlogutil -d DLOG_TESTSUITE | wc -l)" -eq 21 ]] && ok || fail
 587
 588 if [ $type == "pipe" ]; then
 589         for format in raw brief long; do
 590                 for i in {1..8} 10 15 20 25 {513..520}; do
 591                         LOG_DETAILS="testing if padding works correctly (format $format/count $i)"
 592                         log=$(printf '%0.s&' $(seq 1 $i)) # Print the '&' character $i times
 593
 594                         dlogutil -c
 595                         dlogsend -b main $log
 596                         line=$($cmd_prefix $format | tr '\n' '@')
 597
 598                         case $format in
 599                                 raw)
 600                                         REGEX="s/$log@/1/g"
 601                                         ;;
 602                                 brief)
 603                                         REGEX="s/I\/DLOG_SEND\([0-9[:space:]]{5,}\):\s{1}$log@$/1/g"
 604                                         ;;
 605                                 long)
 606                                         REGEX="s/\[\s{1}$regex_time.[0-9]{3,}\s{1}I\/DLOG_SEND\s{1}$regex_pidtid\]@$log@@/1/g"
 607                                         ;;
 608                         esac
 609
 610                         [[ $(echo "$line" | sed -re $REGEX) == "1" ]] && ok || fail
 611                 done
 612         done
 613 fi
 614
 615 LOG_DETAILS="testing if KMSG works in the default format"
 616 # We check if the command returns at least 100 logs. This seems to be a safe value.
 617 # Feel free to change it to a reasonable yet lower value if the test happens to fail otherwise.
 618 [[ "$(dlogutil -db kmsg | wc -l)" -gt 100 ]] && ok || fail
 619
 620 LOG_DETAILS="testing if KMSG works in the raw format"
 621 last_dmesg=`dmesg | tail -n1 | sed -re "s/^\[[ 0-9]{5,}\.[0-9]{6}\] (.*)$/\1/g"`
 622 sleep 1 # To make sure dlog has already parsed the log
 623 dlogutil -db kmsg -v raw | grep -Fm1 "$last_dmesg" >/dev/null && ok || fail
 624
 625 LOG_DETAILS="testing if pid filtering works"
 626 dlogsend -b main -t DLOG_TESTSUITE pidTEST &
 627 sleep 1
 628 line=`dlogutil -v raw -d --pid $!`
 629 [[ "$line" == "pidTEST" ]] && ok || fail
 630
 631 LOG_DETAILS="testing if tid filtering works"
 632 dlogsend -b main -t DLOG_TESTSUITE tidTEST &
 633 sleep 1
 634 line=`dlogutil -v raw -d --tid $!` #dlogsend is a single threaded app so tid is the same as pid
 635 [[ "$line" == "tidTEST" ]] && ok || fail
 636
 637 mv $DLOG_CONFIG_PATH $DLOG_CONFIG_PATH.1
 638 LOG_DETAILS="testing if secure logging works (1/2)"
 639 grep -v enable_secure_logs $DLOG_CONFIG_PATH.1 > $DLOG_CONFIG_PATH
 640 echo "enable_secure_logs=1" >> $DLOG_CONFIG_PATH
 641 dlogutil -c
 642 dlogsend -zb main -t DLOG_TESTSUITE secure &
 643 sleep 1
 644 dlogsend -b main -t DLOG_TESTSUITE insecure &
 645 sleep 1
 646 line=`dlogutil -v raw -d | head -n1`
 647 [[ "$line" == "secure" ]] && ok || fail
 648 LOG_DETAILS="testing if secure logging works (2/2)"
 649 grep -v enable_secure_logs $DLOG_CONFIG_PATH.1 > $DLOG_CONFIG_PATH
 650 echo "enable_secure_logs=0" >> $DLOG_CONFIG_PATH
 651 dlogutil -c
 652 dlogsend -zb main -t DLOG_TESTSUITE secure &
 653 sleep 1
 654 dlogsend -b main -t DLOG_TESTSUITE insecure &
 655 sleep 1
 656 line=`dlogutil -v raw -d | head -n1`
 657 [[ "$line" == "insecure" ]] && ok || fail
 658 mv $DLOG_CONFIG_PATH.1 $DLOG_CONFIG_PATH
 659
 660 dlogsend -b main -t DLOG_TESTSUITE_TAG0 -pI tagTEST0
 661 dlogsend -b main -t DLOG_TESTSUITE_TAG1 -pI tagTEST1
 662 dlogsend -b main -t DLOG_TESTSUITE_TAG2 -pF tagTEST2
 663
 664 LOG_DETAILS="testing if tag filtering works (1/8)"
 665 [[ `dlogutil -dv raw 'DLOG_TESTSUITE_TAG0' | wc -l` -eq 1 ]] && ok || fail
 666 LOG_DETAILS="testing if tag filtering works (2/8)"
 667 [[ `dlogutil -dv raw 'DLOG_TESTSUITE_TAG1' | wc -l` -eq 1 ]] && ok || fail
 668 LOG_DETAILS="testing if tag filtering works (3/8)"
 669 [[ `dlogutil -dv raw 'DLOG_TESTSUITE_TAG' | wc -l` -eq 0 ]] && ok || fail
 670 LOG_DETAILS="testing if tag filtering works (4/8)"
 671 [[ `dlogutil -dv raw 'DLOG_TESTSUITE_TAG*' | wc -l` -eq 3 ]] && ok || fail
 672 LOG_DETAILS="testing if tag filtering works (5/8)"
 673 [[ `dlogutil -dv raw 'DLOG_TESTSUITE_TAG*:I' | wc -l` -eq 3 ]] && ok || fail
 674 LOG_DETAILS="testing if tag filtering works (6/8)"
 675 [[ `dlogutil -dv raw 'DLOG_TESTSUITE_TAG*:W' | wc -l` -eq 1 ]] && ok || fail
 676 LOG_DETAILS="testing if tag filtering works (7/8)"
 677 [[ `dlogutil -dv raw 'DLOG_TESTSUITE_SAMSUNG' | wc -l` -eq 0 ]] && ok || fail
 678 LOG_DETAILS="testing if tag filtering works (8/8)"
 679 [[ `dlogutil -dv raw 'DLOG_TESTSUITE_SAMSUNG*' | wc -l` -eq 0 ]] && ok || fail
 680
 681 if [ "$TEST_DYNAMIC_FILTERS" == "true" ]; then
 682         LOG_DETAILS="testing if limiter and runtime filtering works"
 683         dlogutil -c -b radio
 684         test_filters
 685         [ $(dlogutil -d -b radio | wc -l) -eq 12 ] && ok || fail
 686
 687         LOG_DETAILS="testing proper SMACK label for dynamic config file location"
 688         ORIG_FILTERS_DIR=$(cat $ORIGINAL_CONFIG_PATH | grep dynamic_config_path | awk -F "=" '{print $2}')
 689         [ $(ls -dZ $ORIG_FILTERS_DIR | awk -F " " '{print $1}') == "System::Shared" ] && ok || fail
 690
 691         # This creates a process which will wait for SIGCONT and then spam logs. We know its PID, so we can add
 692         # PID-based limits and see what happens.
 693         sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' &
 694         DLOGSEND_PID=$!
 695         while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done
 696         dlogctl --pid $DLOGSEND_PID -s deny
 697         kill -s CONT $DLOGSEND_PID
 698         wait $DLOGSEND_PID
 699         LOG_DETAILS="testing if PID limiting works (1/10)"
 700         [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 0 ]] && ok || fail
 701         LOG_DETAILS="testing if PID limiting works (2/10)"
 702         [[ $(dlogctl --pid $DLOGSEND_PID -g) == "Denied" ]] && ok || fail
 703         LOG_DETAILS="testing if PID limiting works (3/10)"
 704         dlogctl -g | grep -q "Denied for $DLOGSEND_PID" && ok || fail
 705
 706         sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' &
 707         DLOGSEND_PID=$!
 708         while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done
 709         dlogctl --pid $DLOGSEND_PID -s 25
 710         kill -s CONT $DLOGSEND_PID
 711         wait $DLOGSEND_PID
 712         LOG_DETAILS="testing if PID limiting works (4/10)"
 713         [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 25 ]] && ok || fail
 714         LOG_DETAILS="testing if PID limiting works (5/10)"
 715         [[ $(dlogctl --pid $DLOGSEND_PID -g) == '25 logs/min' ]] && ok || fail
 716         LOG_DETAILS="testing if PID limiting works (6/10)"
 717         dlogctl -g | grep -q "25 logs/min for $DLOGSEND_PID" && ok || fail
 718
 719         sh -c 'kill -s STOP $$; exec dlogsend -b main -c 100 "Pid test"' &
 720         DLOGSEND_PID=$!
 721         while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done
 722         dlogctl --pid $DLOGSEND_PID -s allow
 723         kill -s CONT $DLOGSEND_PID
 724         wait $DLOGSEND_PID
 725         LOG_DETAILS="testing if PID limiting works (7/10)"
 726         [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 100 ]] && ok || fail
 727         LOG_DETAILS="testing if PID limiting works (8/10)"
 728         [[ $(dlogctl --pid $DLOGSEND_PID -g) == 'Unlimited' ]] && ok || fail
 729         LOG_DETAILS="testing if PID limiting works (9/10)"
 730         dlogctl -g | grep -q "Unlimited for $DLOGSEND_PID" && ok || fail
 731
 732         echo "qos_refresh_rate_s=5" > "$RUNTIME_FILTERS_DIR/69-refresh-rate.conf"
 733         sh -c 'kill -s STOP $$; exec dlogsend -b main -c 15 -d 1 "Pid test"' &
 734         DLOGSEND_PID=$!
 735         while [[ $(cut -d ' ' -f 3 < /proc/$DLOGSEND_PID/stat) != "T" ]]; do :; done
 736         dlogctl --pid $DLOGSEND_PID -s 2
 737         kill -s CONT $DLOGSEND_PID
 738         wait $DLOGSEND_PID
 739         rm "$RUNTIME_FILTERS_DIR/69-refresh-rate.conf"
 740         LOG_DETAILS="testing if PID limiting works (10/10)"
 741         # In each 5 second period, 5 logs are sent, so there are 3 periods.
 742         # 2 logs from each period are allowed.
 743         [[ $(dlogutil --pid $DLOGSEND_PID -d | wc -l) -eq 6 ]] && ok || fail
 744 fi
 745
 746 LOG_DETAILS="testing if libdlogutil clears the buffer correctly"
 747 test_libdlogutil clear $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 748
 749 LOG_DETAILS="testing if the library works with multithreaded app"
 750 dlogutil -f $TESTDIR/dlog_mt_test &
 751 MT_TEST=$!
 752 test_libdlog && ok || fail
 753
 754 sleep 1
 755 kill $MT_TEST
 756 MT_TEST=-1
 757
 758 dlogutil -c
 759 SPAWN_CNT=1000
 760
 761 # Spawn logging scripts and wait for them to finish.
 762 # We launch all the $SPAWN_CNT scripts in a subshell, and then use the wait command in order to
 763 # wait for all the jobs of the subshell, which means all the logging scripts.
 764 # Each of the logging scripts is a new subsubshell which waits a random amount of seconds and then logs
 765 # a single message. This gets us 5 groups of logs separated by a second; there are about 200 logs in each
 766 # group, sent about at the same time.
 767 (
 768         for i in `seq 1 $SPAWN_CNT`; do
 769                 delay=$(( (RANDOM) % 5 ))
 770                 ( sleep $delay && dlogsend -b main -t DLOG_TESTSUITE $delay ) &
 771         done
 772         wait
 773 )
 774
 775 LOG_DETAILS="testing if libdlogutil sorts by the timestamp correctly"
 776
 777 test_libdlogutil sorting $LIBDLOGUTIL_CORRECT_PID $type && ok || fail
 778
 779 sort_formats="kerneltime time recv_realtime rwtime threadtime long"
 780
 781 for format in $sort_formats; do
 782         LOG_DETAILS="testing if sorting by timestamp from random sources on heavy load works ($format format)"
 783         prev_ts=0
 784         unsorted=""
 785         prev_line=""
 786
 787         # collect data and analyze timestamps
 788         lines=`dlogutil -b main -d -v $format`
 789         while read line; do
 790                 # filter out empty lines in "long" format
 791                 [ -z "$line" ] && continue
 792                 # filter out non-timestamp lines in "long" format
 793                 if [ $format == "long" ] && [ "`echo "$line" | sed -re 's/^\[[[:print:]]*\]$/line_ok/g'`" != "line_ok" ]; then
 794                         continue
 795                 fi
 796
 797                 [ "$line" -eq "$line" ] 2>/dev/null && continue
 798
 799                 ts=$(extract_timestamp "$format" "$line")
 800
 801                 if [ "$ts" -ge "$prev_ts" ]; then
 802                         prev_ts=$ts
 803                 else
 804                         printf -v unsorted '%s\n\n%s\n%s' "$unsorted" "$prev_line" "$line"
 805                         break
 806                 fi
 807                 prev_line=$line
 808         done <<< "$lines"
 809
 810         [ -z "$unsorted" ] && ok || fail
 811 done
 812
 813 sleep 3
 814
 815 if [ $type == "pipe" ]; then
 816
 817         # spawn a new daemon with limited FDs for the FD checks
 818         kill $LOGGER > /dev/null
 819         sleep 1
 820         ULIMIT_CURRENT=`ulimit -n`
 821         ulimit -n 30
 822         dlog_logger -b 99 -t 600 &> /dev/null &
 823         LOGGER=$!
 824         ulimit -n $ULIMIT_CURRENT
 825
 826         LOG_DETAILS="checking if the daemon closes util connections without logs stored"
 827         run_utils
 828         sleep 3
 829         [ `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
 830
 831         LOG_DETAILS="checking if the daemon closes libdlog connections"
 832         for i in {1..30}; do
 833                 dlogsend -c $i -b main -p e -t FOO BAR BAZ &
 834         done
 835         dlogsend -c 99999 -b main -p e -t FOO BAR BAZ &
 836         sleep 0.5
 837         kill $!
 838         sleep 1.5
 839         [ `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
 840
 841         LOG_DETAILS="checking if the daemon closes util connections with logs stored"
 842         run_utils
 843         sleep 0.5
 844         killall dlogutil &> /dev/null
 845         sleep 1.5
 846         [ `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
 847 fi
 848
 849 # show results, clean up and return an exit code
 850
 851 echo "$OKS / $TOTAL tests passed"
 852 echo "$FAILS / $TOTAL tests failed"
 853
 854 [[ "$FAILS" -eq 0 ]]
 855 # THE LINE ABOVE MUST STAY THE LAST COMMAND IN THE FILE!
 856 # This is because it is used to pass the exit code. If another command
 857 # is executed after it, its exit code will be propagated instead.