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         #FIXME: racy missing synchronization
 101
 102         start_lttng_tracing $SESSION_NAME
 103
 104         # Wait for the applications started in background
 105         wait
 106
 107         stop_lttng_tracing $SESSION_NAME
 108         destroy_lttng_session $SESSION_NAME
 109
 110         # Validate test. Expecting all events.
 111         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH
 112         if [ $? -ne 0 ]; then
 113                 return $?
 114         fi
 115 }
 116
 117 function test_log4j_after_start ()
 118 {
 119         diag "Test LOG4J application AFTER tracing starts"
 120
 121         create_lttng_session $SESSION_NAME $TRACE_PATH
 122         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 123         start_lttng_tracing $SESSION_NAME
 124
 125         # Run 5 times with a 1 second delay
 126         run_app
 127
 128         stop_lttng_tracing $SESSION_NAME
 129         destroy_lttng_session $SESSION_NAME
 130
 131         # Validate test. Expecting all events.
 132         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH
 133         if [ $? -ne 0 ]; then
 134                 return $?
 135         fi
 136 }
 137
 138 function test_log4j_loglevel ()
 139 {
 140         diag "Test LOG4J application with loglevel"
 141
 142         create_lttng_session $SESSION_NAME $TRACE_PATH
 143         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_INFO"
 144         start_lttng_tracing $SESSION_NAME
 145
 146         # Run 5 times with a 1 second delay
 147         run_app
 148
 149         stop_lttng_tracing $SESSION_NAME
 150         destroy_lttng_session $SESSION_NAME
 151
 152         # Validate test. Expecting all events.
 153         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH
 154         if [ $? -ne 0 ]; then
 155                 return $?
 156         fi
 157
 158         diag "Test LOG4J applications with lower loglevel"
 159
 160         create_lttng_session $SESSION_NAME $TRACE_PATH
 161         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_FATAL"
 162         start_lttng_tracing $SESSION_NAME
 163
 164         # Run 5 times with a 1 second delay
 165         run_app
 166
 167         stop_lttng_tracing $SESSION_NAME
 168         destroy_lttng_session $SESSION_NAME
 169
 170         # Validate test. Expecting 0 events.
 171         trace_match_only $EVENT_NAME 0 $TRACE_PATH
 172         if [ $? -ne 0 ]; then
 173                 return $?
 174         fi
 175
 176         diag "Test LOG4J applications with higher loglevel"
 177
 178         create_lttng_session $SESSION_NAME $TRACE_PATH
 179         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_TRACE"
 180         start_lttng_tracing $SESSION_NAME
 181
 182         # Run 5 times with a 1 second delay
 183         run_app
 184
 185         stop_lttng_tracing $SESSION_NAME
 186         destroy_lttng_session $SESSION_NAME
 187
 188         # Validate test. Expecting all events.
 189         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH
 190         return $?
 191 }
 192
 193 function test_log4j_loglevel_multiple ()
 194 {
 195         diag "Test LOG4J application with multiple loglevel"
 196
 197         create_lttng_session $SESSION_NAME $TRACE_PATH
 198         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_INFO"
 199         enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_DEBUG"
 200         start_lttng_tracing $SESSION_NAME
 201
 202         # Run 5 times with a 1 second delay and fire two TP.
 203         run_app 1
 204
 205         stop_lttng_tracing $SESSION_NAME
 206         destroy_lttng_session $SESSION_NAME
 207
 208         # Validate test. Expecting all events times two.
 209         trace_match_only $EVENT_NAME $(($NR_ITER * 2)) $TRACE_PATH
 210         if [ $? -ne 0 ]; then
 211                 return $?
 212         fi
 213
 214         create_lttng_session $SESSION_NAME $TRACE_PATH
 215         enable_log4j_lttng_event_loglevel $SESSION_NAME '*' "LOG4J_INFO"
 216         enable_log4j_lttng_event_loglevel $SESSION_NAME '*' "LOG4J_DEBUG"
 217         start_lttng_tracing $SESSION_NAME
 218
 219         # Run 5 times with a 1 second delay and fire two TP.
 220         run_app 1
 221
 222         stop_lttng_tracing $SESSION_NAME
 223         destroy_lttng_session $SESSION_NAME
 224
 225         # Validate test. Expecting all events times two.
 226         trace_match_only $EVENT_NAME $(($NR_ITER * 2)) $TRACE_PATH
 227         if [ $? -ne 0 ]; then
 228                 return $?
 229         fi
 230 }
 231
 232 function test_log4j_multi_session_loglevel()
 233 {
 234         diag "Test LOG4J with multiple session"
 235
 236         create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1
 237         enable_log4j_loglevel_only $SESSION_NAME-1 '*' "LOG4J_INFO"
 238         start_lttng_tracing $SESSION_NAME-1
 239
 240         create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2
 241         enable_log4j_loglevel_only $SESSION_NAME-2 '*' "LOG4J_DEBUG"
 242         start_lttng_tracing $SESSION_NAME-2
 243
 244         # Run 5 times with a 1 second delay and fire second TP.
 245         run_app 1 1
 246
 247         stop_lttng_tracing $SESSION_NAME-1
 248         stop_lttng_tracing $SESSION_NAME-2
 249         destroy_lttng_session $SESSION_NAME-1
 250         destroy_lttng_session $SESSION_NAME-2
 251
 252         # Expecting 6 events being the main event plus the second tp.
 253         trace_match_only $EVENT_NAME $(($NR_ITER + 1)) $TRACE_PATH/$SESSION_NAME-1
 254         if [ $? -ne 0 ]; then
 255                 return $?
 256         fi
 257
 258         # Expectin 5 events being the debug TP.
 259         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-2
 260         if [ $? -ne 0 ]; then
 261                 return $?
 262         fi
 263 }
 264
 265 function test_log4j_multi_session_disable()
 266 {
 267         diag "Test LOG4J with multiple session with disabled event"
 268
 269         create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1
 270         enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME
 271         enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME2
 272         disable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME
 273         start_lttng_tracing $SESSION_NAME-1
 274
 275         create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2
 276         enable_log4j_lttng_event $SESSION_NAME-2 $EVENT_NAME2
 277         start_lttng_tracing $SESSION_NAME-2
 278
 279         # Run 5 times with a 1 second delay and fire second TP.
 280         run_app 0 1
 281
 282         stop_lttng_tracing $SESSION_NAME-1
 283         stop_lttng_tracing $SESSION_NAME-2
 284         destroy_lttng_session $SESSION_NAME-1
 285         destroy_lttng_session $SESSION_NAME-2
 286
 287         # Validate test. Expecting one event of the second TP.
 288         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-1
 289         if [ $? -ne 0 ]; then
 290                 return $?
 291         fi
 292
 293         # Validate test. Expecting one event of the second TP.
 294         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-2
 295         if [ $? -ne 0 ]; then
 296                 return $?
 297         fi
 298 }
 299
 300 function test_log4j_multi_session_disable_wildcard()
 301 {
 302         diag "Test LOG4J with multiple session with disabled wildcard event"
 303
 304         create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1
 305         enable_log4j_lttng_event $SESSION_NAME-1 '*'
 306
 307         create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2
 308         enable_log4j_lttng_event $SESSION_NAME-2 '*'
 309
 310         disable_log4j_lttng_event $SESSION_NAME-1 '*'
 311
 312         start_lttng_tracing $SESSION_NAME-1
 313         start_lttng_tracing $SESSION_NAME-2
 314
 315         run_app
 316
 317         stop_lttng_tracing $SESSION_NAME-1
 318         stop_lttng_tracing $SESSION_NAME-2
 319         destroy_lttng_session $SESSION_NAME-1
 320         destroy_lttng_session $SESSION_NAME-2
 321
 322         # Validate test. Expecting NO event of the first TP.
 323         trace_match_only $EVENT_NAME 0 $TRACE_PATH/$SESSION_NAME-1
 324         if [ $? -ne 0 ]; then
 325                 return $?
 326         fi
 327
 328         # Validate test. Expecting all events of the first TP.
 329         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-2
 330         if [ $? -ne 0 ]; then
 331                 return $?
 332         fi
 333 }
 334
 335 function test_log4j_disable_all()
 336 {
 337         diag "Test LOG4J with multiple session with disabled all event"
 338
 339         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 340         enable_log4j_lttng_event $SESSION_NAME '*'
 341         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 342         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2
 343
 344         disable_log4j_lttng_event $SESSION_NAME '*'
 345
 346         start_lttng_tracing $SESSION_NAME
 347
 348         run_app 0 1
 349
 350         stop_lttng_tracing $SESSION_NAME
 351         destroy_lttng_session $SESSION_NAME
 352
 353         # Validate test. Expecting NO event of the first TP and second TP.
 354         trace_match_only $EVENT_NAME 0 $TRACE_PATH/$SESSION_NAME
 355         trace_match_only $EVENT_NAME2 0 $TRACE_PATH/$SESSION_NAME
 356         if [ $? -ne 0 ]; then
 357                 return $?
 358         fi
 359 }
 360
 361 function test_log4j_multi_session()
 362 {
 363         diag "Test LOG4J with multiple session"
 364
 365         create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1
 366         enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME
 367         start_lttng_tracing $SESSION_NAME-1
 368
 369         create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2
 370         enable_log4j_lttng_event $SESSION_NAME-2 $EVENT_NAME2
 371         start_lttng_tracing $SESSION_NAME-2
 372
 373         # Run 5 times with a 1 second delay and fire second TP.
 374         run_app 0 1
 375
 376         stop_lttng_tracing $SESSION_NAME-1
 377         stop_lttng_tracing $SESSION_NAME-2
 378         destroy_lttng_session $SESSION_NAME-1
 379         destroy_lttng_session $SESSION_NAME-2
 380
 381         # Validate test. Expecting all events of first TP
 382         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-1
 383         if [ $? -ne 0 ]; then
 384                 return $?
 385         fi
 386
 387         # Validate test. Expecting one event of the second TP.
 388         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-2
 389         if [ $? -ne 0 ]; then
 390                 return $?
 391         fi
 392 }
 393
 394 function test_log4j_destroy_session()
 395 {
 396         diag "Test LOG4J two session with destroy"
 397
 398         create_lttng_session $SESSION_NAME $TRACE_PATH/first-sess
 399         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 400         start_lttng_tracing $SESSION_NAME
 401
 402         # Run 5 times with a 1 second delay
 403         run_app_background 0 1
 404         # Wait for the applications started in background
 405         wait
 406
 407         stop_lttng_tracing $SESSION_NAME
 408         destroy_lttng_session $SESSION_NAME
 409
 410         # Validate test. Expecting at least one event num 1
 411         validate_trace $EVENT_NAME $TRACE_PATH/first-sess
 412         if [ $? -ne 0 ]; then
 413                 return $?
 414         fi
 415
 416         create_lttng_session $SESSION_NAME $TRACE_PATH/second-sess
 417         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2
 418         start_lttng_tracing $SESSION_NAME
 419
 420         # Run 5 times with a 1 second delay
 421         run_app_background 0 1
 422         # Wait for the applications started in background
 423         wait
 424
 425         stop_lttng_tracing $SESSION_NAME
 426         destroy_lttng_session $SESSION_NAME
 427
 428         # Validate test. Expecting only one event num 2
 429         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/second-sess
 430         if [ $? -ne 0 ]; then
 431                 return $?
 432         fi
 433 }
 434
 435 function test_log4j_filtering()
 436 {
 437         diag "Test LOG4J filtering"
 438
 439         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 440         # Enable all event with a filter.
 441         enable_log4j_filter $SESSION_NAME '*' 'msg == "LOG4J second logger fired"'
 442         start_lttng_tracing $SESSION_NAME
 443
 444         # Run 5 times with a 1 second delay and fire second TP.
 445         run_app 0 1
 446
 447         stop_lttng_tracing $SESSION_NAME
 448         destroy_lttng_session $SESSION_NAME
 449
 450         # Validate test. Expecting one event of the second TP only.
 451         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME
 452         if [ $? -ne 0 ]; then
 453                 return $?
 454         fi
 455
 456         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 457         # Enable first Logger but filter msg payload for the INFO one while
 458         # triggering the debug and second TP.
 459         enable_log4j_filter $SESSION_NAME $EVENT_NAME 'msg == "LOG4J tp fired!"'
 460         start_lttng_tracing $SESSION_NAME
 461
 462         # Run 5 times with a 1 second delay, fire debug and second TP.
 463         run_app 1 1
 464
 465         stop_lttng_tracing $SESSION_NAME
 466         destroy_lttng_session $SESSION_NAME
 467
 468         # Validate test. Expecting NR_ITER event of the main INFO tp.
 469         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME
 470         if [ $? -ne 0 ]; then
 471                 return $?
 472         fi
 473 }
 474
 475 function test_log4j_disable()
 476 {
 477         diag "Test LOG4J disable event"
 478
 479         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 480         # Enable all event with a filter.
 481         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 482         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2
 483         disable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 484         start_lttng_tracing $SESSION_NAME
 485
 486         # Run 5 times with a 1 second delay and fire second TP.
 487         run_app 0 1
 488
 489         stop_lttng_tracing $SESSION_NAME
 490         destroy_lttng_session $SESSION_NAME
 491
 492         # Validate test. Expecting one event of the second TP only.
 493         trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME
 494         if [ $? -ne 0 ]; then
 495                 return $?
 496         fi
 497 }
 498
 499 function test_log4j_disable_enable()
 500 {
 501         diag "Test LOG4J disable event followed by an enable"
 502
 503         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 504         # Enable all event with a filter.
 505         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 506         disable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 507         enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME
 508         start_lttng_tracing $SESSION_NAME
 509
 510         # Run 5 times with a 1 second delay and fire second TP.
 511         run_app 0 1
 512
 513         stop_lttng_tracing $SESSION_NAME
 514         destroy_lttng_session $SESSION_NAME
 515
 516         # Validate test. Expecting NR_ITER event of the main INFO tp.
 517         trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME
 518         if [ $? -ne 0 ]; then
 519                 return $?
 520         fi
 521 }
 522
 523 function test_log4j_filter_loglevel()
 524 {
 525         local BOGUS_EVENT_NAME="not_a_real_event"
 526         local FILTER="int_loglevel > 700 || int_loglevel < 700"
 527         local ALL_EVENTS="."
 528
 529         diag "Test LOG4J a filter with a loglevel"
 530
 531         create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME
 532         # Enable an event with a filter and the loglevel-only option.
 533         enable_log4j_filter_loglevel_only $SESSION_NAME $BOGUS_EVENT_NAME "$FILTER" LOG4J_INFO
 534         disable_log4j_lttng_event $SESSION_NAME $BOGUS_EVENT_NAME
 535         enable_log4j_filter_loglevel_only $SESSION_NAME $BOGUS_EVENT_NAME "$FILTER" LOG4J_INFO
 536         start_lttng_tracing $SESSION_NAME
 537
 538         # Run 5 times with a 1 second delay and fire second TP.
 539         run_app 0 1
 540
 541         stop_lttng_tracing $SESSION_NAME
 542         destroy_lttng_session $SESSION_NAME
 543
 544         # Validate test. Expecting no events.
 545         trace_match_only $ALL_EVENTS 0 $TRACE_PATH/$SESSION_NAME
 546         if [ $? -ne 0 ]; then
 547                 return $?
 548         fi
 549 }
 550
 551 plan_tests $NUM_TESTS
 552
 553 print_test_banner "$TEST_DESC"
 554
 555 if [ ! -f "$TESTAPP_PATH.class" ]; then
 556         withapp=0
 557 else
 558         withapp=1
 559 fi
 560
 561 skip $withapp "LOG4J support is needed. Skipping all tests." $NUM_TESTS ||
 562 {
 563         start_lttng_sessiond
 564
 565         tests=(
 566                 test_log4j_multi_session_disable_wildcard
 567                 test_log4j_multi_session_disable
 568                 test_log4j_disable
 569                 test_log4j_disable_enable
 570                 test_log4j_disable_all
 571                 test_log4j_filtering
 572                 test_log4j_multi_session_loglevel
 573                 test_log4j_destroy_session
 574                 test_log4j_loglevel
 575                 test_log4j_loglevel_multiple
 576                 test_log4j_before_start
 577                 test_log4j_after_start
 578                 test_log4j_multi_session
 579                 test_log4j_filter_loglevel
 580         )
 581
 582         for fct_test in ${tests[@]};
 583         do
 584                 TRACE_PATH=$(mktemp -d)
 585
 586                 ${fct_test}
 587                 if [ $? -ne 0 ]; then
 588                         break;
 589                 fi
 590                 rm -rf $TRACE_PATH
 591         done
 592
 593         stop_lttng_sessiond
 594 }