Bug #497


lttng 2.2.0rc1: Size of session directory is very inconsistent when repeating the same test condition several time

Added by Tan le tran about 11 years ago. Updated about 11 years ago.

Target version:
Start date:
Due date:
% Done:


Estimated time:


Problem Description:
 * Not sure which project (ust or tools) this one should be reported to...

 * (Streaming is used when this issue has been encountered)
   When repeating the same test condition a couple of time, we notice that the total filesize
   of the session directory varies quite a bit and a propper explaination can not be deducted 
   for why they differ. It ranges from ~300KB to 1.4MB even if the session only contain 
   a close amount of trace logs.

   The following summary is extracted from the printouts of the last 2 lines 
   of the test instructions below at different run number:
       babeltrace $TC | grep -c $DOMAIN_EVENT
       du -h $TC | tail -n 1 

       --switch-timer   Run#   Number of lines     Size of session
                               seen by babeltrace  directory
       ==============   ====   ==================  ===============
         1000000        1      1760                1.4M
         1000000        2      2002                0.38M
         1000000        3      1691                1.5M
         0              1      1655                1.4M
         0              2      2064                0.24M
         0              3      1943                0.78M

 * When babeltrace run1 (switchTimer 1sec) above, the total file size
   of the output of babeltrace is only about 400K. Why is the corresponding
   CTF binary take more than triple that size ?

 * When trying to run the above without streaming, another fault is encountered
   (will be reported in a separated bug) and therefore, no comparision can be made.

Is problem reproducible ?
  * yes 

How to reproduce (if reproducible):
       export TC=LTTNGgbf_017_8kAppFirst_1s_Pid_buf16k_100ps_run1

       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:// -D tcp://  -o /cluster/temp/log/$TC &
       echo "Create the session." >> $TC.load.log
       date; lttng create $TC -U net://
       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
       du -h $TC | tail -n 1 

Commit used:
babeltrace    : 740aad2 (HEAD, origin/master, origin/HEAD) Show token in CTF parser error
lttng-tools   : 500c239 (HEAD, tag: v2.2.0-rc1, origin/master, origin/HEAD) Update version to v2.2.0-rc1
lttng-ust     : 9c915ee (HEAD, tag: v2.2.0-rc1, origin/master, origin/HEAD) Version 2.2.0-rc1
userspace-rcu : d107390 (HEAD, origin/master, origin/HEAD, globalBuffer) Add tab to output in ...

Any other information:


TC17_node16_8KAppFirst_noTimer_TraceOn1pid_buf16k_100ps_a_b_c.log (97.9 KB) TC17_node16_8KAppFirst_noTimer_TraceOn1pid_buf16k_100ps_a_b_c.log Runs with streaming, SwitchTimer 0 Tan le tran, 04/09/2013 09:52 AM
TC17_node16_8KAppFirst_Timer1s_TraceOn1pid_buf16k_100ps_a_b_c.log (98.5 KB) TC17_node16_8KAppFirst_Timer1s_TraceOn1pid_buf16k_100ps_a_b_c.log Runs with streaming, SwitchTimer 1sec Tan le tran, 04/09/2013 09:52 AM
run4_run5_terminal.log (66 KB) run4_run5_terminal.log terminal log for run4 and 5 Tan le tran, 04/12/2013 08:50 AM
run4.tar (21.2 KB) run4.tar session dir Tan le tran, 04/12/2013 08:50 AM
run5.tar (24.5 KB) run5.tar session dir Tan le tran, 04/12/2013 08:50 AM
Apr22_bug497_sessionDirs.tar (78.9 KB) Apr22_bug497_sessionDirs.tar Session directories with ctf files Tan le tran, 04/22/2013 02:07 PM
Apr22_runs_terminal.log (130 KB) Apr22_runs_terminal.log Terminal logs Tan le tran, 04/22/2013 02:07 PM
TestApp_100perSecOnly.tar (415 KB) TestApp_100perSecOnly.tar TestApp_100perSecOnly (used in this bug report) Tan le tran, 04/22/2013 02:07 PM
fix-per-uid-flush.patch (5.83 KB) fix-per-uid-flush.patch Mathieu Desnoyers, 04/26/2013 03:27 PM

Also available in: Atom PDF