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, '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, '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, '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, '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, '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 __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, 'abc', """ # DURATION TID FUNCTION [28141] | a() { 1.915 us [28141] | b(); 2.405 us [28141] | } /* a */ """, sort='simple')
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 __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, 'abc', """ main 1 main;a 1 main;a;b 1 main;a;b;c 1 """)
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, '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, 'abc', """ a enter b enter b exit a exit """)
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, "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, '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, '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, '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, '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, '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, "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, '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, '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, 'malloc', """ # DURATION TID FUNCTION [16726] | main() { 0.426 us [16726] | malloc(); 0.397 us [16726] | free(); 3.074 us [16726] | } /* 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 __init__(self): TestBase.__init__(self, 'dynamic', """ # DURATION TID FUNCTION [ 63876] | main() { 0.739 us [ 63876] | foo(); 0.833 us [ 63876] | bar(); 1.903 us [ 63876] | } /* main */ """)
def __init__(self): TestBase.__init__(self, 'openclose', """ # DURATION TID FUNCTION [15973] | main() { 5.903 us [15973] | fopen(); 4.374 us [15973] | fclose(); 15.262 us [15973] | } /* 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, 'diff', """ # # uftrace diff # [0] base: xxx (from uftrace record -d xxx -F main tests/t-diff 0 ) # [1] diff: yyy (from uftrace record -d yyy -F main tests/t-diff 1 ) # Total time Self time Calls Function ========== ========== ========== ==================== -5.40% -5.40% +0 atoi +999.99% +875.84% +0 bar +999.99% +498.85% +0 foo +999.99% +10.47% +0 main +999.99% +999.99% +3 usleep """)
def __init__(self): TestBase.__init__( self, 'abc', """ # DURATION TID FUNCTION 62.202 us [28141] | __cxa_atexit(); [28141] | main() { [28141] | a() { [28141] | b() { [28141] | c() { 0.753 us [28141] | getpid(); 1.430 us [28141] | } /* c */ 1.915 us [28141] | } /* b */ 2.405 us [28141] | } /* a */ 3.005 us [28141] | } /* main */ """) self.gen_port()
def __init__(self): TestBase.__init__( self, 'abc', """ # DURATION TID FUNCTION [32766] | main() { [32766] | a() { [32766] | b() { [32766] | /* read:page-fault (major=0, minor=188) */ [32766] | c() { 0.609 us [32766] | getpid(); 13.722 us [32766] | } /* c */ [32766] | /* diff:page-fault (major=+0, minor=+1) */ 24.950 us [32766] | } /* b */ 25.564 us [32766] | } /* a */ 26.963 us [32766] | } /* main */ """)
def __init__(self): TestBase.__init__(self, 'dwarf1', """ # DURATION TID FUNCTION [ 29831] | main() { 0.495 us [ 29831] | foo(-1, 32768) = 32767; [ 29831] | bar("string argument", 'c', 0.000010, &null) { 0.660 us [ 29831] | null("NULL"); 442.163 us [ 29831] | } = -1.000000; /* bar */ [ 29831] | baz(ONE) { 0.323 us [ 29831] | foo(1, -1) = 0; 1.291 us [ 29831] | } /* baz */ 449.927 us [ 29831] | } = 0; /* main */ """, cflags='-g')
def __init__(self): TestBase.__init__( self, 'abc', """ # # uftrace diff # [0] base: xxx (from uftrace record -d xxx tests/t-abc ) # [1] diff: yyy (from uftrace record -d yyy tests/t-abc ) # Total time (diff) Self time (diff) Nr. called (diff) Function ================================ ================================ ================================ ==================================== 6.974 us 6.268 us -10.12% 0.560 us 0.511 us -8.75% 1 1 +0 main 6.414 us 5.757 us -10.24% 0.489 us 0.372 us -23.93% 1 1 +0 a 5.925 us 5.385 us -9.11% 0.786 us 0.554 us -29.52% 1 1 +0 b 5.139 us 4.831 us -5.99% 3.517 us 3.137 us -10.80% 1 1 +0 c 1.622 us 1.694 us +4.44% 1.622 us 1.694 us +4.44% 1 1 +0 getpid """)
def __init__(self): TestBase.__init__( self, 'abc', """ # DURATION TID FUNCTION [32417] | main() { [32417] | a() { [32417] | b() { [32417] | /* read:proc/statm (size=6812KB, rss=780KB, shared=716KB) */ [32417] | c() { 0.479 us [32417] | getpid(); 3.014 us [32417] | } /* c */ [32417] | /* diff:proc/statm (size=+0KB, rss=+0KB, shared=+0KB) */ 16.914 us [32417] | } /* b */ 17.083 us [32417] | } /* a */ 17.873 us [32417] | } /* main */ """)
def __init__(self): TestBase.__init__(self, 'sleep', result=""" # Function Call Graph for 'main' (session: b78e9c27042adaa7) =============== BACKTRACE =============== backtrace #0: hit 1, time 2.109 ms [0] main (0x400570) ========== FUNCTION CALL GRAPH ========== 2.109 ms : (1) main 2.109 ms : (1) foo 2.098 ms : (1) bar 2.096 ms : (1) usleep """, sort='graph')
def __init__(self): TestBase.__init__( self, 'abc', """ # DURATION TID FUNCTION [32417] | main() { [32417] | a() { [32417] | b() { [32417] | /* read:pmu-cache (refers=2105, misses=271) */ [32417] | c() { 0.479 us [32417] | getpid(); 3.014 us [32417] | } /* c */ [32417] | /* diff:pmu-cache (refers=+23, misses=+5, hit=78%) */ 16.914 us [32417] | } /* b */ 17.083 us [32417] | } /* a */ 17.873 us [32417] | } /* main */ """)
def __init__(self): TestBase.__init__(self, 'abc', """ {"traceEvents":[ {"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 __init__(self): TestBase.__init__( self, 'abc', """ # DURATION TID FUNCTION [32417] | main() { [32417] | a() { [32417] | b() { [32417] | /* read:pmu-branch (branch=15482, misses=1192) */ [32417] | c() { 0.479 us [32417] | getpid(); 3.014 us [32417] | } /* c */ [32417] | /* diff:pmu-branch (branch=+785, misses=+71, predict=90%) */ 16.914 us [32417] | } /* b */ 17.083 us [32417] | } /* a */ 17.873 us [32417] | } /* main */ """)
def __init__(self): TestBase.__init__( self, 'diff', """ # # uftrace diff # [0] base: xxx (from uftrace record -d yyy -F main tests/t-diff 1 ) # [1] diff: yyy (from uftrace record -d xxx -F main tests/t-diff 0 ) # Total time (diff) Self time (diff) Calls (diff) Function =================================== =================================== ================================ ================================================ 1.075 us 1.048 us -0.027 us 1.075 us 1.048 us -0.027 us 1 1 +0 atoi 158.971 us 0.118 us -158.853 us 1.437 us 0.118 us -1.319 us 1 1 +0 bar 1.235 ms 0.645 us -1.235 ms 3.276 us 0.527 us -2.749 us 1 1 +0 foo 1.309 ms 3.975 us -1.305 ms 2.601 us 2.282 us -0.319 us 1 1 +0 main 1.300 ms - -1.300 ms 1.300 ms - -1.300 ms 3 0 -3 usleep """)
def __init__(self): TestBase.__init__(self, 'sleep', result=""" # DURATION TID FUNCTION [13256] | main() { [13256] | foo() { [13256] | mem_alloc() { 1.000 us [13256] | malloc(); 1.769 us [13256] | } /* mem_alloc */ [13256] | bar() { 2.073 ms [13256] | usleep(); 2.075 ms [13256] | } /* bar */ 2.084 ms [13256] | } /* foo */ 2.085 ms [13256] | } /* main */ """)
def __init__(self): TestBase.__init__( self, 'sleep', """ # DURATION TID FUNCTION [18219] | main() { [18219] | foo() { [18219] | /* read:proc/statm (size=6812KB, rss=784KB, shared=716KB) */ [18219] | bar() { [18219] | /* read:proc/statm (size=6812KB, rss=784KB, shared=716KB) */ 2.093 ms [18219] | usleep(); [18219] | /* diff:proc/statm (size=+0KB, rss=+0KB, shared=+0KB) */ 2.095 ms [18219] | } /* bar */ [18219] | /* diff:proc/statm (size=+0KB, rss=+0KB, shared=+0KB) */ 2.106 ms [18219] | } /* foo */ 2.107 ms [18219] | } /* main */ """)
def __init__(self): TestBase.__init__(self, 'sort', 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, 'abc', """ # DURATION TID FUNCTION 0.508 us [ 772] | __monstartup(); 0.425 us [ 772] | __cxa_atexit(); [ 772] | main() { [ 772] | a() { [ 772] | b() { [ 772] | c() { 0.419 us [ 772] | getpid(); 0.844 us [ 772] | } 1.037 us [ 772] | } 1.188 us [ 772] | } 1.378 us [ 772] | } """)
def __init__(self): TestBase.__init__( self, 'abc', """ # DURATION TID FUNCTION [32417] | main() { [32417] | a() { [32417] | b() { [32417] | /* read:pmu-cycle (cycle=133314, instructions=74485) */ [32417] | c() { 0.479 us [32417] | getpid(); 3.014 us [32417] | } /* c */ [32417] | /* diff:pmu-cycle (cycle=+5014, instructions=+3514, IPC=0.70) */ 16.914 us [32417] | } /* b */ 17.083 us [32417] | } /* a */ 17.873 us [32417] | } /* main */ """)
def __init__(self): TestBase.__init__( self, 'openclose', """ # DURATION TID FUNCTION 1.088 us [18343] | __monstartup(); 0.640 us [18343] | __cxa_atexit(); [18343] | main() { [18343] | fopen() { 86.790 us [18343] | sys_open(); 89.018 us [18343] | } /* fopen */ [18343] | fclose() { 10.781 us [18343] | sys_close(); 37.325 us [18343] | } /* fclose */ 128.387 us [18343] | } /* main */ """) self.gen_port()
def __init__(self): TestBase.__init__(self, 'sleep', result=""" # DURATION TID FUNCTION [16873] | main() { [16873] | foo() { [16873] | mem_alloc() { 1.675 us [16873] | malloc(); 6.867 us [16873] | } /* mem_alloc */ [16873] | bar() { 2.068 ms [16873] | usleep(); 2.071 ms [16873] | } /* bar */ 2.085 ms [16873] | } /* foo */ 2.086 ms [16873] | } /* main */ """)
def __init__(self): TestBase.__init__(self, 'sort', """ # Function Call Graph for 'main' (session: 67af3e650b051216) =============== BACKTRACE =============== backtrace #0: hit 1, time 10.148 ms [0] main (0x560e956bd610) ========== FUNCTION CALL GRAPH ========== # TOTAL TIME SELF TIME ADDRESS FUNCTION 10.148 ms 37.889 us 560e956bd610 : (1) main 15.991 us 0.765 us 560e956bd7ce : +-(2) foo 15.226 us 15.226 us 560e956bd7a0 : | (6) loop : | 10.094 ms 13.365 us 560e956bd802 : +-(1) bar 10.081 ms 10.081 ms 560e956bd608 : (1) usleep """, sort='graph')
def __init__(self): TestBase.__init__( self, 'openclose', """ # DURATION TID FUNCTION 1.088 us [18343] | __monstartup(); 0.640 us [18343] | __cxa_atexit(); [18343] | main() { [18343] | open() { 86.790 us [18343] | sys_open(); 89.018 us [18343] | } /* open */ [18343] | close() { 10.781 us [18343] | sys_close(); 21.980 us [18343] | exit_to_usermode_loop(); 37.325 us [18343] | } /* close */ 128.387 us [18343] | } /* main */ """)
def __init__(self): TestBase.__init__( self, 'diff', """ # # uftrace diff # [0] base: xxx (from uftrace record -d xxx -F main tests/t-diff 0 ) # [1] diff: yyy (from uftrace record -d yyy -F main tests/t-diff 1 ) # Total time Self time Calls Function =========== =========== =========== ==================== +0.027 us +0.027 us +0 atoi +158.853 us +1.319 us +0 bar +1.235 ms +2.749 us +0 foo +1.305 ms +0.319 us +0 main +1.300 ms +1.300 ms +3 usleep """)
def __init__(self): TestBase.__init__(self, 'sort', """ Total time Self time Calls Function ========== ========== ========== ==================================== 1.152 ms 71.683 us 1 main 1.080 ms 1.813 us 1 bar 1.078 ms 2.892 us 1 usleep 1.075 ms 1.075 ms 1 linux:schedule 70.176 us 70.176 us 1 __monstartup # ignore this 37.525 us 1.137 us 2 foo 36.388 us 36.388 us 6 loop 1.200 us 1.200 us 1 __cxa_atexit # and this too """, sort='report')
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, 'namespace', lang="C++", result=""" # DURATION TID FUNCTION [12683] | ns::ns2::foo::bar() { [12683] | ns::ns2::foo::bar1() { [12683] | ns::ns2::foo::bar2() { [12683] | ns::ns2::foo::bar3() { 1.067 us [12683] | malloc(); 2.390 us [12683] | } /* ns::ns2::foo::bar3 */ 3.197 us [12683] | } /* ns::ns2::foo::bar2 */ 4.177 us [12683] | } /* ns::ns2::foo::bar1 */ 0.695 us [12683] | free(); 105.025 us [12683] | } /* ns::ns2::foo::bar */ 0.602 us [12683] | operator delete(); [12683] | } /* main */ """)
def __init__(self): TestBase.__init__(self, 'allocfree', """ # DURATION TID FUNCTION backtrace [ 4629] | /* [ 0] main */ backtrace [ 4629] | /* [ 1] alloc1 */ backtrace [ 4629] | /* [ 2] alloc2 */ backtrace [ 4629] | /* [ 3] alloc3 */ [ 4629] | alloc4() { [ 4629] | alloc5() { 2.020 us [ 4629] | malloc(); 4.334 us [ 4629] | } /* alloc5 */ 4.671 us [ 4629] | } /* alloc4 */ """, sort='simple')
def __init__(self): TestBase.__init__(self, 'sleep', serial=True, result=""" # DURATION TID FUNCTION [ 395] | main() { [ 395] | foo() { [ 395] | bar() { [ 395] | usleep() { 2.088 ms [ 395] | /* linux:schedule */ 2.105 ms [ 395] | } /* usleep */ 2.109 ms [ 395] | } /* bar */ 2.120 ms [ 395] | } /* foo */ 2.121 ms [ 395] | } /* main */ """)
def __init__(self): TestBase.__init__( self, 'fork', """ # DURATION TID FUNCTION [ 1661] | main() { 130.930 us [ 1661] | fork(); 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=""" # 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, 'diff', """ # # uftrace diff # [0] base: xxx (from uftrace record -d xxx -F main tests/t-diff 0 ) # [1] diff: yyy (from uftrace record -d yyy -F main tests/t-diff 1 ) # Total time Calls Function ============ ========== ==================== +1.296 ms +0 main +1.292 ms +3 usleep +1.225 ms +0 foo +158.450 us +0 bar -0.066 us +0 atoi """)
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.410 us [29826] | operator delete(); 143.705 us [29826] | } /* main */ """)