def __init__(self):
TestBase.__init__(self, 'fork', """
# DURATION TID FUNCTION
[26125] | __cxa_atexit() {
68.297 us [26125] | } /* __cxa_atexit */
[26125] | main() {
[26125] | fork() {
101.456 us [26125] | } /* fork */
[26125] | wait() {
298.356 us [26126] | } /* fork */
[26126] | a() {
[26126] | b() {
[26126] | c() {
[26126] | getpid() {
1.206 us [26126] | } /* getpid */
1.925 us [26126] | } /* c */
2.531 us [26126] | } /* b */
3.151 us [26126] | } /* a */
333.039 us [26126] | } /* main */
19.376 us [26125] | } /* wait */
[26125] | a() {
[26125] | b() {
[26125] | c() {
[26125] | getpid() {
5.031 us [26125] | } /* getpid */
5.934 us [26125] | } /* c */
6.520 us [26125] | } /* b */
7.140 us [26125] | } /* a */
420.059 us [26125] | } /* main */
""")
def build(self, name, cflags='', ldflags=''):
if TestBase.build_libfoo(self, 'bar', cflags, ldflags) != 0:
return TestBase.TEST_BUILD_FAIL
if TestBase.build_libfoo(self, 'baz', cflags, ldflags + ' -L. -lbar') != 0:
return TestBase.TEST_BUILD_FAIL
return TestBase.build_libmain(self, name, 's-dlopen2.cpp', ['libdl.so'],
cflags, ldflags)
def __init__(self):
TestBase.__init__(self, 'longjmp3', """
# DURATION TID FUNCTION
1.164 us [ 4107] | __monstartup();
0.657 us [ 4107] | __cxa_atexit();
[ 4107] | main() {
0.705 us [ 4107] | _setjmp() = 0;
1.823 us [ 4107] | getpid();
0.182 us [ 4107] | _setjmp() = 0;
[ 4107] | foo() {
[ 4107] | longjmp(1) {
8.790 us [ 4107] | } = 1; /* _setjmp */
0.540 us [ 4107] | getpid();
[ 4107] | bar() {
[ 4107] | baz() {
[ 4107] | longjmp(2) {
1.282 us [ 4107] | } = 2; /* _setjmp */
0.540 us [ 4107] | getpid();
[ 4107] | foo() {
[ 4107] | longjmp(3) {
0.578 us [ 4107] | } = 3; /* _setjmp */
[ 4107] | bar() {
[ 4107] | baz() {
[ 4107] | longjmp(4) {
0.642 us [ 4107] | } = 4; /* _setjmp */
18.019 us [ 4107] | } /* main */
""")
def build(self, name, cflags='', ldflags=''):
if TestBase.build_libabc(self, cflags, ldflags) != 0:
return TestBase.TEST_BUILD_FAIL
if TestBase.build_libfoo(self, 'foo', cflags, ldflags) != 0:
return TestBase.TEST_BUILD_FAIL
return TestBase.build_libmain(self, name, 's-dlopen.c', ['libdl.so'],
cflags, ldflags)
def __init__(self):
TestBase.__init__(self, 'abc', """
a enter
b enter
b exit
a exit
""")
def __init__(self):
TestBase.__init__(self, 'exception', lang='C++', result="""
# DURATION TID FUNCTION
2.777 us [10827] | __cxa_atexit();
[10827] | foo() {
[10827] | __static_initialization_and_destruction_0() {
108.818 us [10827] | std::ios_base::Init::Init();
0.350 us [10827] | __cxa_atexit();
111.039 us [10827] | } /* __static_initialization_and_destruction_0 */
111.488 us [10827] | } /* foo */
[10827] | main() {
0.078 us [10827] | foo();
[10827] | test() {
[10827] | oops() {
1.752 us [10827] | __cxa_allocate_exception();
0.088 us [10827] | std::exception::exception();
9.640 us [10827] | __gxx_personality_v0();
9.640 us [10827] | __gxx_personality_v0();
9.640 us [10827] | __gxx_personality_v0();
84.367 us [10827] | } /* oops */
9.640 us [10827] | __gxx_personality_v0();
1.903 us [10827] | __gxx_personality_v0();
0.873 us [10827] | std::exception::~exception();
84.652 us [10827] | } /* test */
0.090 us [10827] | bar();
85.590 us [10827] | } /* main */
2.352 us [10827] | std::ios_base::Init::~Init();
""")
def __init__(self):
TestBase.__init__(self, 'allocfree', """
# DURATION TID FUNCTION
3.937 us [ 447] | __monstartup();
1.909 us [ 447] | __cxa_atexit();
[ 447] | main() {
[ 447] | alloc1() {
[ 447] | alloc2() {
[ 447] | alloc3() {
[ 447] | alloc4() {
[ 447] | alloc5() {
8.408 us [ 447] | malloc(1);
10.642 us [ 447] | } /* alloc5 */
11.502 us [ 447] | } /* alloc4 */
12.057 us [ 447] | } /* alloc3 */
12.780 us [ 447] | } /* alloc2 */
13.400 us [ 447] | } /* alloc1 */
[ 447] | free1() {
[ 447] | free2() {
[ 447] | free3() {
[ 447] | free4() {
[ 447] | free5() {
2.072 us [ 447] | free();
3.951 us [ 447] | } /* free5 */
4.561 us [ 447] | } /* free4 */
5.151 us [ 447] | } /* free3 */
5.713 us [ 447] | } /* free2 */
6.341 us [ 447] | } /* free1 */
21.174 us [ 447] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'lib', """
# DURATION TID FUNCTION
[17459] | lib_b() {
6.911 us [17459] | lib_c();
8.279 us [17459] | } /* lib_b */
""", sort='simple')
def __init__(self):
TestBase.__init__(self, 'sleep', serial=True, result="""
{"traceEvents":[
{"ts":0,"ph":"M","pid":306,"name":"process_name","args":{"name":"[306] t-sleep"}},
{"ts":0,"ph":"M","pid":306,"name":"thread_name","args":{"name":"[306] t-sleep"}},
{"ts":112150305218.363,"ph":"B","pid":306,"name":"__monstartup"},
{"ts":112150305220.090,"ph":"E","pid":306,"name":"__monstartup"},
{"ts":112150305224.313,"ph":"B","pid":306,"name":"__cxa_atexit"},
{"ts":112150305225.219,"ph":"E","pid":306,"name":"__cxa_atexit"},
{"ts":112150305226.496,"ph":"B","pid":306,"name":"main"},
{"ts":112150305226.752,"ph":"B","pid":306,"name":"foo"},
{"ts":112150305226.825,"ph":"B","pid":306,"name":"mem_alloc"},
{"ts":112150305226.921,"ph":"B","pid":306,"name":"malloc"},
{"ts":112150305227.641,"ph":"E","pid":306,"name":"malloc"},
{"ts":112150305228.173,"ph":"E","pid":306,"name":"mem_alloc"},
{"ts":112150305228.317,"ph":"B","pid":306,"name":"bar"},
{"ts":112150305228.436,"ph":"B","pid":306,"name":"usleep"},
{"ts":112150305241.755,"ph":"B","pid":306,"name":"linux:schedule"},
{"ts":112150307301.727,"ph":"E","pid":306,"name":"linux:schedule"},
{"ts":112150307318.143,"ph":"E","pid":306,"name":"usleep"},
{"ts":112150307321.099,"ph":"E","pid":306,"name":"bar"},
{"ts":112150307322.007,"ph":"B","pid":306,"name":"mem_free"},
{"ts":112150307323.132,"ph":"B","pid":306,"name":"free"},
{"ts":112150307328.403,"ph":"E","pid":306,"name":"free"},
{"ts":112150307328.615,"ph":"E","pid":306,"name":"mem_free"},
{"ts":112150307328.742,"ph":"E","pid":306,"name":"foo"},
{"ts":112150307328.905,"ph":"E","pid":306,"name":"main"}
], "displayTimeUnit": "ns", "metadata": {
"command_line":"uftrace record -d xxx -E linux:schedule t-sleep ",
"recorded_time":"Fri Aug 25 14:23:29 2017"
} }
""", sort='chrome')
def __init__(self):
TestBase.__init__(self, 'dlopen', """1
# DURATION TID FUNCTION
1.404 us [22207] | __cxa_atexit();
[22207] | main() {
70.963 us [22207] | dlopen();
1.546 us [22207] | dlsym();
[22207] | lib_a() {
[22207] | lib_b() {
0.678 us [22207] | lib_c();
1.301 us [22207] | } /* lib_b */
2.104 us [22207] | } /* lib_a */
14.446 us [22207] | dlclose();
[22207] | dlopen() {
[22207] | s_libfoo.cpp() {
88.318 us [22207] | __static_initialization_and_destruction_0();
88.719 us [22207] | } /* s_libfoo.cpp */
148.243 us [22207] | } /* dlopen */
0.844 us [22207] | dlsym();
[22207] | foo() {
19.601 us [22207] | print_int();
19.869 us [22207] | } /* foo */
13.391 us [22207] | dlclose();
274.723 us [22207] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'posix_spawn', """
# DURATION TID FUNCTION
[ 9874] | main() {
142.145 us [ 9874] | posix_spawn();
[ 9874] | waitpid() {
[ 9875] | main() {
[ 9875] | a() {
[ 9875] | b() {
[ 9875] | c() {
0.976 us [ 9875] | getpid();
1.992 us [ 9875] | } /* c */
2.828 us [ 9875] | } /* b */
3.658 us [ 9875] | } /* a */
7.713 us [ 9875] | } /* main */
2.515 ms [ 9874] | } /* waitpid */
142.145 us [ 9874] | posix_spawn();
[ 9874] | waitpid() {
[ 9876] | main() {
2.828 us [ 9876] | fopen();
3.658 us [ 9876] | fclose();
7.713 us [ 9876] | } /* main */
2.515 ms [ 9874] | } /* waitpid */
2.708 ms [ 9874] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'sleep', result="""
# DURATION TID FUNCTION
[18229] | bar() {
2.078 ms [18229] | usleep();
2.080 ms [18229] | } /* bar */
""", sort='simple')
def __init__(self):
TestBase.__init__(self, 'fork', """
# DURATION TID FUNCTION
[ 1661] | main() {
[ 1661] | fork() {
5.135 us [ 1661] | sys_writev();
32.391 us [ 1661] | do_syscall_64();
12.192 us [ 1661] | __do_page_fault();
10.982 us [ 1661] | __do_page_fault();
9.183 us [ 1661] | __do_page_fault();
130.930 us [ 1661] | } /* fork */
17.134 us [ 1661] | __do_page_fault();
12.813 us [ 1661] | __do_page_fault();
9.465 us [ 1661] | __do_page_fault();
3.187 us [ 1661] | __do_page_fault();
6.873 us [ 1661] | __do_page_fault();
[ 1661] | wait() {
6.508 us [ 1661] | __do_page_fault();
7.074 us [ 1661] | sys_wait4();
691.873 us [ 1661] | } /* wait */
[ 1661] | a() {
[ 1661] | b() {
[ 1661] | c() {
4.234 us [ 1661] | getpid();
5.680 us [ 1661] | } /* c */
6.094 us [ 1661] | } /* b */
6.602 us [ 1661] | } /* a */
849.948 us [ 1661] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'namespace', lang="C++", result="""
# Function Call Graph for 'main' (session: b508f628ffe7287f)
=============== BACKTRACE ===============
backtrace #0: hit 1, time 17.931 us
[0] main (0x400790)
========== FUNCTION CALL GRAPH ==========
17.931 us : (1) main
2.087 us : +-(2) operator new
: |
0.183 us : +-(1) ns::ns1::foo::foo
: |
4.816 us : +-(1) ns::ns1::foo::bar
2.810 us : | +-(1) ns::ns1::foo::bar1
2.536 us : | | (1) ns::ns1::foo::bar2
2.240 us : | | (1) ns::ns1::foo::bar3
: | |
1.356 us : | +-(1) free
: |
2.624 us : +-(2) operator delete
: |
0.093 us : +-(1) ns::ns2::foo::foo
: |
1.997 us : +-(1) ns::ns2::foo::bar
1.286 us : +-(1) ns::ns2::foo::bar1
1.017 us : | (1) ns::ns2::foo::bar2
0.740 us : | (1) ns::ns2::foo::bar3
: |
0.187 us : +-(1) free
""", sort='graph')
def __init__(self):
TestBase.__init__(self, 'allocfree', """
# DURATION TID FUNCTION
2.417 us [32130] | __monstartup();
1.535 us [32130] | __cxa_atexit();
[32130] | main() {
[32130] | alloc1(1) {
[32130] | alloc2(1) {
[32130] | alloc3(1) {
[32130] | alloc4(1) {
[32130] | alloc5(1) {
1.850 us [32130] | malloc(1);
4.284 us [32130] | } /* alloc5 */
11.517 us [32130] | } /* alloc4 */
12.357 us [32130] | } /* alloc3 */
13.036 us [32130] | } /* alloc2 */
14.543 us [32130] | } /* alloc1 */
[32130] | free1() {
[32130] | free2() {
[32130] | free3() {
[32130] | free4() {
[32130] | free5() {
1.394 us [32130] | free();
2.970 us [32130] | } /* free5 */
3.531 us [32130] | } /* free4 */
4.064 us [32130] | } /* free3 */
4.641 us [32130] | } /* free2 */
5.271 us [32130] | } /* free1 */
21.319 us [32130] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'abc', """
uftrace file header: magic = 4674726163652100
uftrace file header: version = 4
uftrace file header: header size = 40
uftrace file header: endian = 1 (little)
uftrace file header: class = 2 (64 bit)
uftrace file header: features = 0x363 (PLTHOOK | TASK_SESSION | SYM_REL_ADDR | MAX_STACK | PERF_EVENT | AUTO_ARGS)
uftrace file header: info = 0x3bff
reading 5231.dat
58348.873430946 5231: [entry] __monstartup(4004d0) depth: 0
58348.873433169 5231: [exit ] __monstartup(4004d0) depth: 0
58348.873439477 5231: [entry] __cxa_atexit(4004f0) depth: 0
58348.873440994 5231: [exit ] __cxa_atexit(4004f0) depth: 0
58348.873444506 5231: [entry] main(400512) depth: 0
58348.873444843 5231: [entry] a(4006b2) depth: 1
58348.873445107 5231: [entry] b(4006a0) depth: 2
58348.873445348 5231: [entry] c(400686) depth: 3
58348.873445830 5231: [entry] getpid(4004b0) depth: 4
58348.873447154 5231: [exit ] getpid(4004b0) depth: 4
58348.873448318 5231: [exit ] c(400686) depth: 3
58348.873448707 5231: [exit ] b(4006a0) depth: 2
58348.873448996 5231: [exit ] a(4006b2) depth: 1
58348.873449309 5231: [exit ] main(400512) depth: 0
""", sort='dump')
def __init__(self):
TestBase.__init__(self, 'forkexec', result="""
# Function Call Graph for 'main' (session: 327202376e209585)
=============== BACKTRACE ===============
backtrace #0: hit 1, time 5.824 us
[0] main (0x400530)
========== FUNCTION CALL GRAPH ==========
5.824 us : (1) main
5.411 us : (1) a
5.141 us : (1) b
4.670 us : (1) c
0.967 us : (1) getpid
# Function Call Graph for 'main' (session: f34056bd485963b3)
=============== BACKTRACE ===============
backtrace #0: hit 1, time 3.679 ms
[0] main (0x4005b0)
========== FUNCTION CALL GRAPH ==========
3.679 ms : (1) main
127.172 us : +-(1) fork
: |
3.527 ms : +-(1) waitpid
""")
def __init__(self):
TestBase.__init__(self, 'hello', """
# system information
# ==================
# program version : uftrace v0.8.1-133-g7f71
# recorded on : Mon Nov 27 09:40:31 2017
# cmdline : ../uftrace --no-pager -L.. record -d xxx t-hello \\"uftrace\\"
# cpu info : Intel(R) Core(TM) i7-3930K CPU @ 3.20GHz
# number of cpus : 12 / 12 (online / possible)
# memory info : 13.2 / 23.5 GB (free / total)
# system load : 3.25 / 3.17 / 3.11 (1 / 5 / 15 min)
# kernel version : Linux 4.13.11-1-ARCH
# hostname : sejong
# distro : "Arch Linux"
#
# process information
# ===================
# number of tasks : 1
# task list : 10217
# exe image : /home/namhyung/project/uftrace/tests/t-hello
# build id : 7fde527c74f398c5f48b5ec30173d2c17366dd90
# exit status : exited with code: 0
# elapsed time : 0.004278080 sec
# cpu time : 0.002 / 0.002 sec (sys / user)
# context switch : 1 / 0 (voluntary / involuntary)
# max rss : 3284 KB
# page fault : 0 / 197 (major / minor)
# disk iops : 0 / 16 (read / write)""")
def __init__(self):
TestBase.__init__(self, 'sleep', result="""
# DURATION TID FUNCTION
[18260] | main() {
2.088 ms [18260] | foo();
2.090 ms [18260] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'taskname', ldflags='-pthread', serial=True, result="""
{"traceEvents":[
{"ts":0,"ph":"M","pid":4694,"name":"process_name","args":{"name":"[4694] bar"}},
{"ts":0,"ph":"M","pid":4694,"name":"thread_name","args":{"name":"[4694] bar"}},
{"ts":13453314717.085,"ph":"B","pid":4694,"name":"main"},
{"ts":13453314717.245,"ph":"B","pid":4694,"name":"task_name1"},
{"ts":13453314717.814,"ph":"B","pid":4694,"name":"prctl"},
{"ts":0,"ph":"M","pid":4694,"name":"process_name","args":{"name":"[4694] foo"}},
{"ts":0,"ph":"M","pid":4694,"name":"thread_name","args":{"name":"[4694] foo"}},
{"ts":13453314720.072,"ph":"E","pid":4694,"name":"prctl"},
{"ts":13453314720.665,"ph":"E","pid":4694,"name":"task_name1"},
{"ts":13453314720.793,"ph":"B","pid":4694,"name":"task_name2"},
{"ts":13453314720.920,"ph":"B","pid":4694,"name":"pthread_self"},
{"ts":13453314721.080,"ph":"E","pid":4694,"name":"pthread_self"},
{"ts":13453314721.264,"ph":"B","pid":4694,"name":"pthread_setname_np"},
{"ts":0,"ph":"M","pid":4694,"name":"process_name","args":{"name":"[4694] bar"}},
{"ts":0,"ph":"M","pid":4694,"name":"thread_name","args":{"name":"[4694] bar"}},
{"ts":13453314722.478,"ph":"E","pid":4694,"name":"pthread_setname_np"},
{"ts":13453314722.631,"ph":"E","pid":4694,"name":"task_name2"},
{"ts":13453314722.695,"ph":"E","pid":4694,"name":"main"}
], "displayTimeUnit": "ns", "metadata": {
"command_line":"../uftrace --no-pager -L.. record -d xxx t-taskname",
"recorded_time":"Tue Jan 30 16:05:24 2018"
} }
""", sort='chrome')
def __init__(self):
TestBase.__init__(self, 'fork', """
uftrace file header: magic = 4674726163652100
uftrace file header: version = 4
uftrace file header: header size = 40
uftrace file header: endian = 1 (little)
uftrace file header: class = 2 (64 bit)
uftrace file header: features = 0x363 (PLTHOOK | TASK_SESSION | SYM_REL_ADDR | MAX_STACK | PERF_EVENT | AUTO_ARGS)
uftrace file header: info = 0x3bff
reading 5186.dat
58071.916834908 5186: [entry] main(400590) depth: 0
58071.916835853 5186: [entry] fork(400580) depth: 1
58071.917056572 5186: [exit ] fork(400580) depth: 1
58071.917091028 5186: [entry] wait(400570) depth: 1
58071.918038822 5186: [exit ] wait(400570) depth: 1
58071.918040938 5186: [entry] a(400774) depth: 1
58071.918041182 5186: [entry] b(400741) depth: 2
58071.918041482 5186: [entry] c(400706) depth: 3
58071.918042306 5186: [entry] getpid(400530) depth: 4
58071.918045615 5186: [exit ] getpid(400530) depth: 4
58071.918048103 5186: [exit ] c(400706) depth: 3
58071.918048457 5186: [exit ] b(400741) depth: 2
58071.918048760 5186: [exit ] a(400774) depth: 1
58071.918049117 5186: [exit ] main(400590) depth: 0
reading 5188.dat
""", sort='dump')
def __init__(self):
TestBase.__init__(
self,
"signal2",
"""
# DURATION TID FUNCTION
3.966 us [24050] | __monstartup();
0.342 us [24050] | __cxa_atexit();
[24050] | main() {
0.483 us [24050] | signal();
1.476 us [24050] | setitimer();
[24050] | foo() {
[24050] | bar() {
0.401 us [24050] | sighandler();
4.074 ms [24050] | } /* bar */
[24050] | bar() {
0.086 us [24050] | sighandler();
3.330 ms [24050] | } /* bar */
[24050] | bar() {
0.099 us [24050] | sighandler();
3.331 ms [24050] | } /* bar */
10.736 ms [24050] | } /* foo */
10.738 ms [24050] | } /* main */
""",
)
def __init__(self):
TestBase.__init__(self, 'allocfree', """
# DURATION TID FUNCTION
101.601 us [31924] | __monstartup();
2.047 us [31924] | __cxa_atexit();
[31924] | main() {
[31924] | alloc1() {
[31924] | alloc2() {
3.010 us [31924] | alloc3();
4.068 us [31924] | } /* alloc2 */
4.611 us [31924] | } /* alloc1 */
[31924] | free1() {
[31924] | free2() {
[31924] | free3() {
[31924] | free4() {
[31924] | free5() {
backtrace [31924] | /* [ 0] main */
backtrace [31924] | /* [ 1] free1 */
backtrace [31924] | /* [ 2] free2 */
backtrace [31924] | /* [ 3] free3 */
backtrace [31924] | /* [ 4] free4 */
backtrace [31924] | /* [ 5] free5 */
1.894 us [31924] | free();
2.921 us [31924] | } /* free5 */
3.504 us [31924] | } /* free4 */
4.059 us [31924] | } /* free3 */
4.588 us [31924] | } /* free2 */
5.177 us [31924] | } /* free1 */
11.175 us [31924] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'abc', """
main 1
main;a 1
main;a;b 1
main;a;b;c 1
""")
def __init__(self):
TestBase.__init__(self, 'abc', """
# DURATION TID FUNCTION
[28141] | a() {
1.915 us [28141] | b();
2.405 us [28141] | } /* a */
""", sort='simple')
def __init__(self):
TestBase.__init__(
self,
"thread-exec",
"""
# DURATION TID FUNCTION
[23290] | main() {
29.452 us [23290] | pthread_create();
[23292] | thread_func() {
[23292] | execl() {
[23290] | main() {
[23290] | a() {
[23290] | b() {
[23290] | c() {
0.379 us [23290] | getpid();
0.772 us [23290] | } /* c */
1.159 us [23290] | } /* b */
1.289 us [23290] | } /* a */
1.461 us [23290] | } /* main */
uftrace stopped tracing with remaining functions
================================================
task: 23290
[0] main
""",
)
def __init__(self):
TestBase.__init__(self, 'hello', """
# DURATION TID FUNCTION
62.202 us [28141] | __cxa_atexit();
[28141] | main() {
2.405 us [28141] | printf("Hello %s\\n", "01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234...");
3.005 us [28141] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'exp-char', result="""
# DURATION TID FUNCTION
[18279] | main() {
0.371 ms [18279] | foo('f', 'o', 'o');
0.923 ms [18279] | bar('\\x00', 'B', 97, 0x72);
3.281 ms [18279] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'malloc-hook', ldflags='-ldl', result="""
# DURATION TID FUNCTION
[ 4408] | main() {
0.470 us [ 4408] | malloc();
0.390 us [ 4408] | free();
1.512 us [ 4408] | } /* main */
""")
def build(self, name, cflags='', ldflags=''):
if TestBase.build_libabc(self, '', '') != 0:
return TestBase.TEST_BUILD_FAIL
if TestBase.build_libfoo(self, 'foo', '', '') != 0:
return TestBase.TEST_BUILD_FAIL
return TestBase.build_libmain(self, name, 's-nest-libcall.c',
['libabc_test_lib.so', 'libfoo.so'],
cflags, ldflags)
def __init__(self):
TestBase.__init__(self, 'namespace', lang="C++", result="""
# DURATION TID FUNCTION
66.323 us [ 1845] | ns::ns1::foo::foo();
[ 1845] | ns::ns1::foo::bar() {
[ 1845] | ns::ns1::foo::bar1() {
[ 1845] | ns::ns1::foo::bar2() {
[ 1845] | ns::ns1::foo::bar3() {
1.759 us [ 1845] | malloc();
2.656 us [ 1845] | } /* ns::ns1::foo::bar3 */
2.996 us [ 1845] | } /* ns::ns1::foo::bar2 */
3.346 us [ 1845] | } /* ns::ns1::foo::bar1 */
1.367 us [ 1845] | free();
5.499 us [ 1845] | } /* ns::ns1::foo::bar */
[ 1845] | ns::ns2::foo::bar2() {
[ 1845] | ns::ns2::foo::bar3() {
0.450 us [ 1845] | malloc();
0.930 us [ 1845] | } /* ns::ns2::foo::bar3 */
1.393 us [ 1845] | } /* ns::ns2::foo::bar2 */
""")
def pre(self):
if not TestBase.check_perf_paranoid(self):
return TestBase.TEST_SKIP
recv_cmd = '%s recv -d %s' % (TestBase.uftrace_cmd, TDIR)
self.recv_p = sp.Popen(recv_cmd.split())
options = '-H %s -E %s' % ('localhost', 'linux:schedule')
record_cmd = '%s record %s %s' % (TestBase.uftrace_cmd, options, 't-' + self.name)
sp.call(record_cmd.split())
return TestBase.TEST_SUCCESS
def __init__(self):
TestBase.__init__(self,
'chcpu',
serial=True,
result="""
# DURATION TID FUNCTION
[ 19611] | main() {
[ 19611] | /* watch:cpu (cpu=6) */
32.050 us [ 19611] | sysconf();
1.105 us [ 19611] | sched_getcpu();
[ 19611] | sched_setaffinity() {
28.284 us [ 19611] | /* linux:schedule */
[ 19611] | /* watch:cpu (cpu=0) */
56.223 us [ 19611] | } /* sched_setaffinity */
[ 19611] | sched_setaffinity() {
16.719 us [ 19611] | /* linux:schedule */
[ 19611] | /* watch:cpu (cpu=6) */
37.281 us [ 19611] | } /* sched_setaffinity */
142.912 us [ 19611] | } /* main */
""")
def __init__(self):
TestBase.__init__(self,
'namespace',
lang="C++",
result="""
# DURATION TID FUNCTION
4.843 us [29826] | operator new();
1.846 us [29826] | ns::ns1::foo::foo();
[29826] | ns::ns1::foo::bar() {
[29826] | ns::ns1::foo::bar1() {
[29826] | ns::ns1::foo::bar2() {
[29826] | ns::ns1::foo::bar3() {
0.597 us [29826] | operator new();
0.317 us [29826] | ns::ns2::foo::foo();
[29826] | ns::ns2::foo::bar() {
[29826] | ns::ns2::foo::bar1() {
[29826] | ns::ns2::foo::bar2() {
[29826] | ns::ns2::foo::bar3() {
""",
sort='simple')
def __init__(self):
TestBase.__init__(
self, 'sleep', """
# DURATION TID FUNCTION
[ 395] | main() {
[ 395] | foo() {
[ 395] | mem_alloc() {
1.328 us [ 395] | malloc();
1.924 us [ 395] | } /* mem_alloc */
[ 395] | bar() {
[ 395] | usleep() {
2.088 ms [ 395] | /* linux:schedule */
2.105 ms [ 395] | } /* usleep */
2.109 ms [ 395] | } /* bar */
[ 395] | mem_free() {
3.137 us [ 395] | free();
3.783 us [ 395] | } /* mem_free */
2.120 ms [ 395] | } /* foo */
2.121 ms [ 395] | } /* main */
""")
def __init__(self):
TestBase.__init__(self,
'namespace',
lang="C++",
result="""
# DURATION TID FUNCTION
53.511 us [ 6624] | ns::ns1::foo::foo();
[ 6624] | ns::ns1::foo::bar2() {
[ 6624] | ns::ns1::foo::bar3() {
1.607 us [ 6624] | malloc();
2.520 us [ 6624] | } /* ns::ns1::foo::bar3 */
2.982 us [ 6624] | } /* ns::ns1::foo::bar2 */
0.174 us [ 6624] | ns::ns2::foo::foo();
[ 6624] | ns::ns2::foo::bar2() {
[ 6624] | ns::ns2::foo::bar3() {
0.365 us [ 6624] | malloc();
0.834 us [ 6624] | } /* ns::ns2::foo::bar3 */
1.200 us [ 6624] | } /* ns::ns2::foo::bar2 */
""",
sort='simple')
def __init__(self):
TestBase.__init__(self, 'demangle', lang='C++', result="""
# DURATION TID FUNCTION
[31433] | ABC::foo() {
[31433] | __static_initialization_and_destruction_0() {
96.867 us [31433] | std::ios_base::Init::Init();
1.403 us [31433] | __cxa_atexit();
101.554 us [31433] | } /* __static_initialization_and_destruction_0 */
171.419 us [31433] | } /* ABC::foo */
[31433] | main() {
2.540 us [31433] | operator new();
0.146 us [31433] | ABC::ABC();
[31433] | ABC::foo() {
[31433] | ABC::bar() {
0.157 us [31433] | ABC::baz();
0.714 us [31433] | } /* ABC::bar */
1.323 us [31433] | } /* ABC::foo */
5.623 us [31433] | } /* main */
9.223 us [31433] | std::ios_base::Init::~Init();
""")
def __init__(self):
TestBase.__init__(self,
'sort',
serial=True,
result="""
# Function Call Graph for 'main' (session: 54047ea45c46ad91)
=============== BACKTRACE ===============
backtrace #0: hit 1, time 10.329 ms
[0] main (0x4004e0)
========== FUNCTION CALL GRAPH ==========
10.329 ms : (1) main
53.100 us : +-(2) foo
50.745 us : | (6) loop
: |
10.150 ms : +-(1) bar
10.102 ms : (1) usleep
10.088 ms : (1) linux:schedule
""",
sort='graph')
def __init__(self):
TestBase.__init__(self, 'namespace', """
# DURATION TID FUNCTION
[ 6565] | main() {
2.234 us [ 6565] | operator new();
0.897 us [ 6565] | ns::ns1::foo::foo();
[ 6565] | ns::ns1::foo::bar() {
[ 6565] | ns::ns1::foo::bar1() {
[ 6565] | ns::ns1::foo::bar2() {
[ 6565] | ns::ns1::foo::bar3() {
uftrace stopped tracing with remaining functions
================================================
task: 6565
[4] ns::ns1::foo::bar3
[3] ns::ns1::foo::bar2
[2] ns::ns1::foo::bar1
[1] ns::ns1::foo::bar
[0] main
""", lang='C++')
def __init__(self):
TestBase.__init__(self, 'fork', """
# DURATION TID FUNCTION
[ 1661] | main() {
[ 1661] | fork() {
5.135 us [ 1661] | sys_writev();
32.391 us [ 1661] | sys_clone();
130.930 us [ 1661] | } /* fork */
[ 1661] | wait() {
7.074 us [ 1661] | sys_wait4();
691.873 us [ 1661] | } /* wait */
[ 1661] | a() {
[ 1661] | b() {
[ 1661] | c() {
4.234 us [ 1661] | getpid();
5.680 us [ 1661] | } /* c */
6.094 us [ 1661] | } /* b */
6.602 us [ 1661] | } /* a */
849.948 us [ 1661] | } /* main */
""")
def fixup(self, cflags, result):
machine = TestBase.get_elf_machine(self)
if machine == 'arm' or machine == 'aarch64':
return result.replace(
'memset', """memset();
1.440 us [12703] | memcpy""")
return result.replace(
"""return_large() {
1.440 us [12703] | memset();
2.533 us [12703] | } /* return_large */""", 'return_large();')
def __init__(self):
TestBase.__init__(self, 'sort', result="""
#
# function graph for 'main'
#
backtrace
================================
backtrace #0: hit 1, time 10.293 ms
[0] main (0x4004f0)
calling functions
================================
10.293 ms : (1) main
46.626 us : +-(2) foo
44.360 us : | (6) loop
: |
10.138 ms : +-(1) bar
10.100 ms : (1) usleep
""")
def pre(self):
if not TestBase.check_perf_paranoid(self):
return TestBase.TEST_SKIP
uftrace = TestBase.uftrace_cmd
argument = '-d %s -E linux:task-name' % TDIR
program = 't-' + self.name
record_cmd = '%s record %s %s' % (uftrace, argument, program)
sp.call(record_cmd.split())
return TestBase.TEST_SUCCESS
def __init__(self):
TestBase.__init__(self,
'sort',
result="""
# Function Call Graph for 'main' (session: de27777d0a966d5a)
=============== BACKTRACE ===============
backtrace #0: hit 1, time 13.120 ms
[0] main (0x56366ebab7fc)
========== FUNCTION CALL GRAPH ==========
# TOTAL TIME FUNCTION [SOURCE]
13.120 ms : (1) main
694.492 us : +-(2) foo [/home/eslee/soft/uftrace/tests/s-sort.c:10]
688.800 us : | (6) loop [/home/eslee/soft/uftrace/tests/s-sort.c:3]
: |
10.748 ms : +-(1) bar [/home/eslee/soft/uftrace/tests/s-sort.c:17]
10.183 ms : (1) usleep
""",
sort='graph',
cflags='-g')
def __init__(self):
TestBase.__init__(self,
'sleep',
"""
{"traceEvents":[
{"ts":0,"ph":"M","pid":32537,"name":"process_name","args":{"name":"[32537] t-sleep"}},
{"ts":0,"ph":"M","pid":32537,"name":"thread_name","args":{"name":"[32537] t-sleep"}},
{"ts":56466448731,"ph":"B","pid":32537,"name":"main"},
{"ts":56466448731,"ph":"B","pid":32537,"name":"foo"},
{"ts":56466448742,"ph":"B","pid":32537,"name":"bar"},
{"ts":56466448743,"ph":"B","pid":32537,"name":"usleep"},
{"ts":56466450823,"ph":"E","pid":32537,"name":"usleep"},
{"ts":56466450827,"ph":"E","pid":32537,"name":"bar"},
{"ts":56466450834,"ph":"E","pid":32537,"name":"foo"},
{"ts":56466450835,"ph":"E","pid":32537,"name":"main"}
], "metadata": {
"command_line":"uftrace record -d xxx t-sleep ",
"recorded_time":"Mon Oct 3 22:45:57 2016"
} }
""",
sort='chrome')
def __init__(self):
TestBase.__init__(self, 'forkexec', result="""
# Function Call Graph for 't-abc' (session: 327202376e209585)
========== FUNCTION CALL GRAPH ==========
5.824 us : (1) t-abc
5.824 us : (1) main
5.411 us : (1) a
5.141 us : (1) b
4.670 us : (1) c
0.967 us : (1) getpid
# Function Call Graph for 't-forkexec' (session: f34056bd485963b3)
========== FUNCTION CALL GRAPH ==========
3.679 ms : (1) t-forkexec
3.679 ms : (1) main
127.172 us : +-(1) fork
: |
3.527 ms : +-(1) waitpid
: |
: +-(1) execl
""", sort='graph')
def __init__(self):
TestBase.__init__(self, 'arg', """
# DURATION TID FUNCTION
[13476] | main() {
[13476] | foo() {
[13476] | bar() {
0.567 us [13476] | strcmp();
1.779 us [13476] | } /* bar */
[13476] | bar() {
0.133 us [13476] | strcmp();
0.489 us [13476] | } /* bar */
[13476] | bar() {
0.081 us [13476] | strcmp();
0.381 us [13476] | } /* bar */
3.515 us [13476] | } /* foo */
2.235 us [13476] | many(8, 13, 21, 34, 55, 89, 144);
[13476] | pass() {
0.130 us [13476] | check();
0.427 us [13476] | } /* pass */
18.161 us [13476] | } /* main */
""")
def __init__(self):
TestBase.__init__(self, 'namespace', lang="C++", result="""
# DURATION TID FUNCTION
[22757] | main() {
2.554 us [22757] | operator new(unsigned long);
1.040 us [22757] | ns::ns1::foo::foo(int);
[22757] | ns::ns1::foo::bar() {
[22757] | ns::ns1::foo::bar1() {
[22757] | ns::ns1::foo::bar2() {
[22757] | ns::ns1::foo::bar3() {
1.360 us [22757] | malloc();
1.903 us [22757] | } /* ns::ns1::foo::bar3() */
2.276 us [22757] | } /* ns::ns1::foo::bar2() */
2.629 us [22757] | } /* ns::ns1::foo::bar1() */
1.266 us [22757] | free();
4.629 us [22757] | } /* ns::ns1::foo::bar() */
1.927 us [22757] | operator delete(void*);
0.283 us [22757] | operator new(unsigned long);
0.223 us [22757] | operator delete(void*);
76.629 us [22757] | } /* main */
""")
def __init__(self):
TestBase.__init__(self,
'abc',
"""
{"traceEvents":[
{"ts":0,"ph":"M","pid":5231,"name":"process_name","args":{"name":"t-abc"}},
{"ts":0,"ph":"M","pid":5231,"name":"thread_name","args":{"name":"t-abc"}},
{"ts":58348873444,"ph":"B","pid":5231,"name":"main"},
{"ts":58348873444,"ph":"B","pid":5231,"name":"a"},
{"ts":58348873445,"ph":"B","pid":5231,"name":"b"},
{"ts":58348873445,"ph":"B","pid":5231,"name":"c"},
{"ts":58348873448,"ph":"E","pid":5231,"name":"c"},
{"ts":58348873448,"ph":"E","pid":5231,"name":"b"},
{"ts":58348873448,"ph":"E","pid":5231,"name":"a"},
{"ts":58348873449,"ph":"E","pid":5231,"name":"main"}
], "metadata": {
"command_line":"uftrace record -d abc.data t-abc ",
"recorded_time":"Sat Oct 1 18:19:06 2016"
} }
""",
sort='chrome')
def setup(self):
self.option = '-A "float_add@fparg1/32,fparg2/32" -R "float_add@retval/f32" '
self.option += '-A "float_sub@fparg1/32,fparg2" -R "float_sub@retval/f32" '
self.option += '-A "float_mul@fparg1/64,fparg2/32" -R "float_mul@retval/f64" '
self.option += '-A "float_div@fparg1,fparg2" -R "float_div@retval/f"'
if TestBase.is_32bit(self):
# argument count follows the size of type
self.option = self.option.replace('float_mul@fparg1/64,fparg2/32',
'float_mul@fparg1/64,fparg3/32')
self.option = self.option.replace('float_div@fparg1,fparg2',
'float_div@fparg1/64,fparg3/64')
def __init__(self):
TestBase.__init__(self,
'openclose',
serial=True,
result="""
# DURATION TID FUNCTION
1.540 us [27711] | __monstartup();
1.089 us [27711] | __cxa_atexit();
[27711] | main() {
[27711] | fopen() {
[27711] | sys_open() {
12.732 us [27711] | do_sys_open();
14.039 us [27711] | } /* sys_open */
17.193 us [27711] | } /* fopen */
[27711] | fclose() {
[27711] | sys_close() {
0.591 us [27711] | __close_fd();
1.429 us [27711] | } /* sys_close */
8.028 us [27711] | } /* fclose */
26.938 us [27711] | } /* main */
""")
def __init__(self):
TestBase.__init__(self,
'fork',
result="""
#
# function graph for 'a' (session: de8436a173b22b1c)
#
backtrace
================================
backtrace #0: hit 1, time 6.602 us
[0] main (0x4005c5)
[1] a (0x400782)
calling functions
================================
6.602 us : (1) a
6.094 us : (1) b
5.680 us : (1) c
4.234 us : (1) getpid
""")
def __init__(self):
TestBase.__init__(self, 'forkexec', """
# DURATION TID FUNCTION
[ 9874] | main() {
142.145 us [ 9874] | fork();
[ 9874] | waitpid() {
473.298 us [ 9875] | } /* fork */
[ 9875] | execl() {
[ 9875] | main() {
[ 9875] | a() {
[ 9875] | b() {
[ 9875] | c() {
0.976 us [ 9875] | getpid();
1.992 us [ 9875] | } /* c */
2.828 us [ 9875] | } /* b */
3.658 us [ 9875] | } /* a */
7.713 us [ 9875] | } /* main */
2.515 ms [ 9874] | } /* waitpid */
2.708 ms [ 9874] | } /* main */
""")
def __init__(self):
TestBase.__init__(self,
'sleep',
result="""
#
# function graph for 'main' (session: 0bc5da823389c319)
#
backtrace
================================
backtrace #0: hit 1, time 2.103 ms
[0] main (0x400550)
calling functions
================================
2.103 ms : (1) main
2.102 ms : (1) foo
2.084 ms : (1) bar
2.080 ms : (1) usleep
""")
def __init__(self):
TestBase.__init__(self,
'taskname',
ldflags='-pthread',
result="""
# TASK NAME FUNCTION
taskname | main() {
taskname | task_name1() {
taskname | prctl() {
foo | /* linux:task-name (name=foo) */
foo | } /* prctl */
foo | } /* task_name1 */
foo | task_name2() {
foo | pthread_self();
foo | pthread_setname_np() {
bar | /* linux:task-name (name=bar) */
bar | } /* pthread_setname_np */
bar | } /* task_name2 */
bar | } /* main */
""",
sort='simple')
def __init__(self):
TestBase.__init__(self, 'namespace', lang="C++", result="""
# DURATION TID FUNCTION
[ 3357] | main() {
2.874 us [ 3357] | operator new();
3.115 us [ 3357] | operator delete();
0.456 us [ 3357] | operator new();
0.386 us [ 3357] | ns::ns2::foo::foo();
[ 3357] | ns::ns2::foo::bar() {
[ 3357] | ns::ns2::foo::bar1() {
[ 3357] | ns::ns2::foo::bar2() {
[ 3357] | ns::ns2::foo::bar3() {
0.346 us [ 3357] | malloc();
0.732 us [ 3357] | } /* ns::ns2::foo::bar3 */
0.847 us [ 3357] | } /* ns::ns2::foo::bar2 */
1.339 us [ 3357] | } /* ns::ns2::foo::bar1 */
0.411 us [ 3357] | free();
2.072 us [ 3357] | } /* ns::ns2::foo::bar */
0.311 us [ 3357] | operator delete();
105.160 us [ 3357] | } /* main */
""")
def runcmd(self):
argopt = '-A "float_add@fparg1/32,fparg2/32" -R "float_add@retval/f32" '
argopt += '-A "float_sub@fparg1/32,fparg2" -R "float_sub@retval/f32" '
argopt += '-A "float_mul@fparg1/64,fparg2/32" -R "float_mul@retval/f64" '
argopt += '-A "float_div@fparg1,fparg2" -R "float_div@retval/f"'
if TestBase.is_32bit(self):
# argument count follows the size of type
argopt = argopt.replace('float_mul@fparg1/64,fparg2/32',
'float_mul@fparg1/64,fparg3/32')
return '%s %s %s' % (TestBase.uftrace_cmd, argopt, 't-' + self.name)
def __init__(self):
TestBase.__init__(self,
'abc',
"""
uftrace file header: magic = 4674726163652100
uftrace file header: version = 4
uftrace file header: header size = 40
uftrace file header: endian = 1 (little)
uftrace file header: class = 2 (64 bit)
uftrace file header: features = 0x63 (PLTHOOK | TASK_SESSION | SYM_REL_ADDR | MAX_STACK)
uftrace file header: info = 0xbff
reading 5231.dat
58348.873444506 5231: [entry] main(400512) depth: 0
58348.873444843 5231: [entry] a(4006b2) depth: 1
58348.873445107 5231: [entry] b(4006a0) depth: 2
58348.873448707 5231: [exit ] b(4006a0) depth: 2
58348.873448996 5231: [exit ] a(4006b2) depth: 1
58348.873449309 5231: [exit ] main(400512) depth: 0
""",
sort='dump')
def __init__(self):
TestBase.__init__(self, 'sleep', """
# DURATION TID FUNCTION
[24464] | main() {
[24464] | foo() {
[24464] | mem_alloc() {
4.976 us [24464] | malloc();
15.040 us [24464] | } /* mem_alloc */
[24464] | bar() {
[24464] | usleep() {
[24464] | /* sched:sched_switch (prev_comm=t-sleep ...) */
[24464] | /* sched:sched_switch (prev_comm=swapper/0 ...) */
2.176 ms [24464] | } /* usleep */
2.183 ms [24464] | } /* bar */
[24464] | mem_free() {
12.992 us [24464] | free();
15.400 us [24464] | } /* mem_free */
2.215 ms [24464] | } /* foo */
2.216 ms [24464] | } /* main */
""")
def __init__(self):
TestBase.__init__(self,
'abc',
result="""
#
# function graph for 'getpid'
#
backtrace
================================
backtrace #0: hit 1, time 1.622 us
[0] main (0x4004f0)
[1] a (0x40069f)
[2] b (0x400674)
[3] c (0x400636)
[4] getpid (0x400490)
calling functions
================================
1.622 us : (1) getpid
""")
