LTTng » LTTng-tools

[SC-1:Node16 Fri Apr 12 08:04:32/cluster/temp/log] # export TC=LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4

[SC-1:Node16 Fri Apr 12 08:04:40/cluster/temp/log] # DOMAIN_EVENT="com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec"

[SC-1:Node16 Fri Apr 12 08:04:40/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:04:40/cluster/temp/log] # sleep 1

sar -u 1 300 >> $TC.load.log &

netstat -etanp | head -n 2 ; netstat -etanp |egrep 'lttng'

sleep 1

echo "Start to launch apps when no session is active." >> $TC.load.log

#----------------------------------------------------------------------

date; time for n in $(seq 1 8000); do (/home/test_apps/TestApp_100psOnly 200 np &); done

#----------------------------------------------------------------------

echo "End of launching apps when no session is active" >> $TC.load.log

ps -ef |grep -c TestApp

sleep 1

#---------------------------- Get PID to trace on --------------------------------------------------

export my_pid=$(ps -e |grep TestApp | tail -n 1 | awk {'print $1'}); echo $my_pid

sleep 10

ps -ef |egrep 'lttng'

lttng-relayd -C tcp://0.0.0.0:53000 -D tcp://0.0.0.0:53001 -o /cluster/temp/log/$TC &

echo "Create the session." >> $TC.load.log

date; lttng create $TC -U net://192.168.0.1:53000:53001/./

lttng list

sleep 5

echo "Enable channel...." >> $TC.load.log

date; lttng enable-channel chan1 -u -s $TC --buffers-uid --subbuf-size 16384 #--switch-timer 1000000

echo "Enable channel done." >> $TC.load.log

echo "Enable channel metadata...." >> $TC.load.log

date; lttng enable-channel metadata -u -s $TC --buffers-uid --subbuf-size 16384 #--switch-timer 1000000

echo "Enable channel metadata done." >> $TC.load.log

sleep 5

lttng add-context -t vpid -u -s $TC

echo "Enable Event...." >> $TC.load.log

date; lttng enable-event -s $TC -u -c chan1 $DOMAIN_EVENT --filter "PID == $my_pid"

echo "Enable Event done." >> $TC.load.log

sleep 5

echo "Activate the session." >> $TC.load.log

#---------------------------------------------------- activate session -----------------------

date; lttng start;

echo "Activate session Done." >> $TC.load.log

sleep 1

lttng list $TC

sleep 1

ps -e |grep -c TestApp

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 5

dir -R $TC/SC-1/ust/uid/0/64-bit

echo "Stopping the session..." >> $TC.load.log

#---------------------------------------------------- De-activate session -----------------------

lttng stop

echo "Stopping done." >> $TC.load.log

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 5

echo "Destroying the session..." >> $TC.load.log

lttng destroy

echo "Destroy done! " >> $TC.load.log

sleep 5

dir -R $TC/SC-1/ust/uid/0/64-bit

pkill relayd

babeltrace $TC | head -n 10

sleep 1

dir /cluster/dumps

sleep 5

echo "Killing TestApp" >> $TC.load.log

ps -e |grep -c TestApp

pkill TestApp

echo "Killing Done ." >> $TC.load.log

ps -e |grep -c TestApp

sleep 5

pkill sar

cat $TC.load.log

rm $TC.load.log

babeltrace $TC | grep -c $DOMAIN_EVENT

babeltrace $TC | wc -l

du -h $TC | tail -n 1

[SC-1:Node16 Fri Apr 12 08:04:41/cluster/temp/log] # sar -u 1 300 >> $TC.load.log &

[1] 30502

[SC-1:Node16 Fri Apr 12 08:04:41/cluster/temp/log] # netstat -etanp | head -n 2 ; netstat -etanp |egrep 'lttng'

Active Internet connections (servers and established)

Proto Recv-Q Send-Q Local Address Foreign Address State User Inode PID/Program name

[SC-1:Node16 Fri Apr 12 08:04:41/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:04:42/cluster/temp/log] # echo "Start to launch apps when no session is active." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:04:42/cluster/temp/log] # #----------------------------------------------------------------------

[SC-1:Node16 Fri Apr 12 08:04:42/cluster/temp/log] # date; time for n in $(seq 1 8000); do (/home/test_apps/TestApp_100psOnly 200 np &); done

Fri Apr 12 08:04:42 EDT 2013

real 0m21.670s

user 0m1.536s

sys 0m1.612s

[SC-1:Node16 Fri Apr 12 08:05:03/cluster/temp/log] # #----------------------------------------------------------------------

[SC-1:Node16 Fri Apr 12 08:05:03/cluster/temp/log] # echo "End of launching apps when no session is active" >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:04/cluster/temp/log] # ps -ef |grep -c TestApp

8001

[SC-1:Node16 Fri Apr 12 08:05:04/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:05:06/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:05:06/cluster/temp/log] # #---------------------------- Get PID to trace on --------------------------------------------------

[SC-1:Node16 Fri Apr 12 08:05:06/cluster/temp/log] # export my_pid=$(ps -e |grep TestApp | tail -n 1 | awk {'print $1'}); echo $my_pid

32766

[SC-1:Node16 Fri Apr 12 08:05:06/cluster/temp/log] # sleep 10

[SC-1:Node16 Fri Apr 12 08:05:16/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:05:16/cluster/temp/log] # ps -ef |egrep 'lttng'

root 12162 1 0 Apr09 ? 00:01:18 lttng-sessiond -d

root 12979 12162 0 Apr09 ? 00:00:26 lttng-consumerd --quiet -u --consumerd-cmd-sock /var/run/lttng/ustconsumerd64/command --consumerd-err-sock /var/run/lttng/ustconsumerd64/error

root 30393 14451 0 08:05 pts/1 00:00:00 egrep lttng

root 30394 13787 0 08:05 ? 00:00:00 /bin/bash /opt/trace_ea/bin/lttng-proxy start

root 30395 30394 0 08:05 ? 00:00:00 pgrep lttng-sessiond

[SC-1:Node16 Fri Apr 12 08:05:17/cluster/temp/log] # lttng-relayd -C tcp://0.0.0.0:53000 -D tcp://0.0.0.0:53001 -o /cluster/temp/log/$TC &

[2] 30396

[SC-1:Node16 Fri Apr 12 08:05:17/cluster/temp/log] # echo "Create the session." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:17/cluster/temp/log] # date; lttng create $TC -U net://192.168.0.1:53000:53001/./

Fri Apr 12 08:05:17 EDT 2013

Session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4 created.

Traces will be written in net://192.168.0.1:53000:53001/./

[SC-1:Node16 Fri Apr 12 08:05:17/cluster/temp/log] # lttng list

Available tracing sessions:

1) LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4 (net://192.168.0.1:53000/./ [data: 5343]) [inactive]

Use lttng list <session_name> for more details

[SC-1:Node16 Fri Apr 12 08:05:17/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:05:22/cluster/temp/log] # echo "Enable channel...." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:22/cluster/temp/log] # date; lttng enable-channel chan1 -u -s $TC --buffers-uid --subbuf-size 16384 #--switch-timer 1000000

Fri Apr 12 08:05:22 EDT 2013

UST channel chan1 enabled for session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4

[SC-1:Node16 Fri Apr 12 08:05:30/cluster/temp/log] # echo "Enable channel done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:30/cluster/temp/log] # echo "Enable channel metadata...." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:31/cluster/temp/log] # date; lttng enable-channel metadata -u -s $TC --buffers-uid --subbuf-size 16384 #--switch-timer 1000000

Fri Apr 12 08:05:31 EDT 2013

UST channel metadata enabled for session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4

[SC-1:Node16 Fri Apr 12 08:05:31/cluster/temp/log] # echo "Enable channel metadata done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:31/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:05:36/cluster/temp/log] # lttng add-context -t vpid -u -s $TC

UST context vpid added to all channels

[SC-1:Node16 Fri Apr 12 08:05:36/cluster/temp/log] # echo "Enable Event...." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:36/cluster/temp/log] # date; lttng enable-event -s $TC -u -c chan1 $DOMAIN_EVENT --filter "PID == $my_pid"

Fri Apr 12 08:05:36 EDT 2013

Filter 'PID == 32766' successfully set

[SC-1:Node16 Fri Apr 12 08:05:37/cluster/temp/log] # echo "Enable Event done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:37/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:05:42/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:05:42/cluster/temp/log] # echo "Activate the session." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:42/cluster/temp/log] # #---------------------------------------------------- activate session -----------------------

[SC-1:Node16 Fri Apr 12 08:05:42/cluster/temp/log] # date; lttng start;

Fri Apr 12 08:05:42 EDT 2013

Tracing started for session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4

[SC-1:Node16 Fri Apr 12 08:05:49/cluster/temp/log] # echo "Activate session Done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:05:49/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:05:50/cluster/temp/log] # lttng list $TC

Tracing session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4: [active]

Trace path: net://192.168.0.1:53000/./ [data: 53001]

=== Domain: UST global ===

Channels:

-------------

- chan1: [enabled]

Attributes:

overwrite mode: 0

subbufers size: 16384

number of subbufers: 4

switch timer interval: 0

read timer interval: 200000

output: mmap()

Events:

com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec (type: tracepoint) [enabled] [with filter]

- metadata: [enabled]

Attributes:

overwrite mode: 0

subbufers size: 16384

number of subbufers: 4

switch timer interval: 0

read timer interval: 200000

output: mmap()

Events:

None

[SC-1:Node16 Fri Apr 12 08:05:50/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:05:51/cluster/temp/log] # ps -e |grep -c TestApp

8000

[SC-1:Node16 Fri Apr 12 08:05:53/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4/SC-1/ust/uid/0/64-bit:

total 16

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:05 metadata

-rw-rw---- 1 root root 16384 Apr 12 08:05 chan1_2

[SC-1:Node16 Fri Apr 12 08:05:53/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:05:54/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4/SC-1/ust/uid/0/64-bit:

total 16

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:05 metadata

-rw-rw---- 1 root root 16384 Apr 12 08:05 chan1_2

[SC-1:Node16 Fri Apr 12 08:05:54/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:05:55/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4/SC-1/ust/uid/0/64-bit:

total 16

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:05 metadata

-rw-rw---- 1 root root 16384 Apr 12 08:05 chan1_2

[SC-1:Node16 Fri Apr 12 08:05:55/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:05:56/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4/SC-1/ust/uid/0/64-bit:

total 16

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:05 metadata

-rw-rw---- 1 root root 16384 Apr 12 08:05 chan1_2

[SC-1:Node16 Fri Apr 12 08:05:56/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:05:57/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4/SC-1/ust/uid/0/64-bit:

total 16

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:05 metadata

-rw-rw---- 1 root root 16384 Apr 12 08:05 chan1_2

[SC-1:Node16 Fri Apr 12 08:05:57/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:06:02/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4/SC-1/ust/uid/0/64-bit:

total 16

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:05 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:05 metadata

-rw-rw---- 1 root root 16384 Apr 12 08:05 chan1_2

[SC-1:Node16 Fri Apr 12 08:06:02/cluster/temp/log] # echo "Stopping the session..." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:06:02/cluster/temp/log] # #---------------------------------------------------- De-activate session -----------------------

[SC-1:Node16 Fri Apr 12 08:06:02/cluster/temp/log] # lttng stop

Waiting for data availability

Tracing stopped for session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4

[SC-1:Node16 Fri Apr 12 08:06:05/cluster/temp/log] # echo "Stopping done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:06:05/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:06:06/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4/SC-1/ust/uid/0/64-bit:

total 624

-rw-rw---- 1 root root 4096 Apr 12 08:06 metadata

-rw-rw---- 1 root root 4096 Apr 12 08:06 chan1_9

-rw-rw---- 1 root root 16384 Apr 12 08:06 chan1_8

-rw-rw---- 1 root root 12288 Apr 12 08:06 chan1_7

-rw-rw---- 1 root root 4096 Apr 12 08:06 chan1_6

-rw-rw---- 1 root root 98304 Apr 12 08:06 chan1_5

-rw-rw---- 1 root root 4096 Apr 12 08:06 chan1_4

-rw-rw---- 1 root root 4096 Apr 12 08:06 chan1_3

-rw-rw---- 1 root root 24576 Apr 12 08:06 chan1_2

-rw-rw---- 1 root root 180224 Apr 12 08:06 chan1_11

-rw-rw---- 1 root root 253952 Apr 12 08:06 chan1_10

-rw-rw---- 1 root root 16384 Apr 12 08:06 chan1_1

-rw-rw---- 1 root root 4096 Apr 12 08:06 chan1_0

[SC-1:Node16 Fri Apr 12 08:06:06/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:06:11/cluster/temp/log] # echo "Destroying the session..." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:06:11/cluster/temp/log] # lttng destroy

Session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4 destroyed

[SC-1:Node16 Fri Apr 12 08:06:13/cluster/temp/log] # echo "Destroy done! " >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:06:13/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:06:18/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4/SC-1/ust/uid/0/64-bit:

total 676

-rw-rw---- 1 root root 8192 Apr 12 08:06 metadata

-rw-rw---- 1 root root 8192 Apr 12 08:06 chan1_9

-rw-rw---- 1 root root 102400 Apr 12 08:06 chan1_5

-rw-rw---- 1 root root 28672 Apr 12 08:06 chan1_2

-rw-rw---- 1 root root 184320 Apr 12 08:06 chan1_11

-rw-rw---- 1 root root 258048 Apr 12 08:06 chan1_10

-rw-rw---- 1 root root 20480 Apr 12 08:06 chan1_8

-rw-rw---- 1 root root 16384 Apr 12 08:06 chan1_7

-rw-rw---- 1 root root 8192 Apr 12 08:06 chan1_6

-rw-rw---- 1 root root 8192 Apr 12 08:06 chan1_4

-rw-rw---- 1 root root 8192 Apr 12 08:06 chan1_3

-rw-rw---- 1 root root 20480 Apr 12 08:06 chan1_1

-rw-rw---- 1 root root 8192 Apr 12 08:06 chan1_0

[SC-1:Node16 Fri Apr 12 08:06:18/cluster/temp/log] # pkill relayd

[2]+ Done lttng-relayd -C tcp://0.0.0.0:53000 -D tcp://0.0.0.0:53001 -o /cluster/temp/log/$TC

[SC-1:Node16 Fri Apr 12 08:06:19/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:19/cluster/temp/log] # babeltrace $TC | head -n 10

[08:05:44.426153492] (+?.?????????) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 3, HundredPs = 8, unit_float = 8.1234, unit_string = "unit_8" }

[08:05:44.436212899] (+0.010059407) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 3, HundredPs = 9, unit_float = 9.1234, unit_string = "unit_9" }

[08:05:44.446134330] (+0.009921431) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 4, HundredPs = 0, unit_float = 0.1234, unit_string = "unit_0" }

[08:05:44.456134979] (+0.010000649) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 4, HundredPs = 1, unit_float = 1.1234, unit_string = "unit_1" }

[08:05:44.466135545] (+0.010000566) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 4, HundredPs = 2, unit_float = 2.1234, unit_string = "unit_2" }

[08:05:44.476137197] (+0.010001652) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 4, HundredPs = 3, unit_float = 3.1234, unit_string = "unit_3" }

[08:05:44.486134816] (+0.009997619) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 4, HundredPs = 4, unit_float = 4.1234, unit_string = "unit_4" }

[08:05:44.496136129] (+0.010001313) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 4, HundredPs = 5, unit_float = 5.1234, unit_string = "unit_5" }

[08:05:44.506134065] (+0.009997936) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 4, HundredPs = 6, unit_float = 6.1234, unit_string = "unit_6" }

[08:05:44.516134891] (+0.010000826) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 8 }, { vpid = 32766 }, { my_Time = "08:05:44", PID = 32766, OnePs = 61, TenPs = 4, HundredPs = 7, unit_float = 7.1234, unit_string = "unit_7" }

[SC-1:Node16 Fri Apr 12 08:06:19/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:06:20/cluster/temp/log] # dir /cluster/dumps

total 8456

-rw------- 1 root root 76394496 Apr 9 12:56 lttng-sessiond.2050.SC-1.core

-rw------- 1 root root 76275712 Apr 9 12:58 lttng-sessiond.2530.SC-1.core

-rw------- 1 root root 76275712 Apr 9 12:59 lttng-sessiond.2757.SC-1.core

-rw------- 1 root root 76275712 Apr 9 13:01 lttng-sessiond.2949.SC-1.core

-rw------- 1 root root 76378112 Apr 9 14:36 lttng-sessiond.3169.SC-1.core

-rw------- 1 root root 76410880 Apr 9 14:39 lttng-sessiond.9525.SC-1.core

-rw------- 1 root root 76410880 Apr 9 14:40 lttng-sessiond.9829.SC-1.core

-rw------- 1 root root 76410880 Apr 9 14:52 lttng-sessiond.10003.SC-1.core

-rw------- 1 root root 76275712 Apr 9 15:02 lttng-sessiond.10956.SC-1.core

-rw------- 1 root root 76275712 Apr 9 15:07 lttng-sessiond.11824.SC-1.core

[SC-1:Node16 Fri Apr 12 08:06:20/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:06:25/cluster/temp/log] # echo "Killing TestApp" >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:06:25/cluster/temp/log] # ps -e |grep -c TestApp

8000

[SC-1:Node16 Fri Apr 12 08:06:26/cluster/temp/log] # pkill TestApp

[SC-1:Node16 Fri Apr 12 08:06:30/cluster/temp/log] # echo "Killing Done ." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:06:30/cluster/temp/log] # ps -e |grep -c TestApp

0

[SC-1:Node16 Fri Apr 12 08:06:30/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] # pkill sar

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] # cat $TC.load.log

Linux 3.0.42-0.7.3.4775.1.PTF-default (SC-1) 04/12/13 _x86_64_

08:04:41 CPU %user %nice %system %iowait %steal %idle

08:04:42 all 0.00 0.00 0.42 0.00 0.00 99.58

Start to launch apps when no session is active.

08:04:43 all 9.00 0.00 11.04 0.51 0.00 79.46

08:04:44 all 10.89 0.00 12.98 0.00 0.00 76.13

08:04:45 all 12.15 0.00 14.01 0.00 0.00 73.85

08:04:46 all 14.07 0.00 15.58 0.00 0.00 70.35

08:04:47 all 15.11 0.00 19.68 0.00 0.00 65.20

08:04:48 all 16.94 0.00 20.02 0.00 0.00 63.04

08:04:49 all 18.12 0.00 22.86 0.00 0.00 59.02

08:04:50 all 21.11 0.00 23.98 0.00 0.00 54.91

08:04:51 all 21.85 0.00 24.51 0.00 0.00 53.64

08:04:52 all 22.95 0.00 26.11 0.00 0.00 50.94

08:04:53 all 23.50 0.00 27.92 0.00 0.00 48.59

08:04:54 all 24.30 0.00 29.65 0.00 0.00 46.05

08:04:55 all 25.15 0.00 30.47 0.00 0.00 44.38

08:04:56 all 27.52 0.00 32.18 0.00 0.00 40.30

08:04:57 all 28.07 0.00 30.57 0.00 0.00 41.36

08:04:58 all 28.01 0.00 32.18 0.00 0.00 39.81

08:04:59 all 27.90 0.00 34.54 0.00 0.00 37.56

08:05:00 all 29.16 0.00 32.06 0.00 0.00 38.78

08:05:01 all 31.27 0.00 33.85 0.00 0.00 34.88

08:05:02 all 33.03 0.00 36.62 0.00 0.00 30.34

08:05:03 all 30.96 0.00 36.41 0.00 0.00 32.63

End of launching apps when no session is active

08:05:04 all 31.65 0.00 36.95 0.17 0.00 31.23

08:05:05 all 30.03 0.00 32.07 0.00 0.00 37.91

08:05:06 all 29.54 0.00 31.87 0.00 0.00 38.59

08:05:07 all 30.23 0.00 32.09 0.00 0.00 37.68

08:05:08 all 30.45 0.00 27.40 0.00 0.00 42.15

08:05:09 all 32.42 0.00 29.51 0.00 0.00 38.07

08:05:10 all 31.93 0.00 29.98 0.00 0.00 38.10

08:05:11 all 30.06 0.00 29.14 0.00 0.00 40.80

08:05:12 all 25.94 0.00 33.81 0.09 0.00 40.16

08:05:13 all 28.15 0.00 31.60 0.00 0.00 40.25

08:05:14 all 28.04 0.00 30.67 0.00 0.00 41.29

08:05:15 all 29.92 0.00 30.19 0.00 0.00 39.89

08:05:16 all 29.14 0.00 29.97 0.00 0.00 40.89

08:05:17 all 28.33 0.00 34.32 0.00 0.00 37.35

Create the session.

08:05:18 all 31.26 0.00 34.16 0.26 0.00 34.33

08:05:19 all 27.66 0.00 30.64 0.00 0.00 41.70

08:05:20 all 28.76 0.00 28.50 0.00 0.00 42.74

08:05:21 all 29.85 0.00 30.72 0.00 0.00 39.43

08:05:22 all 27.80 0.00 30.37 0.00 0.00 41.83

Enable channel....

08:05:23 all 28.07 0.00 31.49 0.44 0.00 40.00

08:05:24 all 31.17 0.00 37.92 0.00 0.00 30.91

08:05:25 all 32.82 0.00 33.71 0.00 0.00 33.47

08:05:26 all 32.74 0.00 34.11 0.00 0.00 33.14

08:05:27 all 29.98 0.00 38.07 0.00 0.00 31.94

08:05:28 all 32.16 0.00 32.66 0.00 0.00 35.18

08:05:29 all 32.57 0.00 34.62 0.00 0.00 32.81

08:05:30 all 31.87 0.00 35.85 0.00 0.00 32.28

Enable channel done.

Enable channel metadata....

Enable channel metadata done.

08:05:31 all 31.50 0.00 33.88 0.41 0.00 34.21

08:05:32 all 26.63 0.00 34.06 0.00 0.00 39.31

08:05:33 all 30.36 0.00 30.36 0.00 0.00 39.28

08:05:34 all 27.11 0.00 33.28 0.00 0.00 39.61

08:05:35 all 29.30 0.00 30.93 0.00 0.00 39.77

08:05:36 all 30.73 0.00 33.51 0.00 0.00 35.76

Enable Event....

08:05:37 all 30.46 0.00 34.81 0.18 0.00 34.55

Enable Event done.

08:05:38 all 30.39 0.00 32.68 0.08 0.00 36.85

08:05:39 all 29.20 0.00 32.99 0.00 0.00 37.81

08:05:40 all 30.11 0.00 32.73 0.00 0.00 37.16

08:05:41 all 29.47 0.00 31.63 0.00 0.00 38.90

08:05:42 all 30.52 0.00 30.43 0.00 0.00 39.05

Activate the session.

08:05:43 all 33.09 0.00 34.69 0.24 0.00 31.97

08:05:44 all 37.72 0.00 34.27 0.00 0.00 28.01

08:05:45 all 42.99 0.00 33.33 0.00 0.00 23.67

08:05:46 all 46.15 0.00 37.58 0.00 0.00 16.27

08:05:47 all 49.84 0.00 33.60 0.00 0.00 16.56

08:05:48 all 53.31 0.00 32.81 0.00 0.00 13.88

08:05:49 all 55.12 0.00 34.41 0.00 0.00 10.48

Activate session Done.

08:05:50 all 56.00 0.00 30.93 0.00 0.00 13.07

08:05:51 all 54.52 0.00 30.79 0.00 0.00 14.70

08:05:52 all 54.84 0.00 36.75 0.00 0.00 8.41

08:05:53 all 56.67 0.00 32.78 0.09 0.00 10.46

08:05:54 all 53.59 0.00 31.22 0.00 0.00 15.19

08:05:55 all 51.02 0.00 35.48 0.00 0.00 13.50

08:05:56 all 53.81 0.00 32.20 0.00 0.00 14.00

08:05:57 all 52.93 0.00 31.64 0.00 0.00 15.44

08:05:58 all 54.00 0.00 32.66 0.00 0.00 13.34

08:05:59 all 55.18 0.00 32.39 0.00 0.00 12.44

08:06:00 all 54.08 0.00 31.08 0.00 0.00 14.85

08:06:01 all 53.50 0.00 33.02 0.00 0.00 13.48

08:06:02 all 56.07 0.00 31.56 0.00 0.00 12.38

Stopping the session...

08:06:03 all 51.52 0.00 34.13 0.08 0.00 14.26

08:06:04 all 45.21 0.00 35.39 0.00 0.00 19.40

Stopping done.

08:06:05 all 35.56 0.00 35.79 0.16 0.00 28.49

08:06:06 all 29.76 0.00 31.75 0.71 0.00 37.78

08:06:07 all 28.09 0.00 33.14 0.00 0.00 38.76

08:06:08 all 29.65 0.00 33.04 0.00 0.00 37.31

08:06:09 all 30.59 0.00 30.99 0.00 0.00 38.42

08:06:10 all 29.79 0.00 32.25 0.00 0.00 37.97

Destroying the session...

08:06:11 all 29.49 0.00 33.84 0.16 0.00 36.50

08:06:12 all 32.29 0.00 34.33 0.00 0.00 33.39

08:06:13 all 31.05 0.00 36.99 0.08 0.00 31.88

Destroy done!

08:06:14 all 33.07 0.00 34.49 1.26 0.00 31.19

08:06:15 all 28.26 0.00 31.68 0.00 0.00 40.07

08:06:16 all 28.94 0.00 30.50 0.00 0.00 40.56

08:06:17 all 29.62 0.00 33.87 0.00 0.00 36.51

08:06:18 all 28.41 0.00 31.20 0.00 0.00 40.39

08:06:19 all 30.59 0.00 32.67 0.00 0.00 36.74

08:06:20 all 29.97 0.00 31.10 0.00 0.00 38.92

08:06:21 all 28.97 0.00 29.81 0.00 0.00 41.23

08:06:22 all 30.00 0.00 27.86 0.00 0.00 42.14

08:06:23 all 29.76 0.00 32.04 0.00 0.00 38.20

08:06:24 all 29.60 0.00 30.25 0.00 0.00 40.15

08:06:25 all 30.78 0.00 29.48 0.00 0.00 39.74

Killing TestApp

08:06:26 all 31.95 0.00 37.55 0.16 0.00 30.34

08:06:27 all 26.57 0.00 49.54 0.00 0.00 23.89

08:06:28 all 22.99 0.00 62.56 0.00 0.00 14.45

08:06:29 all 20.59 0.00 61.59 0.00 0.00 17.82

08:06:30 all 12.75 0.00 57.75 0.00 0.00 29.50

Killing Done .

08:06:31 all 0.51 0.00 8.38 0.51 0.00 90.60

08:06:32 all 0.00 0.00 0.17 0.00 0.00 99.83

08:06:33 all 0.00 0.00 0.00 0.00 0.00 100.00

08:06:34 all 0.08 0.00 0.17 0.00 0.00 99.75

08:06:35 all 0.00 0.00 0.33 0.00 0.00 99.67

[1]+ Terminated sar -u 1 300 >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] # rm $TC.load.log

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] # babeltrace $TC | grep -c $DOMAIN_EVENT

1925

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] # babeltrace $TC | wc -l

1925

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] # du -h $TC | tail -n 1

700K LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run4

[SC-1:Node16 Fri Apr 12 08:06:35/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:53/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:06:54/cluster/temp/log] # export TC=LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5

[SC-1:Node16 Fri Apr 12 08:07:07/cluster/temp/log] # DOMAIN_EVENT="com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec"

[SC-1:Node16 Fri Apr 12 08:07:07/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:07:07/cluster/temp/log] # sleep 1

sar -u 1 300 >> $TC.load.log &

netstat -etanp | head -n 2 ; netstat -etanp |egrep 'lttng'

sleep 1

echo "Start to launch apps when no session is active." >> $TC.load.log

#----------------------------------------------------------------------

date; time for n in $(seq 1 8000); do (/home/test_apps/TestApp_100psOnly 200 np &); done

#----------------------------------------------------------------------

echo "End of launching apps when no session is active" >> $TC.load.log

ps -ef |grep -c TestApp

sleep 1

#---------------------------- Get PID to trace on --------------------------------------------------

export my_pid=$(ps -e |grep TestApp | tail -n 1 | awk {'print $1'}); echo $my_pid

sleep 10

ps -ef |egrep 'lttng'

lttng-relayd -C tcp://0.0.0.0:53000 -D tcp://0.0.0.0:53001 -o /cluster/temp/log/$TC &

echo "Create the session." >> $TC.load.log

date; lttng create $TC -U net://192.168.0.1:53000:53001/./

lttng list

sleep 5

echo "Enable channel...." >> $TC.load.log

date; lttng enable-channel chan1 -u -s $TC --buffers-uid --subbuf-size 16384 #--switch-timer 1000000

echo "Enable channel done." >> $TC.load.log

echo "Enable channel metadata...." >> $TC.load.log

date; lttng enable-channel metadata -u -s $TC --buffers-uid --subbuf-size 16384 #--switch-timer 1000000

echo "Enable channel metadata done." >> $TC.load.log

sleep 5

lttng add-context -t vpid -u -s $TC

echo "Enable Event...." >> $TC.load.log

date; lttng enable-event -s $TC -u -c chan1 $DOMAIN_EVENT --filter "PID == $my_pid"

echo "Enable Event done." >> $TC.load.log

sleep 5

echo "Activate the session." >> $TC.load.log

#---------------------------------------------------- activate session -----------------------

date; lttng start;

echo "Activate session Done." >> $TC.load.log

sleep 1

lttng list $TC

sleep 1

ps -e |grep -c TestApp

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 5

dir -R $TC/SC-1/ust/uid/0/64-bit

echo "Stopping the session..." >> $TC.load.log

#---------------------------------------------------- De-activate session -----------------------

lttng stop

echo "Stopping done." >> $TC.load.log

sleep 1

dir -R $TC/SC-1/ust/uid/0/64-bit

sleep 5

echo "Destroying the session..." >> $TC.load.log

lttng destroy

echo "Destroy done! " >> $TC.load.log

sleep 5

dir -R $TC/SC-1/ust/uid/0/64-bit

pkill relayd

babeltrace $TC | head -n 10

sleep 1

dir /cluster/dumps

sleep 5

echo "Killing TestApp" >> $TC.load.log

ps -e |grep -c TestApp

pkill TestApp

echo "Killing Done ." >> $TC.load.log

ps -e |grep -c TestApp

sleep 5

pkill sar

cat $TC.load.log

rm $TC.load.log

babeltrace $TC | grep -c $DOMAIN_EVENT

babeltrace $TC | wc -l

du -h $TC | tail -n 1

[SC-1:Node16 Fri Apr 12 08:07:08/cluster/temp/log] # sar -u 1 300 >> $TC.load.log &

[1] 24871

[SC-1:Node16 Fri Apr 12 08:07:08/cluster/temp/log] # netstat -etanp | head -n 2 ; netstat -etanp |egrep 'lttng'

Active Internet connections (servers and established)

Proto Recv-Q Send-Q Local Address Foreign Address State User Inode PID/Program name

[SC-1:Node16 Fri Apr 12 08:07:08/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:07:09/cluster/temp/log] # echo "Start to launch apps when no session is active." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:07:09/cluster/temp/log] # #----------------------------------------------------------------------

[SC-1:Node16 Fri Apr 12 08:07:09/cluster/temp/log] # date; time for n in $(seq 1 8000); do (/home/test_apps/TestApp_100psOnly 200 np &); done

Fri Apr 12 08:07:09 EDT 2013

real 0m22.908s

user 0m2.068s

sys 0m1.596s

[SC-1:Node16 Fri Apr 12 08:07:32/cluster/temp/log] # #----------------------------------------------------------------------

[SC-1:Node16 Fri Apr 12 08:07:32/cluster/temp/log] # echo "End of launching apps when no session is active" >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:07:32/cluster/temp/log] # ps -ef |grep -c TestApp

8001

[SC-1:Node16 Fri Apr 12 08:07:33/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:07:34/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:07:34/cluster/temp/log] # #---------------------------- Get PID to trace on --------------------------------------------------

[SC-1:Node16 Fri Apr 12 08:07:34/cluster/temp/log] # export my_pid=$(ps -e |grep TestApp | tail -n 1 | awk {'print $1'}); echo $my_pid

32765

[SC-1:Node16 Fri Apr 12 08:07:35/cluster/temp/log] # sleep 10

[SC-1:Node16 Fri Apr 12 08:07:45/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:07:45/cluster/temp/log] # ps -ef |egrep 'lttng'

root 12162 1 0 Apr09 ? 00:01:25 lttng-sessiond -d

root 12979 12162 0 Apr09 ? 00:00:28 lttng-consumerd --quiet -u --consumerd-cmd-sock /var/run/lttng/ustconsumerd64/command --consumerd-err-sock /var/run/lttng/ustconsumerd64/error

root 24760 14451 0 08:07 pts/1 00:00:00 egrep lttng

[SC-1:Node16 Fri Apr 12 08:07:46/cluster/temp/log] # lttng-relayd -C tcp://0.0.0.0:53000 -D tcp://0.0.0.0:53001 -o /cluster/temp/log/$TC &

[2] 24761

[SC-1:Node16 Fri Apr 12 08:07:46/cluster/temp/log] # echo "Create the session." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:07:46/cluster/temp/log] # date; lttng create $TC -U net://192.168.0.1:53000:53001/./

Fri Apr 12 08:07:46 EDT 2013

Session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5 created.

Traces will be written in net://192.168.0.1:53000:53001/./

[SC-1:Node16 Fri Apr 12 08:07:46/cluster/temp/log] # lttng list

Available tracing sessions:

1) LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5 (net://192.168.0.1:53000/./ [data: 5343]) [inactive]

Use lttng list <session_name> for more details

[SC-1:Node16 Fri Apr 12 08:07:46/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:07:51/cluster/temp/log] # echo "Enable channel...." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:07:51/cluster/temp/log] # date; lttng enable-channel chan1 -u -s $TC --buffers-uid --subbuf-size 16384 #--switch-timer 1000000

Fri Apr 12 08:07:51 EDT 2013

UST channel chan1 enabled for session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5

[SC-1:Node16 Fri Apr 12 08:07:59/cluster/temp/log] # echo "Enable channel done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:07:59/cluster/temp/log] # echo "Enable channel metadata...." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:07:59/cluster/temp/log] # date; lttng enable-channel metadata -u -s $TC --buffers-uid --subbuf-size 16384 #--switch-timer 1000000

Fri Apr 12 08:07:59 EDT 2013

UST channel metadata enabled for session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5

[SC-1:Node16 Fri Apr 12 08:07:59/cluster/temp/log] # echo "Enable channel metadata done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:07:59/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:08:04/cluster/temp/log] # lttng add-context -t vpid -u -s $TC

UST context vpid added to all channels

[SC-1:Node16 Fri Apr 12 08:08:05/cluster/temp/log] # echo "Enable Event...." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:08:05/cluster/temp/log] # date; lttng enable-event -s $TC -u -c chan1 $DOMAIN_EVENT --filter "PID == $my_pid"

Fri Apr 12 08:08:05 EDT 2013

Filter 'PID == 32765' successfully set

[SC-1:Node16 Fri Apr 12 08:08:06/cluster/temp/log] # echo "Enable Event done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:08:06/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:08:11/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:08:11/cluster/temp/log] # echo "Activate the session." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:08:11/cluster/temp/log] # #---------------------------------------------------- activate session -----------------------

[SC-1:Node16 Fri Apr 12 08:08:11/cluster/temp/log] # date; lttng start;

Fri Apr 12 08:08:11 EDT 2013

Tracing started for session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5

[SC-1:Node16 Fri Apr 12 08:08:18/cluster/temp/log] # echo "Activate session Done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:08:18/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:08:19/cluster/temp/log] # lttng list $TC

Tracing session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5: [active]

Trace path: net://192.168.0.1:53000/./ [data: 53001]

=== Domain: UST global ===

Channels:

-------------

- chan1: [enabled]

Attributes:

overwrite mode: 0

subbufers size: 16384

number of subbufers: 4

switch timer interval: 0

read timer interval: 200000

output: mmap()

Events:

com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec (type: tracepoint) [enabled] [with filter]

- metadata: [enabled]

Attributes:

overwrite mode: 0

subbufers size: 16384

number of subbufers: 4

switch timer interval: 0

read timer interval: 200000

output: mmap()

Events:

None

[SC-1:Node16 Fri Apr 12 08:08:19/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:08:20/cluster/temp/log] # ps -e |grep -c TestApp

8000

[SC-1:Node16 Fri Apr 12 08:08:21/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5/SC-1/ust/uid/0/64-bit:

total 0

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_2

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:07 metadata

[SC-1:Node16 Fri Apr 12 08:08:21/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:08:22/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5/SC-1/ust/uid/0/64-bit:

total 0

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_2

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:07 metadata

[SC-1:Node16 Fri Apr 12 08:08:22/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:08:23/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5/SC-1/ust/uid/0/64-bit:

total 0

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_2

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:07 metadata

[SC-1:Node16 Fri Apr 12 08:08:23/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:08:24/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5/SC-1/ust/uid/0/64-bit:

total 0

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_2

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:07 metadata

[SC-1:Node16 Fri Apr 12 08:08:24/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:08:25/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5/SC-1/ust/uid/0/64-bit:

total 0

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_2

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_11

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:07 metadata

[SC-1:Node16 Fri Apr 12 08:08:25/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:08:30/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5/SC-1/ust/uid/0/64-bit:

total 32

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_9

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_8

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_7

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_6

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_5

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_4

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_3

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_2

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_10

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_1

-rw-rw---- 1 root root 0 Apr 12 08:07 chan1_0

-rw-rw---- 1 root root 0 Apr 12 08:07 metadata

-rw-rw---- 1 root root 32768 Apr 12 08:08 chan1_11

[SC-1:Node16 Fri Apr 12 08:08:30/cluster/temp/log] # echo "Stopping the session..." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:08:30/cluster/temp/log] # #---------------------------------------------------- De-activate session -----------------------

[SC-1:Node16 Fri Apr 12 08:08:30/cluster/temp/log] # lttng stop

Waiting for data availability

Tracing stopped for session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5

[SC-1:Node16 Fri Apr 12 08:08:34/cluster/temp/log] # echo "Stopping done." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:08:34/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:08:35/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5/SC-1/ust/uid/0/64-bit:

total 1212

-rw-rw---- 1 root root 4096 Apr 12 08:08 metadata

-rw-rw---- 1 root root 4096 Apr 12 08:08 chan1_9

-rw-rw---- 1 root root 12288 Apr 12 08:08 chan1_8

-rw-rw---- 1 root root 4096 Apr 12 08:08 chan1_7

-rw-rw---- 1 root root 4096 Apr 12 08:08 chan1_6

-rw-rw---- 1 root root 303104 Apr 12 08:08 chan1_5

-rw-rw---- 1 root root 12288 Apr 12 08:08 chan1_4

-rw-rw---- 1 root root 4096 Apr 12 08:08 chan1_3

-rw-rw---- 1 root root 8192 Apr 12 08:08 chan1_2

-rw-rw---- 1 root root 864256 Apr 12 08:08 chan1_11

-rw-rw---- 1 root root 4096 Apr 12 08:08 chan1_10

-rw-rw---- 1 root root 4096 Apr 12 08:08 chan1_1

-rw-rw---- 1 root root 4096 Apr 12 08:08 chan1_0

[SC-1:Node16 Fri Apr 12 08:08:35/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:08:40/cluster/temp/log] # echo "Destroying the session..." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:08:40/cluster/temp/log] # lttng destroy

Session LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5 destroyed

[SC-1:Node16 Fri Apr 12 08:08:42/cluster/temp/log] # echo "Destroy done! " >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:08:42/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:08:47/cluster/temp/log] # dir -R $TC/SC-1/ust/uid/0/64-bit

LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5/SC-1/ust/uid/0/64-bit:

total 1264

-rw-rw---- 1 root root 8192 Apr 12 08:08 metadata

-rw-rw---- 1 root root 8192 Apr 12 08:08 chan1_9

-rw-rw---- 1 root root 8192 Apr 12 08:08 chan1_6

-rw-rw---- 1 root root 307200 Apr 12 08:08 chan1_5

-rw-rw---- 1 root root 8192 Apr 12 08:08 chan1_3

-rw-rw---- 1 root root 12288 Apr 12 08:08 chan1_2

-rw-rw---- 1 root root 868352 Apr 12 08:08 chan1_11

-rw-rw---- 1 root root 8192 Apr 12 08:08 chan1_10

-rw-rw---- 1 root root 8192 Apr 12 08:08 chan1_1

-rw-rw---- 1 root root 8192 Apr 12 08:08 chan1_0

-rw-rw---- 1 root root 16384 Apr 12 08:08 chan1_8

-rw-rw---- 1 root root 8192 Apr 12 08:08 chan1_7

-rw-rw---- 1 root root 16384 Apr 12 08:08 chan1_4

[SC-1:Node16 Fri Apr 12 08:08:47/cluster/temp/log] # pkill relayd

[SC-1:Node16 Fri Apr 12 08:08:48/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:08:48/cluster/temp/log] # babeltrace $TC | head -n 10

[08:08:16.214750794] (+?.?????????) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 5 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 1, HundredPs = 7, unit_float = 7.1234, unit_string = "unit_7" }

[08:08:16.224684065] (+0.009933271) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 11 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 1, HundredPs = 8, unit_float = 8.1234, unit_string = "unit_8" }

[08:08:16.234705382] (+0.010021317) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 11 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 1, HundredPs = 9, unit_float = 9.1234, unit_string = "unit_9" }

[08:08:16.244666060] (+0.009960678) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 11 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 2, HundredPs = 0, unit_float = 0.1234, unit_string = "unit_0" }

[08:08:16.254671037] (+0.010004977) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 11 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 2, HundredPs = 1, unit_float = 1.1234, unit_string = "unit_1" }

[08:08:16.264670378] (+0.009999341) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 11 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 2, HundredPs = 2, unit_float = 2.1234, unit_string = "unit_2" }

[08:08:16.274672198] (+0.010001820) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 11 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 2, HundredPs = 3, unit_float = 3.1234, unit_string = "unit_3" }

[08:08:16.284658307] (+0.009986109) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 11 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 2, HundredPs = 4, unit_float = 4.1234, unit_string = "unit_4" }

[08:08:16.294662070] (+0.010003763) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 11 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 2, HundredPs = 5, unit_float = 5.1234, unit_string = "unit_5" }

[08:08:16.304655015] (+0.009992945) SC-1 com_ericsson_cba_trace_testapp100_hightraf:HundredPerSec: { cpu_id = 11 }, { vpid = 32765 }, { my_Time = "08:08:16", PID = 32765, OnePs = 63, TenPs = 2, HundredPs = 6, unit_float = 6.1234, unit_string = "unit_6" }

[2]+ Done lttng-relayd -C tcp://0.0.0.0:53000 -D tcp://0.0.0.0:53001 -o /cluster/temp/log/$TC

[SC-1:Node16 Fri Apr 12 08:08:48/cluster/temp/log] # sleep 1

[SC-1:Node16 Fri Apr 12 08:08:49/cluster/temp/log] # dir /cluster/dumps

total 8456

-rw------- 1 root root 76394496 Apr 9 12:56 lttng-sessiond.2050.SC-1.core

-rw------- 1 root root 76275712 Apr 9 12:58 lttng-sessiond.2530.SC-1.core

-rw------- 1 root root 76275712 Apr 9 12:59 lttng-sessiond.2757.SC-1.core

-rw------- 1 root root 76275712 Apr 9 13:01 lttng-sessiond.2949.SC-1.core

-rw------- 1 root root 76378112 Apr 9 14:36 lttng-sessiond.3169.SC-1.core

-rw------- 1 root root 76410880 Apr 9 14:39 lttng-sessiond.9525.SC-1.core

-rw------- 1 root root 76410880 Apr 9 14:40 lttng-sessiond.9829.SC-1.core

-rw------- 1 root root 76410880 Apr 9 14:52 lttng-sessiond.10003.SC-1.core

-rw------- 1 root root 76275712 Apr 9 15:02 lttng-sessiond.10956.SC-1.core

-rw------- 1 root root 76275712 Apr 9 15:07 lttng-sessiond.11824.SC-1.core

[SC-1:Node16 Fri Apr 12 08:08:49/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:08:54/cluster/temp/log] # echo "Killing TestApp" >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:08:54/cluster/temp/log] # ps -e |grep -c TestApp

8000

[SC-1:Node16 Fri Apr 12 08:08:55/cluster/temp/log] # pkill TestApp

[SC-1:Node16 Fri Apr 12 08:09:02/cluster/temp/log] # echo "Killing Done ." >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:09:02/cluster/temp/log] # ps -e |grep -c TestApp

0

[SC-1:Node16 Fri Apr 12 08:09:02/cluster/temp/log] # sleep 5

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] # pkill sar

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] # cat $TC.load.log

Linux 3.0.42-0.7.3.4775.1.PTF-default (SC-1) 04/12/13 _x86_64_

08:07:08 CPU %user %nice %system %iowait %steal %idle

08:07:09 all 0.00 0.00 0.33 0.00 0.00 99.67

Start to launch apps when no session is active.

08:07:10 all 8.96 0.00 10.74 0.25 0.00 80.05

08:07:11 all 11.12 0.00 11.73 0.00 0.00 77.15

08:07:12 all 11.96 0.00 13.30 0.00 0.00 74.73

08:07:13 all 13.06 0.00 15.45 0.00 0.00 71.49

08:07:14 all 15.34 0.00 17.11 0.00 0.00 67.55

08:07:15 all 16.81 0.00 20.95 0.00 0.00 62.24

08:07:16 all 17.35 0.00 22.68 0.00 0.00 59.97

08:07:17 all 19.69 0.00 22.86 0.00 0.00 57.45

08:07:18 all 19.67 0.00 25.39 0.00 0.00 54.94

08:07:19 all 21.63 0.00 26.32 0.00 0.00 52.04

08:07:20 all 24.17 0.00 27.39 0.00 0.00 48.43

08:07:21 all 26.40 0.00 27.86 0.00 0.00 45.74

08:07:22 all 25.72 0.00 29.97 0.00 0.00 44.31

08:07:23 all 25.74 0.00 30.31 0.00 0.00 43.95

08:07:24 all 25.99 0.00 32.78 0.00 0.00 41.23

08:07:25 all 26.89 0.00 33.22 0.00 0.00 39.90

08:07:26 all 28.38 0.00 32.85 0.00 0.00 38.77

08:07:27 all 30.40 0.00 33.53 0.00 0.00 36.07

08:07:28 all 31.82 0.00 34.55 0.00 0.00 33.64

08:07:29 all 29.27 0.00 34.84 0.00 0.00 35.90

08:07:30 all 33.78 0.00 33.61 0.00 0.00 32.61

08:07:31 all 32.66 0.00 36.97 0.00 0.00 30.37

End of launching apps when no session is active

08:07:32 all 31.20 0.00 35.88 0.26 0.00 32.67

08:07:33 all 29.84 0.00 35.93 0.00 0.00 34.23

08:07:34 all 30.55 0.00 32.28 0.00 0.00 37.17

08:07:35 all 30.31 0.00 33.25 0.00 0.00 36.44

08:07:36 all 29.18 0.00 31.39 0.00 0.00 39.43

08:07:37 all 32.99 0.00 31.14 0.00 0.00 35.87

08:07:38 all 30.37 0.00 31.09 0.00 0.00 38.54

08:07:39 all 29.77 0.00 31.28 0.00 0.00 38.95

08:07:40 all 28.73 0.00 35.04 0.00 0.00 36.23

08:07:41 all 28.77 0.00 31.16 0.00 0.00 40.07

08:07:42 all 28.21 0.00 32.61 0.00 0.00 39.18

08:07:43 all 30.60 0.00 32.05 0.00 0.00 37.35

08:07:44 all 30.06 0.00 32.14 0.00 0.00 37.80

08:07:45 all 28.48 0.00 34.00 0.00 0.00 37.52

Create the session.

08:07:46 all 32.25 0.00 34.28 0.16 0.00 33.31

08:07:47 all 27.79 0.00 35.18 0.00 0.00 37.03

08:07:48 all 28.26 0.00 32.21 0.00 0.00 39.53

08:07:49 all 28.42 0.00 31.88 0.00 0.00 39.70

08:07:50 all 32.12 0.00 34.27 0.00 0.00 33.61

Enable channel....

08:07:51 all 29.58 0.00 32.81 0.39 0.00 37.21

08:07:52 all 31.76 0.00 35.38 0.00 0.00 32.86

08:07:53 all 30.44 0.00 39.20 0.00 0.00 30.36

08:07:54 all 29.56 0.00 35.78 0.00 0.00 34.65

08:07:55 all 31.85 0.00 33.19 0.00 0.00 34.95

08:07:56 all 29.94 0.00 35.65 0.00 0.00 34.42

08:07:57 all 30.96 0.00 32.70 0.00 0.00 36.35

08:07:58 all 30.47 0.00 33.42 0.00 0.00 36.11

08:07:59 all 29.96 0.00 36.19 0.00 0.00 33.85

Enable channel done.

Enable channel metadata....

Enable channel metadata done.

08:08:00 all 26.87 0.00 31.05 0.27 0.00 41.81

08:08:01 all 23.97 0.00 30.95 0.00 0.00 45.09

08:08:02 all 27.76 0.00 31.76 0.00 0.00 40.48

08:08:03 all 29.02 0.00 27.70 0.00 0.00 43.27

08:08:04 all 27.93 0.00 28.72 0.00 0.00 43.35

Enable Event....

08:08:05 all 32.33 0.00 31.98 0.26 0.00 35.42

Enable Event done.

08:08:06 all 29.85 0.00 34.27 0.17 0.00 35.71

08:08:07 all 29.16 0.00 28.64 0.00 0.00 42.20

08:08:08 all 29.27 0.00 33.50 0.00 0.00 37.23

08:08:09 all 29.13 0.00 29.21 0.00 0.00 41.66

08:08:10 all 29.79 0.00 28.08 0.00 0.00 42.12

Activate the session.

08:08:11 all 30.38 0.00 30.89 0.09 0.00 38.64

08:08:12 all 32.38 0.00 33.68 0.00 0.00 33.94

08:08:13 all 36.21 0.00 32.22 0.00 0.00 31.57

08:08:14 all 42.30 0.00 33.62 0.00 0.00 24.08

08:08:15 all 45.13 0.00 36.05 0.00 0.00 18.82

08:08:16 all 47.39 0.00 35.64 0.00 0.00 16.97

08:08:17 all 54.68 0.00 32.14 0.00 0.00 13.18

Activate session Done.

08:08:18 all 55.97 0.00 32.98 0.09 0.00 10.96

08:08:19 all 53.81 0.00 30.05 0.00 0.00 16.13

08:08:20 all 54.54 0.00 32.16 0.00 0.00 13.30

08:08:21 all 56.29 0.00 37.05 0.00 0.00 6.66

08:08:22 all 54.01 0.00 32.80 0.00 0.00 13.19

08:08:23 all 53.17 0.00 31.28 0.00 0.00 15.55

08:08:24 all 53.59 0.00 35.04 0.00 0.00 11.38

08:08:25 all 53.03 0.00 30.85 0.00 0.00 16.12

08:08:26 all 54.38 0.00 29.32 0.00 0.00 16.30

08:08:27 all 53.91 0.00 34.44 0.00 0.00 11.65

08:08:28 all 54.83 0.00 29.97 0.00 0.00 15.20

08:08:29 all 54.14 0.00 31.45 0.00 0.00 14.41

08:08:30 all 55.58 0.00 32.66 0.00 0.00 11.75

Stopping the session...

08:08:31 all 55.31 0.00 30.84 0.08 0.00 13.77

08:08:32 all 50.33 0.00 32.81 0.00 0.00 16.86

08:08:33 all 42.61 0.00 37.38 0.00 0.00 20.02

Stopping done.

08:08:34 all 32.78 0.00 32.51 0.18 0.00 34.54

08:08:35 all 27.08 0.00 30.85 1.03 0.00 41.05

08:08:36 all 28.92 0.00 32.46 0.00 0.00 38.62

08:08:37 all 26.45 0.00 32.56 0.00 0.00 40.99

08:08:38 all 26.84 0.00 32.15 0.00 0.00 41.01

08:08:39 all 27.56 0.00 34.29 0.00 0.00 38.15

Destroying the session...

08:08:40 all 28.85 0.00 33.07 0.08 0.00 38.00

08:08:41 all 30.82 0.00 33.67 0.08 0.00 35.43

08:08:42 all 31.10 0.00 36.74 0.00 0.00 32.15

Destroy done!

08:08:43 all 30.72 0.00 31.54 1.31 0.00 36.44

08:08:44 all 28.48 0.00 31.23 0.00 0.00 40.29

08:08:45 all 29.44 0.00 32.40 0.00 0.00 38.16

08:08:46 all 31.34 0.00 31.81 0.00 0.00 36.85

08:08:47 all 30.76 0.00 30.53 0.00 0.00 38.71

08:08:48 all 30.55 0.00 35.50 0.00 0.00 33.95

08:08:49 all 29.43 0.00 33.47 0.00 0.00 37.10

08:08:50 all 27.93 0.00 31.70 0.00 0.00 40.38

08:08:51 all 29.90 0.00 30.23 0.00 0.00 39.87

08:08:52 all 31.22 0.00 33.31 0.00 0.00 35.47

08:08:53 all 28.64 0.00 32.49 0.00 0.00 38.87

Killing TestApp

08:08:54 all 30.95 0.00 31.18 0.16 0.00 37.71

08:08:55 all 31.54 0.00 37.59 0.00 0.00 30.87

08:08:56 all 27.36 0.00 50.50 0.00 0.00 22.14

08:08:57 all 23.42 0.00 57.33 0.00 0.00 19.25

08:08:58 all 23.72 0.00 55.68 0.00 0.00 20.59

08:08:59 all 16.65 0.00 57.24 0.00 0.00 26.11

08:09:00 all 14.32 0.00 60.61 0.00 0.00 25.06

08:09:01 all 12.28 0.00 53.63 0.00 0.00 34.09

Killing Done .

08:09:02 all 3.85 0.00 33.68 0.43 0.00 62.05

08:09:03 all 0.00 0.00 0.08 0.00 0.00 99.92

08:09:04 all 0.00 0.00 0.25 0.00 0.00 99.75

08:09:05 all 0.00 0.00 0.08 0.00 0.00 99.92

08:09:06 all 0.08 0.00 0.17 0.00 0.00 99.75

[1]+ Terminated sar -u 1 300 >> $TC.load.log

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] # rm $TC.load.log

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] # babeltrace $TC | grep -c $DOMAIN_EVENT

1762

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] # babeltrace $TC | wc -l

1762

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] # du -h $TC | tail -n 1

1.3M LTTNGgbf_017_8kAppFirst_NoTimer_Pid_buf16k_100ps_run5

[SC-1:Node16 Fri Apr 12 08:09:07/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:10:06/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:10:06/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:10:07/cluster/temp/log] #

[SC-1:Node16 Fri Apr 12 08:10:07/cluster/temp/log] #