Skip to content

Instantly share code, notes, and snippets.

@nkurz
Created February 11, 2016 20:52
Show Gist options
  • Save nkurz/45824bfdd95a756dcbe6 to your computer and use it in GitHub Desktop.
Save nkurz/45824bfdd95a756dcbe6 to your computer and use it in GitHub Desktop.
function trace of one iteration from http://nicst.de/bench-user-irq-detect.html
/* function trace of one iteration from http://nicst.de/bench-user-irq-detect.html */
/* lxdetectirq_thread_capture_start(struct lxdetectirq_capture const * const c) */
/* ioctl(c->fds[0], PERF_EVENT_IOC_ENABLE, PERF_IOC_FLAG_GROUP) */
timer-5372 [003] .... 382853.609575: syscall_trace_enter_phase1 <-tracesys
timer-5372 [003] .... 382853.609575: context_tracking_user_exit <-syscall_trace_enter_phase1
timer-5372 [003] .... 382853.609575: context_tracking_exit <-context_tracking_user_exit
timer-5372 [003] d... 382853.609576: context_tracking_recursion_enter <-context_tracking_exit
timer-5372 [003] d... 382853.609576: rcu_user_exit <-context_tracking_exit
timer-5372 [003] d... 382853.609576: vtime_account_user <-context_tracking_exit
timer-5372 [003] d... 382853.609576: _raw_spin_lock <-vtime_account_user
timer-5372 [003] d... 382853.609576: get_vtime_delta <-vtime_account_user
timer-5372 [003] d... 382853.609576: account_user_time <-vtime_account_user
timer-5372 [003] d... 382853.609576: cpuacct_account_field <-account_user_time
timer-5372 [003] d... 382853.609576: acct_account_cputime <-account_user_time
timer-5372 [003] d... 382853.609576: __acct_update_integrals <-acct_account_cputime
timer-5372 [003] d... 382853.609576: jiffies_to_timeval <-__acct_update_integrals
timer-5372 [003] d... 382853.609576: user_exit:
timer-5372 [003] .... 382853.609576: syscall_trace_enter_phase2 <-tracesys_phase2
timer-5372 [003] .... 382853.609576: sys_ioctl(fd: 5, cmd: 2400, arg: 1)
timer-5372 [003] .... 382853.609576: sys_enter: NR 16 (5, 2400, 1, 7f2bffe2a6a0, 7f2bffbe3dc0, 0)
timer-5372 [003] .... 382853.609576: do_audit_syscall_entry <-syscall_trace_enter_phase2
timer-5372 [003] .... 382853.609576: SyS_ioctl <-tracesys_phase2
timer-5372 [003] .... 382853.609576: __fdget <-SyS_ioctl
timer-5372 [003] .... 382853.609577: __fget_light <-__fdget
timer-5372 [003] .... 382853.609577: security_file_ioctl <-SyS_ioctl
timer-5372 [003] .... 382853.609577: do_vfs_ioctl <-SyS_ioctl
timer-5372 [003] .... 382853.609577: mutex_lock <-perf_event_ctx_lock_nested.isra.58
timer-5372 [003] .... 382853.609577: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609577: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609577: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609577: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609577: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609577: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609577: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609577: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609577: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609578: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609578: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609578: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609578: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609578: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609578: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609578: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609578: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609578: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609578: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609578: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609578: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609578: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609578: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609579: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609579: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609579: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609579: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609579: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609579: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609579: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609579: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609579: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609579: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609579: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609579: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609579: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609579: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609580: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609580: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609580: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609580: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609580: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609580: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609580: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609580: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609580: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609580: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609580: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609580: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609580: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609580: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609580: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609581: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609581: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609581: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609581: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609581: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609581: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609581: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609581: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609581: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609581: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609581: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609581: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609581: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609581: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609582: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609582: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609582: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609582: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609582: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609582: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609582: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609582: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609582: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609582: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609582: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609582: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609582: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609583: _raw_spin_lock_irq <-_perf_event_enable
timer-5372 [003] .... 382853.609583: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.609583: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.609583: _raw_spin_lock <-__perf_event_enable
timer-5372 [003] .... 382853.609583: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.609583: mutex_unlock <-perf_ioctl
timer-5372 [003] .... 382853.609583: syscall_trace_leave <-int_very_careful
timer-5372 [003] .... 382853.609583: context_tracking_user_exit <-syscall_trace_leave
timer-5372 [003] .... 382853.609583: context_tracking_exit <-context_tracking_user_exit
timer-5372 [003] d... 382853.609583: context_tracking_recursion_enter <-context_tracking_exit
timer-5372 [003] .... 382853.609583: sys_ioctl -> 0x0
timer-5372 [003] .... 382853.609583: sys_exit: NR 16 = 0
timer-5372 [003] .... 382853.609583: context_tracking_user_enter <-syscall_trace_leave
timer-5372 [003] .... 382853.609583: context_tracking_enter <-context_tracking_user_enter
timer-5372 [003] d... 382853.609583: context_tracking_recursion_enter <-context_tracking_enter
timer-5372 [003] d... 382853.609583: user_enter:
timer-5372 [003] d... 382853.609584: vtime_user_enter <-context_tracking_enter
timer-5372 [003] d... 382853.609584: _raw_spin_lock <-vtime_user_enter
timer-5372 [003] d... 382853.609584: __vtime_account_system <-vtime_user_enter
timer-5372 [003] d... 382853.609584: get_vtime_delta <-__vtime_account_system
timer-5372 [003] d... 382853.609584: account_system_time <-__vtime_account_system
timer-5372 [003] d... 382853.609584: cpuacct_account_field <-account_system_time
timer-5372 [003] d... 382853.609584: acct_account_cputime <-account_system_time
timer-5372 [003] d... 382853.609584: __acct_update_integrals <-acct_account_cputime
timer-5372 [003] d... 382853.609584: jiffies_to_timeval <-__acct_update_integrals
timer-5372 [003] d... 382853.609584: rcu_user_enter <-context_tracking_enter
timer-5372 [003] d... 382853.609584: rcu_eqs_enter <-rcu_user_enter
timer-5372 [003] d... 382853.609584: rcu_eqs_enter_common <-rcu_eqs_enter
/* rdtsc start */
/* user test (10 million cycle empty loop in this case) */
/* rdtsc stop */
/* int lxdetectirq_thread_capture_stop(struct lxdetectirq_capture * const c) */
/* ioctl(c->fds[0], PERF_EVENT_IOC_DISABLE, PERF_IOC_FLAG_GROUP) */
timer-5372 [003] .... 382853.612538: syscall_trace_enter_phase1 <-tracesys
timer-5372 [003] .... 382853.612538: context_tracking_user_exit <-syscall_trace_enter_phase1
timer-5372 [003] .... 382853.612538: context_tracking_exit <-context_tracking_user_exit
timer-5372 [003] d... 382853.612538: context_tracking_recursion_enter <-context_tracking_exit
timer-5372 [003] d... 382853.612538: rcu_user_exit <-context_tracking_exit
timer-5372 [003] d... 382853.612538: vtime_account_user <-context_tracking_exit
timer-5372 [003] d... 382853.612538: _raw_spin_lock <-vtime_account_user
timer-5372 [003] d... 382853.612538: get_vtime_delta <-vtime_account_user
timer-5372 [003] d... 382853.612538: account_user_time <-vtime_account_user
timer-5372 [003] d... 382853.612538: cpuacct_account_field <-account_user_time
timer-5372 [003] d... 382853.612538: acct_account_cputime <-account_user_time
timer-5372 [003] d... 382853.612538: __acct_update_integrals <-acct_account_cputime
timer-5372 [003] d... 382853.612539: jiffies_to_timeval <-__acct_update_integrals
timer-5372 [003] d... 382853.612539: user_exit:
timer-5372 [003] .... 382853.612539: syscall_trace_enter_phase2 <-tracesys_phase2
timer-5372 [003] .... 382853.612539: sys_ioctl(fd: 5, cmd: 2401, arg: 1)
timer-5372 [003] .... 382853.612539: sys_enter: NR 16 (5, 2401, 1, 7f2bffe2a6a0, 7f2bffbe3dc0, 0)
timer-5372 [003] .... 382853.612539: do_audit_syscall_entry <-syscall_trace_enter_phase2
timer-5372 [003] .... 382853.612539: SyS_ioctl <-tracesys_phase2
timer-5372 [003] .... 382853.612539: __fdget <-SyS_ioctl
timer-5372 [003] .... 382853.612539: __fget_light <-__fdget
timer-5372 [003] .... 382853.612539: security_file_ioctl <-SyS_ioctl
timer-5372 [003] .... 382853.612539: do_vfs_ioctl <-SyS_ioctl
timer-5372 [003] .... 382853.612539: mutex_lock <-perf_event_ctx_lock_nested.isra.58
timer-5372 [003] .... 382853.612539: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612539: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612539: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612539: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612540: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612540: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612540: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612540: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612540: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612540: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612540: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612540: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612540: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612540: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612541: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612541: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612541: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612541: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612541: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612541: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612541: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612541: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612541: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612541: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612541: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612541: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612541: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612541: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612541: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612542: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612542: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612542: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612542: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612542: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612542: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612542: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612542: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612542: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612542: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612542: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612542: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612542: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612542: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612542: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612543: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612543: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612543: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612543: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612543: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612543: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612543: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612543: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612543: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612543: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612543: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612543: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612543: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612543: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612543: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612543: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612544: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612544: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612544: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612544: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612544: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612544: mutex_lock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612544: smp_call_function_single <-task_function_call
timer-5372 [003] .... 382853.612544: generic_exec_single <-smp_call_function_single
timer-5372 [003] d... 382853.612544: _raw_spin_lock <-__perf_event_disable
timer-5372 [003] .... 382853.612544: mutex_unlock <-perf_event_for_each_child
timer-5372 [003] .... 382853.612544: mutex_unlock <-perf_ioctl
timer-5372 [003] .... 382853.612544: syscall_trace_leave <-int_very_careful
timer-5372 [003] .... 382853.612544: context_tracking_user_exit <-syscall_trace_leave
timer-5372 [003] .... 382853.612544: context_tracking_exit <-context_tracking_user_exit
timer-5372 [003] d... 382853.612544: context_tracking_recursion_enter <-context_tracking_exit
timer-5372 [003] .... 382853.612545: sys_ioctl -> 0x0
timer-5372 [003] .... 382853.612545: sys_exit: NR 16 = 0
timer-5372 [003] .... 382853.612545: context_tracking_user_enter <-syscall_trace_leave
timer-5372 [003] .... 382853.612545: context_tracking_enter <-context_tracking_user_enter
timer-5372 [003] d... 382853.612545: context_tracking_recursion_enter <-context_tracking_enter
timer-5372 [003] d... 382853.612545: user_enter:
timer-5372 [003] d... 382853.612545: vtime_user_enter <-context_tracking_enter
timer-5372 [003] d... 382853.612545: _raw_spin_lock <-vtime_user_enter
timer-5372 [003] d... 382853.612545: __vtime_account_system <-vtime_user_enter
timer-5372 [003] d... 382853.612545: get_vtime_delta <-__vtime_account_system
timer-5372 [003] d... 382853.612545: account_system_time <-__vtime_account_system
timer-5372 [003] d... 382853.612545: cpuacct_account_field <-account_system_time
timer-5372 [003] d... 382853.612545: acct_account_cputime <-account_system_time
timer-5372 [003] d... 382853.612545: __acct_update_integrals <-acct_account_cputime
timer-5372 [003] d... 382853.612545: jiffies_to_timeval <-__acct_update_integrals
timer-5372 [003] d... 382853.612545: rcu_user_enter <-context_tracking_enter
timer-5372 [003] d... 382853.612546: rcu_eqs_enter <-rcu_user_enter
timer-5372 [003] d... 382853.612546: rcu_eqs_enter_common <-rcu_eqs_enter
/* read(c->fds[0], c->samples, sizeof(c->samples)); */
timer-5372 [003] .... 382853.612546: syscall_trace_enter_phase1 <-tracesys
timer-5372 [003] .... 382853.612546: context_tracking_user_exit <-syscall_trace_enter_phase1
timer-5372 [003] .... 382853.612546: context_tracking_exit <-context_tracking_user_exit
timer-5372 [003] d... 382853.612546: context_tracking_recursion_enter <-context_tracking_exit
timer-5372 [003] d... 382853.612546: rcu_user_exit <-context_tracking_exit
timer-5372 [003] d... 382853.612546: vtime_account_user <-context_tracking_exit
timer-5372 [003] d... 382853.612546: _raw_spin_lock <-vtime_account_user
timer-5372 [003] d... 382853.612546: get_vtime_delta <-vtime_account_user
timer-5372 [003] d... 382853.612546: account_user_time <-vtime_account_user
timer-5372 [003] d... 382853.612546: cpuacct_account_field <-account_user_time
timer-5372 [003] d... 382853.612546: acct_account_cputime <-account_user_time
timer-5372 [003] d... 382853.612546: __acct_update_integrals <-acct_account_cputime
timer-5372 [003] d... 382853.612546: jiffies_to_timeval <-__acct_update_integrals
timer-5372 [003] d... 382853.612546: user_exit:
timer-5372 [003] .... 382853.612547: syscall_trace_enter_phase2 <-tracesys_phase2
timer-5372 [003] .... 382853.612547: sys_read(fd: 5, buf: 7ffc2594ecf8, count: 78)
timer-5372 [003] .... 382853.612547: sys_enter: NR 0 (5, 7ffc2594ecf8, 78, 7f2bffe2a6a0, 7f2bffbe3dc0, 0)
timer-5372 [003] .... 382853.612547: do_audit_syscall_entry <-syscall_trace_enter_phase2
timer-5372 [003] .... 382853.612547: SyS_read <-tracesys_phase2
timer-5372 [003] .... 382853.612547: __fdget_pos <-SyS_read
timer-5372 [003] .... 382853.612547: __fget_light <-__fdget_pos
timer-5372 [003] .... 382853.612547: vfs_read <-SyS_read
timer-5372 [003] .... 382853.612547: rw_verify_area <-vfs_read
timer-5372 [003] .... 382853.612547: security_file_permission <-rw_verify_area
timer-5372 [003] .... 382853.612547: apparmor_file_permission <-security_file_permission
timer-5372 [003] .... 382853.612547: common_file_perm <-apparmor_file_permission
timer-5372 [003] .... 382853.612547: aa_file_perm <-common_file_perm
timer-5372 [003] .... 382853.612547: __fsnotify_parent <-security_file_permission
timer-5372 [003] .... 382853.612547: fsnotify <-security_file_permission
timer-5372 [003] .... 382853.612547: __vfs_read <-vfs_read
timer-5372 [003] .... 382853.612548: mutex_lock <-perf_event_ctx_lock_nested.isra.58
timer-5372 [003] .... 382853.612548: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612548: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612549: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612550: mutex_lock <-perf_event_read_value
timer-5372 [003] .... 382853.612550: mutex_unlock <-perf_event_read_value
timer-5372 [003] .... 382853.612550: mutex_unlock <-perf_read
timer-5372 [003] .... 382853.612550: __fsnotify_parent <-vfs_read
timer-5372 [003] .... 382853.612550: fsnotify <-vfs_read
timer-5372 [003] .... 382853.612550: syscall_trace_leave <-int_very_careful
timer-5372 [003] .... 382853.612550: context_tracking_user_exit <-syscall_trace_leave
timer-5372 [003] .... 382853.612550: context_tracking_exit <-context_tracking_user_exit
timer-5372 [003] d... 382853.612550: context_tracking_recursion_enter <-context_tracking_exit
timer-5372 [003] .... 382853.612550: sys_read -> 0x78
timer-5372 [003] .... 382853.612550: sys_exit: NR 0 = 120
timer-5372 [003] .... 382853.612550: context_tracking_user_enter <-syscall_trace_leave
timer-5372 [003] .... 382853.612550: context_tracking_enter <-context_tracking_user_enter
timer-5372 [003] d... 382853.612550: context_tracking_recursion_enter <-context_tracking_enter
timer-5372 [003] d... 382853.612550: user_enter:
timer-5372 [003] d... 382853.612550: vtime_user_enter <-context_tracking_enter
timer-5372 [003] d... 382853.612551: _raw_spin_lock <-vtime_user_enter
timer-5372 [003] d... 382853.612551: __vtime_account_system <-vtime_user_enter
timer-5372 [003] d... 382853.612551: get_vtime_delta <-__vtime_account_system
timer-5372 [003] d... 382853.612551: account_system_time <-__vtime_account_system
timer-5372 [003] d... 382853.612551: cpuacct_account_field <-account_system_time
timer-5372 [003] d... 382853.612551: acct_account_cputime <-account_system_time
timer-5372 [003] d... 382853.612551: __acct_update_integrals <-acct_account_cputime
timer-5372 [003] d... 382853.612551: jiffies_to_timeval <-__acct_update_integrals
timer-5372 [003] d... 382853.612551: rcu_user_enter <-context_tracking_enter
timer-5372 [003] d... 382853.612551: rcu_eqs_enter <-rcu_user_enter
timer-5372 [003] d... 382853.612551: rcu_eqs_enter_common <-rcu_eqs_enter
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment