tests/regression/ust/java-log4j/test_java_log4j

   1 #!/bin/bash
   2 #
   3 # Copyright (C) - 2014 David Goulet <dgoulet@efficios.com>
   4 #
   5 # This program is free software; you can redistribute it and/or modify it under
   6 # the terms of the GNU General Public License, version 2 only, as published by
   7 # the Free Software Foundation.
   8 #
   9 # This program is distributed in the hope that it will be useful, but WITHOUT
  10 # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
  11 # FOR A PARTICULAR PURPOSE.  See the GNU General Public License for more
  12 # details.
  13 #
  14 # You should have received a copy of the GNU General Public License along with
  15 # this program; if not, write to the Free Software Foundation, Inc., 51
  16 # Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
  17
  18 TEST_DESC="Java LOG4J support"
  19
  20 CURDIR=$(dirname $0)/
  21 TESTDIR=$CURDIR/../../..
  22 NR_ITER=6
  23 NR_MSEC_WAIT=1000
  24 TESTAPP_NAME="JTestLTTng"
  25 TESTAPP_BIN="$TESTAPP_NAME.java"
  26 TESTAPP_PATH="$CURDIR/$TESTAPP_NAME"
  27 SESSION_NAME="log4j"
  28 EVENT_NAME="log4j-event"
  29 EVENT_NAME2="log4j-event-2"
  30 JAVA_CP="$CURDIR:/usr/local/share/java/liblttng-ust-agent.jar:/usr/share/java/*"
  31 OUTPUT_DEST="/dev/null"
  32
  33 NUM_TESTS=155
  34
  35 source $TESTDIR/utils/utils.sh
  36
  37 function run_app
  38 {
  39         local debug_tp=$1
  40         local fire_second_tp=$2
  41
  42         java -cp $JAVA_CP -Djava.library.path="/usr/local/lib:/usr/lib" $TESTAPP_NAME $NR_ITER $NR_MSEC_WAIT $debug_tp $fire_second_tp >/dev/null 2>&1
  43 }
  44
  45 function run_app_background
  46 {
  47         run_app $@ &
  48 }
  49
  50 function enable_log4j_loglevel_only()
  51 {
  52         sess_name=$1
  53         event_name="$2"
  54         loglevel=$3
  55         channel_name=$4
  56
  57         if [ -z $channel_name ]; then
  58                 # default channel if none specified
  59                 chan=""
  60         else
  61                 chan="-c $channel_name"
  62         fi
  63
  64         $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event --loglevel-only $loglevel "$event_name" $chan -s $sess_name -l >/dev/null 2>&1
  65         ok $? "Enable LOG4J event $event_name for session $sess_name with loglevel-only $loglevel"
  66 }
  67
  68 function enable_log4j_filter()
  69 {
  70         local sess_name="$1"
  71         local event_name="$2"
  72         local filter="$3"
  73
  74         $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event "$event_name" -s $sess_name -l --filter "$filter" >/dev/null 2>&1
  75         ok $? "Enable event $event_name with filter $filter for session $sess_name"
  76 }
  77
  78 function enable_log4j_filter_loglevel_only()
  79 {
  80         local sess_name="$1"
  81         local event_name="$2"
  82         local filter="$3"
  83         local loglevel="$4"
  84
  85         $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event --loglevel-only $loglevel "$event_name" -s $sess_name -l --filter "$filter" >/dev/null 2>&1
  86         ok $? "Enable event $event_name with filter \"$filter\" and loglevel-only $loglevel for session $sess_name"
  87 }
  88
  89 # MUST set TESTDIR before calling those functions
  90
  91 function test_log4j_before_start ()
  92 {
  93         diag "Test LOG4J application BEFORE tracing starts"
  94         create_lttng_session $SESSION_NAME $TRACE_PATH
  95         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
  96
  97         # Run 5 times with a 1 second delay
  98         run_app_background
  99
 100         start_lttng_tracing $SESSION_NAME
 101
 102         # Wait for the applications started in background
 103         wait ${!}
 104
 105         stop_lttng_tracing $SESSION_NAME
 106         destroy_lttng_session $SESSION_NAME
 107
 108         # Validate test. Expecting all events.
 109         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH
 110         if [ $? -ne 0 ]; then
 111                 return $?
 112         fi
 113 }
 114
 115 function test_log4j_after_start ()
 116 {
 117         diag "Test LOG4J application AFTER tracing starts"
 118
 119         create_lttng_session $SESSION_NAME $TRACE_PATH
 120         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 121         start_lttng_tracing $SESSION_NAME
 122
 123         # Run 5 times with a 1 second delay
 124         run_app
 125
 126         stop_lttng_tracing $SESSION_NAME
 127         destroy_lttng_session $SESSION_NAME
 128
 129         # Validate test. Expecting all events.
 130         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH
 131         if [ $? -ne 0 ]; then
 132                 return $?
 133         fi
 134 }
 135
 136 function test_log4j_loglevel ()
 137 {
 138         diag "Test LOG4J application with loglevel"
 139
 140         create_lttng_session $SESSION_NAME $TRACE_PATH
 141         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_INFO"
 142         start_lttng_tracing $SESSION_NAME
 143
 144         # Run 5 times with a 1 second delay
 145         run_app
 146
 147         stop_lttng_tracing $SESSION_NAME
 148         destroy_lttng_session $SESSION_NAME
 149
 150         # Validate test. Expecting all events.
 151         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH
 152         if [ $? -ne 0 ]; then
 153                 return $?
 154         fi
 155
 156         diag "Test LOG4J applications with lower loglevel"
 157
 158         create_lttng_session $SESSION_NAME $TRACE_PATH
 159         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_FATAL"
 160         start_lttng_tracing $SESSION_NAME
 161
 162         # Run 5 times with a 1 second delay
 163         run_app
 164
 165         stop_lttng_tracing $SESSION_NAME
 166         destroy_lttng_session $SESSION_NAME
 167
 168         # Validate test. Expecting 0 events.
 169         trace_match_only $EVENT_NAME 0 $TRACE_PATH
 170         if [ $? -ne 0 ]; then
 171                 return $?
 172         fi
 173
 174         diag "Test LOG4J applications with higher loglevel"
 175
 176         create_lttng_session $SESSION_NAME $TRACE_PATH
 177         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_TRACE"
 178         start_lttng_tracing $SESSION_NAME
 179
 180         # Run 5 times with a 1 second delay
 181         run_app
 182
 183         stop_lttng_tracing $SESSION_NAME
 184         destroy_lttng_session $SESSION_NAME
 185
 186         # Validate test. Expecting all events.
 187         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH
 188         return $?
 189 }
 190
 191 function test_log4j_loglevel_multiple ()
 192 {
 193         diag "Test LOG4J application with multiple loglevel"
 194
 195         create_lttng_session $SESSION_NAME $TRACE_PATH
 196         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_INFO"
 197         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_DEBUG"
 198         start_lttng_tracing $SESSION_NAME
 199
 200         # Run 5 times with a 1 second delay and fire two TP.
 201         run_app 1
 202
 203         stop_lttng_tracing $SESSION_NAME
 204         destroy_lttng_session $SESSION_NAME
 205
 206         # Validate test. Expecting all events times two.
 207         trace_match_only $EVENT_NAME $(($NR_ITER * 2)) $TRACE_PATH
 208         if [ $? -ne 0 ]; then
 209                 return $?
 210         fi
 211
 212         create_lttng_session $SESSION_NAME $TRACE_PATH
 213         enable_log4j_lttng_event_loglevel $SESSION_NAME '*' "LOG4J_INFO"
 214         enable_log4j_lttng_event_loglevel $SESSION_NAME '*' "LOG4J_DEBUG"
 215         start_lttng_tracing $SESSION_NAME
 216
 217         # Run 5 times with a 1 second delay and fire two TP.
 218         run_app 1
 219
 220         stop_lttng_tracing $SESSION_NAME
 221         destroy_lttng_session $SESSION_NAME
 222
 223         # Validate test. Expecting all events times two.
 224         trace_match_only $EVENT_NAME $(($NR_ITER * 2)) $TRACE_PATH
 225         if [ $? -ne 0 ]; then
 226                 return $?
 227         fi
 228 }
 229
 230 function test_log4j_multi_session_loglevel()
 231 {
 232         diag "Test LOG4J with multiple session"
 233
 234         create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1
 235         enable_log4j_loglevel_only $SESSION_NAME-1 '*' "LOG4J_INFO"
 236         start_lttng_tracing $SESSION_NAME-1
 237
 238         create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2
 239         enable_log4j_loglevel_only $SESSION_NAME-2 '*' "LOG4J_DEBUG"
 240         start_lttng_tracing $SESSION_NAME-2
 241
 242         # Run 5 times with a 1 second delay and fire second TP.
 243         run_app 1 1
 244
 245         stop_lttng_tracing $SESSION_NAME-1
 246         stop_lttng_tracing $SESSION_NAME-2
 247         destroy_lttng_session $SESSION_NAME-1
 248         destroy_lttng_session $SESSION_NAME-2
 249
 250         # Expecting 6 events being the main event plus the second tp.
 251         trace_match_only $EVENT_NAME $(($NR_ITER + 1)) $TRACE_PATH/$SESSION_NAME-1
 252         if [ $? -ne 0 ]; then
 253                 return $?
 254         fi
 255
 256         # Expectin 5 events being the debug TP.
 257         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-2
 258         if [ $? -ne 0 ]; then
 259                 return $?
 260         fi
 261 }
 262
 263 function test_log4j_multi_session_disable()
 264 {
 265         diag "Test LOG4J with multiple session with disabled event"
 266
 267         create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1
 268         enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME
 269         enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME2
 270         disable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME
 271         start_lttng_tracing $SESSION_NAME-1
 272
 273         create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2
 274         enable_log4j_lttng_event $SESSION_NAME-2 $EVENT_NAME2
 275         start_lttng_tracing $SESSION_NAME-2
 276
 277         # Run 5 times with a 1 second delay and fire second TP.
 278         run_app 0 1
 279
 280         stop_lttng_tracing $SESSION_NAME-1
 281         stop_lttng_tracing $SESSION_NAME-2
 282         destroy_lttng_session $SESSION_NAME-1
 283         destroy_lttng_session $SESSION_NAME-2
 284
 285         # Validate test. Expecting one event of the second TP.
 286         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-1
 287         if [ $? -ne 0 ]; then
 288                 return $?
 289         fi
 290
 291         # Validate test. Expecting one event of the second TP.
 292         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-2
 293         if [ $? -ne 0 ]; then
 294                 return $?
 295         fi
 296 }
 297
 298 function test_log4j_multi_session_disable_wildcard()
 299 {
 300         diag "Test LOG4J with multiple session with disabled wildcard event"
 301
 302         create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1
 303         enable_log4j_lttng_event $SESSION_NAME-1 '*'
 304
 305         create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2
 306         enable_log4j_lttng_event $SESSION_NAME-2 '*'
 307
 308         disable_log4j_lttng_event $SESSION_NAME-1 '*'
 309
 310         start_lttng_tracing $SESSION_NAME-1
 311         start_lttng_tracing $SESSION_NAME-2
 312
 313         run_app
 314
 315         stop_lttng_tracing $SESSION_NAME-1
 316         stop_lttng_tracing $SESSION_NAME-2
 317         destroy_lttng_session $SESSION_NAME-1
 318         destroy_lttng_session $SESSION_NAME-2
 319
 320         # Validate test. Expecting NO event of the first TP.
 321         trace_match_only $EVENT_NAME 0 $TRACE_PATH/$SESSION_NAME-1
 322         if [ $? -ne 0 ]; then
 323                 return $?
 324         fi
 325
 326         # Validate test. Expecting all events of the first TP.
 327         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-2
 328         if [ $? -ne 0 ]; then
 329                 return $?
 330         fi
 331 }
 332
 333 function test_log4j_disable_all()
 334 {
 335         diag "Test LOG4J with multiple session with disabled all event"
 336
 337         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 338         enable_log4j_lttng_event $SESSION_NAME '*'
 339         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 340         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2
 341
 342         disable_log4j_lttng_event $SESSION_NAME '*'
 343
 344         start_lttng_tracing $SESSION_NAME
 345
 346         run_app 0 1
 347
 348         stop_lttng_tracing $SESSION_NAME
 349         destroy_lttng_session $SESSION_NAME
 350
 351         # Validate test. Expecting NO event of the first TP and second TP.
 352         trace_match_only $EVENT_NAME 0 $TRACE_PATH/$SESSION_NAME
 353         trace_match_only $EVENT_NAME2 0 $TRACE_PATH/$SESSION_NAME
 354         if [ $? -ne 0 ]; then
 355                 return $?
 356         fi
 357 }
 358
 359 function test_log4j_multi_session()
 360 {
 361         diag "Test LOG4J with multiple session"
 362
 363         create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1
 364         enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME
 365         start_lttng_tracing $SESSION_NAME-1
 366
 367         create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2
 368         enable_log4j_lttng_event $SESSION_NAME-2 $EVENT_NAME2
 369         start_lttng_tracing $SESSION_NAME-2
 370
 371         # Run 5 times with a 1 second delay and fire second TP.
 372         run_app 0 1
 373
 374         stop_lttng_tracing $SESSION_NAME-1
 375         stop_lttng_tracing $SESSION_NAME-2
 376         destroy_lttng_session $SESSION_NAME-1
 377         destroy_lttng_session $SESSION_NAME-2
 378
 379         # Validate test. Expecting all events of first TP
 380         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-1
 381         if [ $? -ne 0 ]; then
 382                 return $?
 383         fi
 384
 385         # Validate test. Expecting one event of the second TP.
 386         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-2
 387         if [ $? -ne 0 ]; then
 388                 return $?
 389         fi
 390 }
 391
 392 function test_log4j_destroy_session()
 393 {
 394         diag "Test LOG4J two session with destroy"
 395
 396         create_lttng_session $SESSION_NAME $TRACE_PATH/first-sess
 397         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 398         start_lttng_tracing $SESSION_NAME
 399
 400         # Run 5 times with a 1 second delay
 401         run_app_background 0 1
 402
 403         sleep 1
 404
 405         stop_lttng_tracing $SESSION_NAME
 406         destroy_lttng_session $SESSION_NAME
 407
 408         # Validate test. Expecting at least one event num 1
 409         validate_trace $EVENT_NAME $TRACE_PATH/first-sess
 410         if [ $? -ne 0 ]; then
 411                 return $?
 412         fi
 413
 414         create_lttng_session $SESSION_NAME $TRACE_PATH/second-sess
 415         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2
 416         start_lttng_tracing $SESSION_NAME
 417
 418         # Wait for the applications started in background
 419         wait ${!}
 420
 421         stop_lttng_tracing $SESSION_NAME
 422         destroy_lttng_session $SESSION_NAME
 423
 424         # Validate test. Expecting only one event num 2
 425         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/second-sess
 426         if [ $? -ne 0 ]; then
 427                 return $?
 428         fi
 429 }
 430
 431 function test_log4j_filtering()
 432 {
 433         diag "Test LOG4J filtering"
 434
 435         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 436         # Enable all event with a filter.
 437         enable_log4j_filter $SESSION_NAME '*' 'msg == "LOG4J second logger fired"'
 438         start_lttng_tracing $SESSION_NAME
 439
 440         # Run 5 times with a 1 second delay and fire second TP.
 441         run_app 0 1
 442
 443         stop_lttng_tracing $SESSION_NAME
 444         destroy_lttng_session $SESSION_NAME
 445
 446         # Validate test. Expecting one event of the second TP only.
 447         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME
 448         if [ $? -ne 0 ]; then
 449                 return $?
 450         fi
 451
 452         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 453         # Enable first Logger but filter msg payload for the INFO one while
 454         # triggering the debug and second TP.
 455         enable_log4j_filter $SESSION_NAME $EVENT_NAME 'msg == "LOG4J tp fired!"'
 456         start_lttng_tracing $SESSION_NAME
 457
 458         # Run 5 times with a 1 second delay, fire debug and second TP.
 459         run_app 1 1
 460
 461         stop_lttng_tracing $SESSION_NAME
 462         destroy_lttng_session $SESSION_NAME
 463
 464         # Validate test. Expecting NR_ITER event of the main INFO tp.
 465         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME
 466         if [ $? -ne 0 ]; then
 467                 return $?
 468         fi
 469 }
 470
 471 function test_log4j_disable()
 472 {
 473         diag "Test LOG4J disable event"
 474
 475         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 476         # Enable all event with a filter.
 477         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 478         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2
 479         disable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 480         start_lttng_tracing $SESSION_NAME
 481
 482         # Run 5 times with a 1 second delay and fire second TP.
 483         run_app 0 1
 484
 485         stop_lttng_tracing $SESSION_NAME
 486         destroy_lttng_session $SESSION_NAME
 487
 488         # Validate test. Expecting one event of the second TP only.
 489         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME
 490         if [ $? -ne 0 ]; then
 491                 return $?
 492         fi
 493 }
 494
 495 function test_log4j_disable_enable()
 496 {
 497         diag "Test LOG4J disable event followed by an enable"
 498
 499         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 500         # Enable all event with a filter.
 501         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 502         disable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 503         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 504         start_lttng_tracing $SESSION_NAME
 505
 506         # Run 5 times with a 1 second delay and fire second TP.
 507         run_app 0 1
 508
 509         stop_lttng_tracing $SESSION_NAME
 510         destroy_lttng_session $SESSION_NAME
 511
 512         # Validate test. Expecting NR_ITER event of the main INFO tp.
 513         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME
 514         if [ $? -ne 0 ]; then
 515                 return $?
 516         fi
 517 }
 518
 519 function test_log4j_filter_loglevel()
 520 {
 521         local BOGUS_EVENT_NAME="not_a_real_event"
 522         local FILTER="int_loglevel > 700 || int_loglevel < 700"
 523         local ALL_EVENTS="."
 524
 525         diag "Test LOG4J a filter with a loglevel"
 526
 527         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 528         # Enable an event with a filter and the loglevel-only option.
 529         enable_log4j_filter_loglevel_only $SESSION_NAME $BOGUS_EVENT_NAME "$FILTER" LOG4J_INFO
 530         disable_log4j_lttng_event $SESSION_NAME $BOGUS_EVENT_NAME
 531         enable_log4j_filter_loglevel_only $SESSION_NAME $BOGUS_EVENT_NAME "$FILTER" LOG4J_INFO
 532         start_lttng_tracing $SESSION_NAME
 533
 534         # Run 5 times with a 1 second delay and fire second TP.
 535         run_app 0 1
 536
 537         stop_lttng_tracing $SESSION_NAME
 538         destroy_lttng_session $SESSION_NAME
 539
 540         # Validate test. Expecting no events.
 541         trace_match_only $ALL_EVENTS 0 $TRACE_PATH/$SESSION_NAME
 542         if [ $? -ne 0 ]; then
 543                 return $?
 544         fi
 545 }
 546
 547 plan_tests $NUM_TESTS
 548
 549 print_test_banner "$TEST_DESC"
 550
 551 if [ ! -f "$TESTAPP_PATH.class" ]; then
 552         withapp=0
 553 else
 554         withapp=1
 555 fi
 556
 557 skip $withapp "LOG4J support is needed. Skipping all tests." $NUM_TESTS ||
 558 {
 559         start_lttng_sessiond
 560
 561         tests=(
 562                 test_log4j_multi_session_disable_wildcard
 563                 test_log4j_multi_session_disable
 564                 test_log4j_disable
 565                 test_log4j_disable_enable
 566                 test_log4j_disable_all
 567                 test_log4j_filtering
 568                 test_log4j_multi_session_loglevel
 569                 test_log4j_destroy_session
 570                 test_log4j_loglevel
 571                 test_log4j_loglevel_multiple
 572                 test_log4j_before_start
 573                 test_log4j_after_start
 574                 test_log4j_multi_session
 575                 test_log4j_filter_loglevel
 576         )
 577
 578         for fct_test in ${tests[@]};
 579         do
 580                 TRACE_PATH=$(mktemp -d)
 581
 582                 ${fct_test}
 583                 if [ $? -ne 0 ]; then
 584                         break;
 585                 fi
 586                 rm -rf $TRACE_PATH
 587         done
 588
 589         stop_lttng_sessiond
 590 }