Project

General

Profile

Bug #349 ยป filters_dont_work_with_old_apps.txt

Jesus Garcia, 09/21/2012 10:21 AM

 
==========================================================================================
Tracing with apps compiled with old lttng
------------------------------------------------------------------------------------------
CURRENT HEAD: foss/babeltrace 2ae35d4 (HEAD, tag: v1.0.0-rc4) Update version to 1.0.0-rc4
CURRENT HEAD: foss/lttng-tools 6c12303 (HEAD, tag: v2.0.4) Update version to 2.0.4 stable
CURRENT HEAD: foss/lttng-ust f8b9341 (HEAD, tag: v2.0.4) Update version to 2.0.4
CURRENT HEAD: foss/userspace-rcu 3227f2c (HEAD, tag: v0.7.3) Update version to 0.7.3
==========================================================================================

SC-1:~ # date
Thu Sep 20 23:22:37 EDT 2012
SC-1:~ # lttng -h
LTTng Trace Control 2.1.0-rc3 - Basse Messe

usage: lttng [OPTIONS] <COMMAND> [<ARGS>]

Options:
-h, --help Show this help
--list-options Simple listing of lttng options
--list-commands Simple listing of lttng commands
-v, --verbose Increase verbosity
-q, --quiet Quiet mode
-g, --group NAME Unix tracing group name. (default: tracing)
-n, --no-sessiond Don't spawn a session daemon
--sessiond-path PATH Session daemon full path

Commands:
add-context Add context to event and/or channel
calibrate Quantify LTTng overhead
create Create tracing session
destroy Tear down tracing session
enable-channel Enable tracing channel
enable-event Enable tracing event
disable-channel Disable tracing channel
disable-event Disable tracing event
enable-consumer Enable local or streaming consumer
disable-consumer Disable consumer
list List possible tracing options
set-session Set current session name
start Start tracing
stop Stop tracing
version Show version information
view Start trace viewer

Each command also has its own -h, --help option.

Please see the lttng(1) man page for full documentation.
See http://lttng.org for updates, bug reports and news.
SC-1:~ #
SC-1:~ #
SC-1:~ # ps -eaf | egrep "trace|lttng|TestApp"
root 6679 1 0 14:45 ? 00:00:00 lttng-sessiond -d
root 15528 12001 0 23:23 pts/0 00:00:00 egrep trace|lttng|TestApp
root 16242 1 0 14:50 ? 00:00:05 /opt/trace_ea/bin/TraceEa
root 16483 16242 0 14:50 ? 00:00:00 /opt/trace_ea/bin/TraceEa
SC-1:~ #
SC-1:~ #
SC-1:~ # lttng list
Currently no available tracing session
SC-1:~ #
SC-1:~ # lttng create ses1
Session ses1 created.
Traces will be written in /root/lttng-traces/ses1-20120920-232402
SC-1:~ #
SC-1:~ # lttng enable-event com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA -u --filter ' TenPs==1'
UST event com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA created in channel channel0
SC-1:~ #
SC-1:~ # lttng start
Tracing started for session ses1
SC-1:~ #
SC-1:~ #
SC-1:~ # /home/test_apps/TestApp_type1 5 np &
[1] 15600
SC-1:~ #
SC-1:~ #
SC-1:~ # 23:24:47end of program

[1]+ Done /home/test_apps/TestApp_type1 5 np
SC-1:~ #
SC-1:~ # lttng list
Available tracing sessions:
1) ses1 (/root/lttng-traces/ses1-20120920-232402) [active]

Use lttng list <session_name> for more details
SC-1:~ #
SC-1:~ #
SC-1:~ # lttng list -u
UST events:
-------------
None

SC-1:~ #
SC-1:~ #
SC-1:~ # lttng stop
Tracing stopped for session ses1
SC-1:~ #
SC-1:~ # lttng list
Available tracing sessions:
1) ses1 (/root/lttng-traces/ses1-20120920-232402) [inactive]

Use lttng list <session_name> for more details
SC-1:~ #
SC-1:~ #
SC-1:~ # babeltrace --no-delta /root/lttng-traces/ses1-20120920-232402
[23:24:42.834811487] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:42", OnePs = 0, TenPs = 7 }
[23:24:42.877485520] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:42", OnePs = 0, TenPs = 8 }
[23:24:42.977488386] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:42", OnePs = 0, TenPs = 9 }
[23:24:43.077523721] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 0 }
[23:24:43.177482799] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 1 }
[23:24:43.277482892] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 2 }
[23:24:43.377492215] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 3 }
[23:24:43.477482871] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 4 }
[23:24:43.577484003] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 5 }
[23:24:43.677482598] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 6 }
[23:24:43.777481548] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 7 }
[23:24:43.877486029] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 8 }
[23:24:43.977485465] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:43", OnePs = 1, TenPs = 9 }
[23:24:44.077535847] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 0 }
[23:24:44.177486482] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 1 }
[23:24:44.277488206] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 2 }
[23:24:44.377483661] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 3 }
[23:24:44.477485910] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 4 }
[23:24:44.577585052] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 5 }
[23:24:44.677488925] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 6 }
[23:24:44.777485161] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 7 }
[23:24:44.877593328] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 8 }
[23:24:44.977590638] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:44", OnePs = 2, TenPs = 9 }
[23:24:45.077615121] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 0 }
[23:24:45.177483657] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 1 }
[23:24:45.277484521] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 2 }
[23:24:45.377483146] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 3 }
[23:24:45.477483185] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 4 }
[23:24:45.577482947] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 5 }
[23:24:45.677583267] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 6 }
[23:24:45.777583120] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 7 }
[23:24:45.877582880] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 8 }
[23:24:45.977483212] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:45", OnePs = 3, TenPs = 9 }
[23:24:46.077515964] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 0 }
[23:24:46.177482885] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 1 }
[23:24:46.277484194] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 2 }
[23:24:46.377482045] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 3 }
[23:24:46.477486401] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 4 }
[23:24:46.577483229] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 5 }
[23:24:46.677483569] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 6 }
[23:24:46.777482805] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 7 }
[23:24:46.877482539] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 8 }
[23:24:46.977486175] SC-1:TestApp_type1:15600 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 3 }, { my_Time = "23:24:46", OnePs = 4, TenPs = 9 }
SC-1:~ #
SC-1:~ #
SC-1:~ #
SC-1:~ #
SC-1:~ #
SC-1:~ # lttng destroy
Session ses1 destroyed
SC-1:~ #




==========================================================================================
Tracing with apps compiled with new lttng
------------------------------------------------------------------------------------------
CURRENT HEAD: foss/babeltrace 9b3c1d6 (HEAD, origin/master, origin/HEAD) Fix: emf uri: surround by " "
CURRENT HEAD: foss/lttng-tools 6b8f2e6 (HEAD, origin/master, origin/HEAD) Add consumer commands to lttng.1 man page
CURRENT HEAD: foss/lttng-ust 82513db (HEAD, origin/master, origin/HEAD) Filter error message cleanup
CURRENT HEAD: foss/userspace-rcu a5a9f42 (HEAD, origin/master, origin/HEAD, master) Ensure that read-side functions meet 10-line LGPL criterion
==========================================================================================

SC-1:~ # date
Thu Sep 20 23:33:20 EDT 2012
SC-1:~ #
SC-1:~ # lttng -h
LTTng Trace Control 2.1.0-rc3 - Basse Messe

usage: lttng [OPTIONS] <COMMAND> [<ARGS>]

Options:
-h, --help Show this help
--list-options Simple listing of lttng options
--list-commands Simple listing of lttng commands
-v, --verbose Increase verbosity
-q, --quiet Quiet mode
-g, --group NAME Unix tracing group name. (default: tracing)
-n, --no-sessiond Don't spawn a session daemon
--sessiond-path PATH Session daemon full path

Commands:
add-context Add context to event and/or channel
calibrate Quantify LTTng overhead
create Create tracing session
destroy Tear down tracing session
enable-channel Enable tracing channel
enable-event Enable tracing event
disable-channel Disable tracing channel
disable-event Disable tracing event
enable-consumer Enable local or streaming consumer
disable-consumer Disable consumer
list List possible tracing options
set-session Set current session name
start Start tracing
stop Stop tracing
version Show version information
view Start trace viewer

Each command also has its own -h, --help option.

Please see the lttng(1) man page for full documentation.
See http://lttng.org for updates, bug reports and news.
SC-1:~ #
SC-1:~ # ps -eaf | egrep "trace|lttng|TestApp"
root 6679 1 0 14:45 ? 00:00:00 lttng-sessiond -d
root 15576 6679 0 23:24 ? 00:00:00 lttng-consumerd --quiet -u --consumerd-cmd-sock /var/run/lttng/ustconsumerd64/command --consumerd-err-sock /var/run/lttng/ustconsumerd64/error
root 16154 12001 0 23:33 pts/0 00:00:00 egrep trace|lttng|TestApp
root 16242 1 0 14:50 ? 00:00:06 /opt/trace_ea/bin/TraceEa
root 16483 16242 0 14:50 ? 00:00:00 /opt/trace_ea/bin/TraceEa
SC-1:~ #
SC-1:~ #
SC-1:~ # lttng list
Currently no available tracing session
SC-1:~ #
SC-1:~ #
SC-1:~ # lttng create ses2
Session ses2 created.
Traces will be written in /root/lttng-traces/ses2-20120920-233358
SC-1:~ # lttng enable-event com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA -u --filter ' TenPs==1'
UST event com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA created in channel channel0
SC-1:~ #
SC-1:~ # lttng start
Tracing started for session ses2
SC-1:~ #
SC-1:~ # /home/test_apps/new_apps/TestApp_type1 3 np &
[1] 16215
SC-1:~ # 23:34:43end of program

[1]+ Done /home/test_apps/new_apps/TestApp_type1 3 np
SC-1:~ #
SC-1:~ #
SC-1:~ # lttng list
Available tracing sessions:
1) ses2 (/root/lttng-traces/ses2-20120920-233358) [active]

Use lttng list <session_name> for more details
SC-1:~ #
SC-1:~ #
SC-1:~ # lttng stop
Tracing stopped for session ses2
SC-1:~ #
SC-1:~ # lttng list
Available tracing sessions:
1) ses2 (/root/lttng-traces/ses2-20120920-233358) [inactive]

Use lttng list <session_name> for more details
SC-1:~ #
SC-1:~ # ps -eaf | egrep "trace|lttng|TestApp"
root 6679 1 0 14:45 ? 00:00:00 lttng-sessiond -d
root 15576 6679 0 23:24 ? 00:00:00 lttng-consumerd --quiet -u --consumerd-cmd-sock /var/run/lttng/ustconsumerd64/command --consumerd-err-sock /var/run/lttng/ustconsumerd64/error
root 16242 1 0 14:50 ? 00:00:06 /opt/trace_ea/bin/TraceEa
root 16262 12001 0 23:35 pts/0 00:00:00 egrep trace|lttng|TestApp
root 16483 16242 0 14:50 ? 00:00:00 /opt/trace_ea/bin/TraceEa
SC-1:~ #
SC-1:~ #
SC-1:~ #
SC-1:~ #
SC-1:~ # babeltrace --no-delta /root/lttng-traces/ses2-20120920-233358
[23:34:40.204507031] SC-1:TestApp_type1:16215 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 1 }, { my_Time = "23:34:40", OnePs = 0, TenPs = 1, unit_float = 1.1234, unit_string = "unit_1", stringAllSigns = "~`!@#$%^&*()-_=+\|{}[]'":;?/>.<," }
[23:34:41.177490622] SC-1:TestApp_type1:16215 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 1 }, { my_Time = "23:34:41", OnePs = 1, TenPs = 1, unit_float = 1.1234, unit_string = "unit_1", stringAllSigns = "~`!@#$%^&*()-_=+\|{}[]'":;?/>.<," }
[23:34:42.177589405] SC-1:TestApp_type1:16215 com_ericsson_cba_trace_testapp_lowtraf:TenPerSecA: { cpu_id = 1 }, { my_Time = "23:34:42", OnePs = 2, TenPs = 1, unit_float = 1.1234, unit_string = "unit_1", stringAllSigns = "~`!@#$%^&*()-_=+\|{}[]'":;?/>.<," }
SC-1:~ #
SC-1:~ #
    (1-1/1)