tools/trace.py: aggregate trace events by '-A' option
authorzhenwei pi <pizhenwei@bytedance.com>
Thu, 13 Jan 2022 11:56:32 +0000 (19:56 +0800)
committeryonghong-song <ys114321@gmail.com>
Fri, 14 Jan 2022 03:12:05 +0000 (19:12 -0800)
commit047541c4b0274d68cd6837e7f19c133b1ce548ce
tree4d699bdf91ccfb2e925a8680e7dfba58c2355b9e
parentaa7200b9b2a7a2ce2e8a6f0dc1f456f3f93af1da
tools/trace.py: aggregate trace events by '-A' option

Orignally we can save the backtrace of a specified function into a
text file, then try to analyze the messy trace to guess why the
function is called.

To make the work easier, aggregate amount of trace by -A with -M EVENTS.
A typical example:
1, if we find that the sys CPU utilization is higher by 'top' command
2, then find that the timer interrupt is more normal by 'irqtop' command
3, to confirm kernel timer setting frequence by 'funccount -i 1 clockevents_program_event'
4, to trace timer setting by 'trace clockevents_program_event -K -A -M 1000'

1294576 1294584 CPU 0/KVM       clockevents_program_event
        clockevents_program_event+0x1 [kernel]
        hrtimer_start_range_ns+0x209 [kernel]
        start_sw_timer+0x173 [kvm]
        restart_apic_timer+0x6c [kvm]
        kvm_set_msr_common+0x442 [kvm]
        __kvm_set_msr+0xa2 [kvm]
        kvm_emulate_wrmsr+0x36 [kvm]
        vcpu_enter_guest+0x326 [kvm]
        kvm_arch_vcpu_ioctl_run+0xcc [kvm]
        kvm_vcpu_ioctl+0x22f [kvm]
        do_vfs_ioctl+0xa1 [kernel]
        ksys_ioctl+0x60 [kernel]
        __x64_sys_ioctl+0x16 [kernel]
        do_syscall_64+0x59 [kernel]
        entry_SYSCALL_64_after_hwframe+0x44 [kernel]
-->COUNT 271

...
Then we can know that 271 timer setting in recent 1000(~27%) occurs in
KVM code path.

To avoid too large size of a dictionary in python, -A works always with
-M.

Also fix several minor changes to keep 'trace -h' aligned with trace_example.txt.

Signed-off-by: zhenwei pi <pizhenwei@bytedance.com>
man/man8/trace.8
tools/trace.py
tools/trace_example.txt