码迷,mamicode.com
首页 > 移动开发 > 详细

Android下的一些调试手段(含kernel调试办法)

时间:2015-01-04 21:33:05      阅读:352      评论:0      收藏:0      [点我收藏+]

标签:android   kernel   调试   profiling   

主要介绍除了常规的kernel的printk和android的DDMS, logcat外的几个调试手段.

包括bugreport, oprofile, traceview, ftrace等.


Bugreport

Bugreport是android平台自带的工具, 收集了device端的详细的状况, 可以在console下直接运行“bugreport > /sdcard/bugreport.log”或者接入USB cable并打开adb debug的状况下运行”adb bugreport > bugreport.log”.
下面是一个抓取的bugreport的参考资料.
 
相关代码路径
frameworks\base\cmds\bugreport
frameworks\base\cmds\dumpstate
frameworks\base\cmds\dumpsys


oprofile

Oprofie的原理比较简单: 很多CPU都提供一个所谓性能计数器的东西(performance counter),
大致的原理就是程序可以注册告诉CPU对什么event感兴趣(比如CPU_CYCLE, CPU经历了一次时钟周期),
然后CPU在执行了相应的操作后, 就会在性能计数器上加1, 这样程序就可以取出.
所以, 使用OProfile来定位CPU使用率的问题, 就变成了让oprofile收集程序运行过程中哪个可执行程序(或是so)中的哪个function, 消耗的CPU CYCLE最多.

在实际应用中, oprofile可以用来对找出系统的瓶颈并进行优化.
R70中默认的工程中, Oprofile是没有被编译进来的, 需要修改external\oprofile\opcontrol\android.mk和external\oprofile\daemon\android.mk
两个文件中的LOCAL_MODULE_TAGS 属性从debug修改为eng或者user, 从而将oprofile编译进android中.

此外, Oprofile需要kernel中打开相应的compile option来支持, kernel对应代码在kernel\trace目录中. 相应的config如下:

General setup  [*] Profiling Support
    CONFIG_PROFILING

General setup <*> OProfile system profiling
    CONFIG_OPROFILE
    CONFIG_RING_BUFFER
    CONFIG_RING_BUFFER_ALLOW_SWAP
    CONFIG_RING_BUFFER_BENCHMARK is not set

General setup   Kernel Performance Events And Counters
    [*] Kernel performance events and counters
    CONFIG_PERF_EVENTS
    CONFIG_HW_PERF_EVENTS

Examples:
技术分享


技术分享

技术分享

最后, 在PC端安装oprofile以便对device端生成的结果进行解析.

技术分享

如果需要得到最后的图形结果, 还需要安装Graphviz.

技术分享

所有的准备工作就绪后,只要在device端运行如下的命令,即可启动oprofile对device进行检测.

opcontrol–quick     ===>  setup相应的环境和参数

opcontrol–start      ===>  启动oprofile

opcontrol–status   ===>  中途可以查看oprofile的状态

opcontrol–stop      ===>  停止oprofile

opcontrol–dump    ===>  将结果保存至/data/oprofile 路径

 

最后, 在PC端运行android工程中的external\oprofile下的opimport_pull脚本, 即可生成相应的结果callgraph.txt, load.txt, load2.txt以及callgraph.png(如下).

技术分享

注意, 在运行脚本前需要设置一些环境变量和device端kernel对应的vmlinux档案.

exportOPROFILE_EVENTS_DIR= {Your Android Source DIR}/prebuilt/linux-x86_64/oprofile/

exportOPROFILE_BIN_DIR=/{Oprofile Bin DIR on Your PC }/

exportOUT= {Your Android Source DIR}/out/target/product/smdkv210

cd  {Your Android Source DIR}/out/target/product/smdkv210/symbols

ln -s {Your Kernel Source DIR}/vmlinux ./vmlinux


traceview

Traceview是android自带的tool,用来分析在android端通过调用Debug.startMethodTracing("xxxx");生成的名为xxxx.trace的档案. 这个方法需要在android的代码中添加Debug.startMethodTracing("xxxx")和Debug.stopMethodTracing()的代码. 使用者通过在合理地点添加这两个函数, 可以很直观的分析在这个中间过程中, 系统的运行状况, 上到每个进程在什么时候开始跑了多长时间, 下到每个函数跑了多少次, 每次跑了多长时间.

技术分享


Ftrace

ftrace是内建于Linux内核的跟踪工具, 从2.6.27开始加入主流内核. ftrace的作用是帮助开发人员了解 Linux 内核的运行时行为, 以便进行故障调试或性能分析.

使用ftrace可以对内核函数调用、上下文切换进行跟踪, 还可以查看中断被关闭的时长, 跟踪内核态中的延迟以及性能问题等.

使用ftrace对内核进行跟踪调试, 可以找到内核中出现的问题的根源, 通过ftrace来观察内核中发生的活动, 则可以了解内核的工作机制.

 Ftrace可以在device的UI没有反应, 但是console还是active的状况下对kernel进行分析.

Ftrace的功能需要在kernel中打开相应的config. 此外, 打开ftrace会给系统带来额外的overhead, 因此应该在release的版本中尽可能关闭ftrace的功能.

图 1.Kernel hackin

图 1. Kernel hacking

技术分享
图 2. Tracers

技术分享
图 3. 内核支持的跟踪器列表

技术分享

R70的kernel中,Ftrace支持的tracer有 wakeup, preemptirqsoff, preemptoff, irqsoff, function, sched_switch共6种.

具体的使用方法可以参考Reference中的连接以及kernel中的documents\trace下的ftrace.txt

得到的一些结果如下:

# tracer: function
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |
 InputDispatcher-412   [000] 10173.076687: sub_preempt_count <-mnt_want_write
 InputDispatcher-412   [000] 10173.076690: __mark_inode_dirty <-file_update_time
 InputDispatcher-412   [000] 10173.076692: mnt_drop_write <-file_update_time
 InputDispatcher-412   [000] 10173.076694: add_preempt_count <-mnt_drop_write
 InputDispatcher-412   [000] 10173.076697: sub_preempt_count <-mnt_drop_write
 InputDispatcher-412   [000] 10173.076699: inotify_inode_queue_event <-vfs_write
 InputDispatcher-412   [000] 10173.076701: __fsnotify_parent <-vfs_write
 InputDispatcher-412   [000] 10173.076704: inotify_dentry_parent_queue_event <-vfs_write
 InputDispatcher-412   [000] 10173.076706: fsnotify <-vfs_write
 InputDispatcher-412   [000] 10173.076708: fput <-sys_write
 InputDispatcher-412   [000] 10173.076715: sys_clock_gettime <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.076718: posix_ktime_get_ts <-sys_clock_gettime
 InputDispatcher-412   [000] 10173.076720: ktime_get_ts <-posix_ktime_get_ts
 InputDispatcher-412   [000] 10173.076722: s5p_sched_timer_read <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076725: set_normalized_timespec <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076730: sys_clock_gettime <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.076732: posix_ktime_get_ts <-sys_clock_gettime
 InputDispatcher-412   [000] 10173.076735: ktime_get_ts <-posix_ktime_get_ts
 InputDispatcher-412   [000] 10173.076737: s5p_sched_timer_read <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076739: set_normalized_timespec <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076743: sys_clock_gettime <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.076746: posix_ktime_get_ts <-sys_clock_gettime
 InputDispatcher-412   [000] 10173.076748: ktime_get_ts <-posix_ktime_get_ts
 InputDispatcher-412   [000] 10173.076750: s5p_sched_timer_read <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076752: set_normalized_timespec <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076758: sys_epoll_wait <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.076760: fget <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.076763: add_preempt_count <-fget
 InputDispatcher-412   [000] 10173.076765: sub_preempt_count <-fget
 InputDispatcher-412   [000] 10173.076769: _raw_spin_lock_irqsave <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.076771: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.076774: _raw_spin_unlock_irqrestore <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.076775: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.076778: ep_scan_ready_list <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.076780: mutex_lock <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.076782: __might_sleep <-mutex_lock
 InputDispatcher-412   [000] 10173.076785: __mutex_lock_slowpath <-mutex_lock
 InputDispatcher-412   [000] 10173.076787: add_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.076790: sub_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.076792: _raw_spin_lock_irqsave <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.076794: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.076797: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.076798: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.076800: ep_send_events_proc <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.076803: pipe_poll <-ep_send_events_proc
 InputDispatcher-412   [000] 10173.076805: _raw_spin_lock_irqsave <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.076808: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.076810: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.076812: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.076814: mutex_unlock <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.076816: __mutex_unlock_slowpath <-mutex_unlock
 InputDispatcher-412   [000] 10173.076819: fput <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.076825: sys_clock_gettime <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.076828: posix_ktime_get_ts <-sys_clock_gettime
 InputDispatcher-412   [000] 10173.076830: ktime_get_ts <-posix_ktime_get_ts
 InputDispatcher-412   [000] 10173.076832: s5p_sched_timer_read <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076835: set_normalized_timespec <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076838: sys_clock_gettime <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.076841: posix_ktime_get_ts <-sys_clock_gettime
 InputDispatcher-412   [000] 10173.076843: ktime_get_ts <-posix_ktime_get_ts
 InputDispatcher-412   [000] 10173.076845: s5p_sched_timer_read <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076848: set_normalized_timespec <-ktime_get_ts
 InputDispatcher-412   [000] 10173.076855: sys_epoll_wait <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.076857: fget <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.076860: add_preempt_count <-fget
 InputDispatcher-412   [000] 10173.076862: sub_preempt_count <-fget
 InputDispatcher-412   [000] 10173.076864: _raw_spin_lock_irqsave <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.076867: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.076869: _raw_spin_unlock_irqrestore <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.076871: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.076873: schedule_hrtimeout_range <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.076876: schedule_hrtimeout_range_clock <-schedule_hrtimeout_range
 InputDispatcher-412   [000] 10173.076878: schedule <-schedule_hrtimeout_range_clock
 InputDispatcher-412   [000] 10173.076880: add_preempt_count <-schedule
 InputDispatcher-412   [000] 10173.076882: rcu_note_context_switch <-schedule
 InputDispatcher-412   [000] 10173.076884: rcu_sched_qs <-rcu_note_context_switch
 InputDispatcher-412   [000] 10173.076886: _raw_spin_lock_irq <-schedule
 InputDispatcher-412   [000] 10173.076888: add_preempt_count <-_raw_spin_lock_irq
 InputDispatcher-412   [000] 10173.076890: T.1190 <-schedule
 InputDispatcher-412   [000] 10173.076891: dequeue_task <-T.1190
 InputDispatcher-412   [000] 10173.076893: s5p_sched_timer_read <-sched_clock
 InputDispatcher-412   [000] 10173.076895: dequeue_task_fair <-dequeue_task
 InputDispatcher-412   [000] 10173.076897: dequeue_entity <-dequeue_task_fair
 InputDispatcher-412   [000] 10173.076898: update_curr <-dequeue_entity
 InputDispatcher-412   [000] 10173.076900: calc_delta_mine <-update_curr
 InputDispatcher-412   [000] 10173.076902: update_min_vruntime <-update_curr
 InputDispatcher-412   [000] 10173.076904: cpuacct_charge <-update_curr
 InputDispatcher-412   [000] 10173.076905: add_preempt_count <-cpuacct_charge
 InputDispatcher-412   [000] 10173.076907: sub_preempt_count <-cpuacct_charge
 InputDispatcher-412   [000] 10173.076909: clear_buddies <-dequeue_entity
 InputDispatcher-412   [000] 10173.076911: update_min_vruntime <-dequeue_entity
 InputDispatcher-412   [000] 10173.076913: put_prev_task_fair <-schedule
 InputDispatcher-412   [000] 10173.076915: pick_next_task_fair <-schedule
 InputDispatcher-412   [000] 10173.076916: __pick_next_entity <-pick_next_task_fair
 InputDispatcher-412   [000] 10173.076918: clear_buddies <-pick_next_task_fair
 InputDispatcher-412   [000] 10173.076920: set_next_entity <-pick_next_task_fair
 InputDispatcher-412   [000] 10173.076921: __dequeue_entity <-set_next_entity
 InputDispatcher-412   [000] 10173.076924: _raw_spin_unlock_irq <-schedule
 InputDispatcher-412   [000] 10173.076926: sub_preempt_count <-_raw_spin_unlock_irq
 InputDispatcher-412   [000] 10173.076931: atomic_notifier_call_chain <-__switch_to
 InputDispatcher-412   [000] 10173.076932: __atomic_notifier_call_chain <-atomic_notifier_call_chain
 InputDispatcher-412   [000] 10173.076934: add_preempt_count <-__atomic_notifier_call_chain
 InputDispatcher-412   [000] 10173.076936: notifier_call_chain <-__atomic_notifier_call_chain
 InputDispatcher-412   [000] 10173.076938: thumbee_notifier <-notifier_call_chain
 InputDispatcher-412   [000] 10173.076939: vfp_notifier <-notifier_call_chain
 InputDispatcher-412   [000] 10173.076941: sub_preempt_count <-__atomic_notifier_call_chain
 ity.filemanager-713   [000] 10173.076944: T.1196 <-schedule
 ity.filemanager-713   [000] 10173.076947: sub_preempt_count <-schedule
 ity.filemanager-713   [000] 10173.076950: _raw_spin_lock_irqsave <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.076952: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.076955: _raw_spin_unlock_irqrestore <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.076956: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.076959: ep_scan_ready_list <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.076961: mutex_lock <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.076963: __might_sleep <-mutex_lock
 ity.filemanager-713   [000] 10173.076965: __mutex_lock_slowpath <-mutex_lock
 ity.filemanager-713   [000] 10173.076968: add_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.076971: sub_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.076973: _raw_spin_lock_irqsave <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.076975: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.076977: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.076979: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.076981: ep_send_events_proc <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.076984: pipe_poll <-ep_send_events_proc
 ity.filemanager-713   [000] 10173.076987: _raw_spin_lock_irqsave <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.076989: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.076992: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.076994: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.076996: mutex_unlock <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.076998: __mutex_unlock_slowpath <-mutex_unlock
 ity.filemanager-713   [000] 10173.077001: fput <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.077018: sys_read <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.077020: fget_light <-sys_read
 ity.filemanager-713   [000] 10173.077023: add_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.077026: sub_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.077028: vfs_read <-sys_read
 ity.filemanager-713   [000] 10173.077030: rw_verify_area <-vfs_read
 ity.filemanager-713   [000] 10173.077033: do_sync_read <-vfs_read
 ity.filemanager-713   [000] 10173.077035: pipe_read <-do_sync_read
 ity.filemanager-713   [000] 10173.077037: mutex_lock <-pipe_read
 ity.filemanager-713   [000] 10173.077040: __might_sleep <-mutex_lock
 ity.filemanager-713   [000] 10173.077042: __mutex_lock_slowpath <-mutex_lock
 ity.filemanager-713   [000] 10173.077045: add_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.077047: sub_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.077050: generic_pipe_buf_confirm <-pipe_read
 ity.filemanager-713   [000] 10173.077052: generic_pipe_buf_map <-pipe_read
 ity.filemanager-713   [000] 10173.077054: add_preempt_count <-generic_pipe_buf_map
 ity.filemanager-713   [000] 10173.077057: generic_pipe_buf_unmap <-pipe_read
 ity.filemanager-713   [000] 10173.077059: sub_preempt_count <-generic_pipe_buf_unmap
 ity.filemanager-713   [000] 10173.077061: anon_pipe_buf_release <-pipe_read
 ity.filemanager-713   [000] 10173.077063: mutex_unlock <-pipe_read
 ity.filemanager-713   [000] 10173.077066: __mutex_unlock_slowpath <-mutex_unlock
 ity.filemanager-713   [000] 10173.077068: __wake_up_sync <-pipe_read
 ity.filemanager-713   [000] 10173.077071: __wake_up_sync_key <-__wake_up_sync
 ity.filemanager-713   [000] 10173.077073: _raw_spin_lock_irqsave <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.077075: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.077078: __wake_up_common <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.077080: ep_poll_callback <-__wake_up_common
 ity.filemanager-713   [000] 10173.077081: _raw_spin_lock_irqsave <-ep_poll_callback
 ity.filemanager-713   [000] 10173.077083: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.077085: _raw_spin_unlock_irqrestore <-ep_poll_callback
 ity.filemanager-713   [000] 10173.077087: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077089: _raw_spin_unlock_irqrestore <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.077090: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077093: kill_fasync <-pipe_read
 ity.filemanager-713   [000] 10173.077095: touch_atime <-pipe_read
 ity.filemanager-713   [000] 10173.077098: current_fs_time <-touch_atime
 ity.filemanager-713   [000] 10173.077100: current_kernel_time <-current_fs_time
 ity.filemanager-713   [000] 10173.077102: timespec_trunc <-current_fs_time
 ity.filemanager-713   [000] 10173.077104: mnt_want_write <-touch_atime
 ity.filemanager-713   [000] 10173.077109: add_preempt_count <-mnt_want_write
 ity.filemanager-713   [000] 10173.077112: __mnt_is_readonly <-mnt_want_write
 ity.filemanager-713   [000] 10173.077113: sub_preempt_count <-mnt_want_write
 ity.filemanager-713   [000] 10173.077116: __mark_inode_dirty <-touch_atime
 ity.filemanager-713   [000] 10173.077118: mnt_drop_write <-touch_atime
 ity.filemanager-713   [000] 10173.077120: add_preempt_count <-mnt_drop_write
 ity.filemanager-713   [000] 10173.077123: sub_preempt_count <-mnt_drop_write
 ity.filemanager-713   [000] 10173.077125: inotify_inode_queue_event <-vfs_read
 ity.filemanager-713   [000] 10173.077127: __fsnotify_parent <-vfs_read
 ity.filemanager-713   [000] 10173.077130: inotify_dentry_parent_queue_event <-vfs_read
 ity.filemanager-713   [000] 10173.077132: fsnotify <-vfs_read
 ity.filemanager-713   [000] 10173.077135: fput <-sys_read
 ity.filemanager-713   [000] 10173.077139: sys_ioctl <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.077142: fget_light <-sys_ioctl
 ity.filemanager-713   [000] 10173.077144: add_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.077146: sub_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.077148: do_vfs_ioctl <-sys_ioctl
 ity.filemanager-713   [000] 10173.077151: vfs_ioctl <-do_vfs_ioctl
 ity.filemanager-713   [000] 10173.077153: ashmem_ioctl <-vfs_ioctl
 ity.filemanager-713   [000] 10173.077156: mutex_lock <-ashmem_ioctl
 ity.filemanager-713   [000] 10173.077158: __might_sleep <-mutex_lock
 ity.filemanager-713   [000] 10173.077160: __mutex_lock_slowpath <-mutex_lock
 ity.filemanager-713   [000] 10173.077162: add_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.077165: sub_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.077167: mutex_unlock <-ashmem_ioctl
 ity.filemanager-713   [000] 10173.077170: __mutex_unlock_slowpath <-mutex_unlock
 ity.filemanager-713   [000] 10173.077173: fput <-sys_ioctl
 ity.filemanager-713   [000] 10173.077240: sys_write <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.077243: fget_light <-sys_write
 ity.filemanager-713   [000] 10173.077246: add_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.077248: sub_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.077251: vfs_write <-sys_write
 ity.filemanager-713   [000] 10173.077253: rw_verify_area <-vfs_write
 ity.filemanager-713   [000] 10173.077255: do_sync_write <-vfs_write
 ity.filemanager-713   [000] 10173.077258: pipe_write <-do_sync_write
 ity.filemanager-713   [000] 10173.077260: mutex_lock <-pipe_write
 ity.filemanager-713   [000] 10173.077262: __might_sleep <-mutex_lock
 ity.filemanager-713   [000] 10173.077265: __mutex_lock_slowpath <-mutex_lock
 ity.filemanager-713   [000] 10173.077267: add_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.077270: sub_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.077273: iov_fault_in_pages_read <-pipe_write
 ity.filemanager-713   [000] 10173.077275: add_preempt_count <-pipe_write
 ity.filemanager-713   [000] 10173.077278: pipe_iov_copy_from_user <-pipe_write
 ity.filemanager-713   [000] 10173.077279: sub_preempt_count <-pipe_write
 ity.filemanager-713   [000] 10173.077282: mutex_unlock <-pipe_write
 ity.filemanager-713   [000] 10173.077284: __mutex_unlock_slowpath <-mutex_unlock
 ity.filemanager-713   [000] 10173.077287: __wake_up_sync <-pipe_write
 ity.filemanager-713   [000] 10173.077289: __wake_up_sync_key <-__wake_up_sync
 ity.filemanager-713   [000] 10173.077291: _raw_spin_lock_irqsave <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.077294: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.077296: __wake_up_common <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.077298: ep_poll_callback <-__wake_up_common
 ity.filemanager-713   [000] 10173.077300: _raw_spin_lock_irqsave <-ep_poll_callback
 ity.filemanager-713   [000] 10173.077301: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.077303: _raw_spin_unlock_irqrestore <-ep_poll_callback
 ity.filemanager-713   [000] 10173.077305: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077307: _raw_spin_unlock_irqrestore <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.077309: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077311: kill_fasync <-pipe_write
 ity.filemanager-713   [000] 10173.077313: file_update_time <-pipe_write
 ity.filemanager-713   [000] 10173.077316: current_fs_time <-file_update_time
 ity.filemanager-713   [000] 10173.077318: current_kernel_time <-current_fs_time
 ity.filemanager-713   [000] 10173.077321: timespec_trunc <-current_fs_time
 ity.filemanager-713   [000] 10173.077323: mnt_want_write_file <-file_update_time
 ity.filemanager-713   [000] 10173.077326: mnt_want_write <-mnt_want_write_file
 ity.filemanager-713   [000] 10173.077328: add_preempt_count <-mnt_want_write
 ity.filemanager-713   [000] 10173.077330: __mnt_is_readonly <-mnt_want_write
 ity.filemanager-713   [000] 10173.077332: sub_preempt_count <-mnt_want_write
 ity.filemanager-713   [000] 10173.077334: __mark_inode_dirty <-file_update_time
 ity.filemanager-713   [000] 10173.077337: mnt_drop_write <-file_update_time
 ity.filemanager-713   [000] 10173.077339: add_preempt_count <-mnt_drop_write
 ity.filemanager-713   [000] 10173.077341: sub_preempt_count <-mnt_drop_write
 ity.filemanager-713   [000] 10173.077344: inotify_inode_queue_event <-vfs_write
 ity.filemanager-713   [000] 10173.077346: __fsnotify_parent <-vfs_write
 ity.filemanager-713   [000] 10173.077348: inotify_dentry_parent_queue_event <-vfs_write
 ity.filemanager-713   [000] 10173.077351: fsnotify <-vfs_write
 ity.filemanager-713   [000] 10173.077353: fput <-sys_write
 ity.filemanager-713   [000] 10173.077364: sys_clock_gettime <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.077367: posix_ktime_get_ts <-sys_clock_gettime
 ity.filemanager-713   [000] 10173.077369: ktime_get_ts <-posix_ktime_get_ts
 ity.filemanager-713   [000] 10173.077371: s5p_sched_timer_read <-ktime_get_ts
 ity.filemanager-713   [000] 10173.077374: set_normalized_timespec <-ktime_get_ts
 ity.filemanager-713   [000] 10173.077437: sys_write <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.077440: fget_light <-sys_write
 ity.filemanager-713   [000] 10173.077442: add_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.077445: sub_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.077447: vfs_write <-sys_write
 ity.filemanager-713   [000] 10173.077450: rw_verify_area <-vfs_write
 ity.filemanager-713   [000] 10173.077452: do_sync_write <-vfs_write
 ity.filemanager-713   [000] 10173.077454: pipe_write <-do_sync_write
 ity.filemanager-713   [000] 10173.077457: mutex_lock <-pipe_write
 ity.filemanager-713   [000] 10173.077459: __might_sleep <-mutex_lock
 ity.filemanager-713   [000] 10173.077461: __mutex_lock_slowpath <-mutex_lock
 ity.filemanager-713   [000] 10173.077463: add_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.077467: sub_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.077469: iov_fault_in_pages_read <-pipe_write
 ity.filemanager-713   [000] 10173.077472: add_preempt_count <-pipe_write
 ity.filemanager-713   [000] 10173.077474: pipe_iov_copy_from_user <-pipe_write
 ity.filemanager-713   [000] 10173.077476: sub_preempt_count <-pipe_write
 ity.filemanager-713   [000] 10173.077478: mutex_unlock <-pipe_write
 ity.filemanager-713   [000] 10173.077481: __mutex_unlock_slowpath <-mutex_unlock
 ity.filemanager-713   [000] 10173.077484: __wake_up_sync <-pipe_write
 ity.filemanager-713   [000] 10173.077486: __wake_up_sync_key <-__wake_up_sync
 ity.filemanager-713   [000] 10173.077488: _raw_spin_lock_irqsave <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.077491: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.077493: __wake_up_common <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.077495: ep_poll_callback <-__wake_up_common
 ity.filemanager-713   [000] 10173.077497: _raw_spin_lock_irqsave <-ep_poll_callback
 ity.filemanager-713   [000] 10173.077499: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.077500: __wake_up_locked <-ep_poll_callback
 ity.filemanager-713   [000] 10173.077502: __wake_up_common <-__wake_up_locked
 ity.filemanager-713   [000] 10173.077504: default_wake_function <-__wake_up_common
 ity.filemanager-713   [000] 10173.077506: try_to_wake_up <-default_wake_function
 ity.filemanager-713   [000] 10173.077508: add_preempt_count <-try_to_wake_up
 ity.filemanager-713   [000] 10173.077509: task_rq_lock <-try_to_wake_up
 ity.filemanager-713   [000] 10173.077511: _raw_spin_lock <-task_rq_lock
 ity.filemanager-713   [000] 10173.077513: add_preempt_count <-_raw_spin_lock
 ity.filemanager-713   [000] 10173.077515: activate_task <-try_to_wake_up
 ity.filemanager-713   [000] 10173.077516: enqueue_task <-activate_task
 ity.filemanager-713   [000] 10173.077518: s5p_sched_timer_read <-sched_clock
 ity.filemanager-713   [000] 10173.077520: enqueue_task_fair <-enqueue_task
 ity.filemanager-713   [000] 10173.077522: enqueue_entity <-enqueue_task_fair
 ity.filemanager-713   [000] 10173.077524: update_curr <-enqueue_entity
 ity.filemanager-713   [000] 10173.077525: update_min_vruntime <-update_curr
 ity.filemanager-713   [000] 10173.077527: cpuacct_charge <-update_curr
 ity.filemanager-713   [000] 10173.077529: add_preempt_count <-cpuacct_charge
 ity.filemanager-713   [000] 10173.077532: sub_preempt_count <-cpuacct_charge
 ity.filemanager-713   [000] 10173.077534: place_entity <-enqueue_entity
 ity.filemanager-713   [000] 10173.077536: __enqueue_entity <-enqueue_entity
 ity.filemanager-713   [000] 10173.077538: check_preempt_wakeup <-try_to_wake_up
 ity.filemanager-713   [000] 10173.077540: update_curr <-check_preempt_wakeup
 ity.filemanager-713   [000] 10173.077542: wakeup_preempt_entity <-check_preempt_wakeup
 ity.filemanager-713   [000] 10173.077544: calc_delta_mine <-wakeup_preempt_entity
 ity.filemanager-713   [000] 10173.077546: resched_task <-check_preempt_wakeup
 ity.filemanager-713   [000] 10173.077548: _raw_spin_unlock_irqrestore <-try_to_wake_up
 ity.filemanager-713   [000] 10173.077550: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077551: preempt_schedule <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077553: sub_preempt_count <-try_to_wake_up
 ity.filemanager-713   [000] 10173.077555: preempt_schedule <-try_to_wake_up
 ity.filemanager-713   [000] 10173.077556: _raw_spin_unlock_irqrestore <-ep_poll_callback
 ity.filemanager-713   [000] 10173.077558: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077560: preempt_schedule <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077562: _raw_spin_unlock_irqrestore <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.077564: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077566: preempt_schedule <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.077568: add_preempt_count <-preempt_schedule
 ity.filemanager-713   [000] 10173.077571: schedule <-preempt_schedule
 ity.filemanager-713   [000] 10173.077572: add_preempt_count <-schedule
 ity.filemanager-713   [000] 10173.077574: rcu_note_context_switch <-schedule
 ity.filemanager-713   [000] 10173.077576: rcu_sched_qs <-rcu_note_context_switch
 ity.filemanager-713   [000] 10173.077578: _raw_spin_lock_irq <-schedule
 ity.filemanager-713   [000] 10173.077579: add_preempt_count <-_raw_spin_lock_irq
 ity.filemanager-713   [000] 10173.077581: s5p_sched_timer_read <-sched_clock
 ity.filemanager-713   [000] 10173.077583: put_prev_task_fair <-schedule
 ity.filemanager-713   [000] 10173.077585: update_curr <-put_prev_task_fair
 ity.filemanager-713   [000] 10173.077587: update_min_vruntime <-update_curr
 ity.filemanager-713   [000] 10173.077588: cpuacct_charge <-update_curr
 ity.filemanager-713   [000] 10173.077590: add_preempt_count <-cpuacct_charge
 ity.filemanager-713   [000] 10173.077592: sub_preempt_count <-cpuacct_charge
 ity.filemanager-713   [000] 10173.077594: __enqueue_entity <-put_prev_task_fair
 ity.filemanager-713   [000] 10173.077596: pick_next_task_fair <-schedule
 ity.filemanager-713   [000] 10173.077598: __pick_next_entity <-pick_next_task_fair
 ity.filemanager-713   [000] 10173.077600: clear_buddies <-pick_next_task_fair
 ity.filemanager-713   [000] 10173.077601: set_next_entity <-pick_next_task_fair
 ity.filemanager-713   [000] 10173.077603: __dequeue_entity <-set_next_entity
 ity.filemanager-713   [000] 10173.077606: _raw_spin_unlock_irq <-schedule
 ity.filemanager-713   [000] 10173.077607: sub_preempt_count <-_raw_spin_unlock_irq
 ity.filemanager-713   [000] 10173.077611: atomic_notifier_call_chain <-__switch_to
 ity.filemanager-713   [000] 10173.077613: __atomic_notifier_call_chain <-atomic_notifier_call_chain
 ity.filemanager-713   [000] 10173.077615: add_preempt_count <-__atomic_notifier_call_chain
 ity.filemanager-713   [000] 10173.077619: notifier_call_chain <-__atomic_notifier_call_chain
 ity.filemanager-713   [000] 10173.077621: thumbee_notifier <-notifier_call_chain
 ity.filemanager-713   [000] 10173.077623: vfp_notifier <-notifier_call_chain
 ity.filemanager-713   [000] 10173.077624: sub_preempt_count <-__atomic_notifier_call_chain
 InputDispatcher-412   [000] 10173.077627: T.1196 <-schedule
 InputDispatcher-412   [000] 10173.077629: sub_preempt_count <-schedule
 InputDispatcher-412   [000] 10173.077632: _raw_spin_lock_irqsave <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077634: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.077637: _raw_spin_unlock_irqrestore <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077639: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.077641: ep_scan_ready_list <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077643: mutex_lock <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077646: __might_sleep <-mutex_lock
 InputDispatcher-412   [000] 10173.077648: __mutex_lock_slowpath <-mutex_lock
 InputDispatcher-412   [000] 10173.077650: add_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.077653: sub_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.077655: _raw_spin_lock_irqsave <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077658: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.077660: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077662: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.077664: ep_send_events_proc <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077667: pipe_poll <-ep_send_events_proc
 InputDispatcher-412   [000] 10173.077669: _raw_spin_lock_irqsave <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077672: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.077674: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077676: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.077678: mutex_unlock <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077680: __mutex_unlock_slowpath <-mutex_unlock
 InputDispatcher-412   [000] 10173.077684: fput <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077693: sys_clock_gettime <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.077696: posix_ktime_get_ts <-sys_clock_gettime
 InputDispatcher-412   [000] 10173.077698: ktime_get_ts <-posix_ktime_get_ts
 InputDispatcher-412   [000] 10173.077701: s5p_sched_timer_read <-ktime_get_ts
 InputDispatcher-412   [000] 10173.077703: set_normalized_timespec <-ktime_get_ts
 InputDispatcher-412   [000] 10173.077708: sys_read <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.077710: fget_light <-sys_read
 InputDispatcher-412   [000] 10173.077712: add_preempt_count <-fget_light
 InputDispatcher-412   [000] 10173.077715: sub_preempt_count <-fget_light
 InputDispatcher-412   [000] 10173.077717: vfs_read <-sys_read
 InputDispatcher-412   [000] 10173.077720: rw_verify_area <-vfs_read
 InputDispatcher-412   [000] 10173.077722: do_sync_read <-vfs_read
 InputDispatcher-412   [000] 10173.077724: pipe_read <-do_sync_read
 InputDispatcher-412   [000] 10173.077727: mutex_lock <-pipe_read
 InputDispatcher-412   [000] 10173.077729: __might_sleep <-mutex_lock
 InputDispatcher-412   [000] 10173.077731: __mutex_lock_slowpath <-mutex_lock
 InputDispatcher-412   [000] 10173.077733: add_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.077736: sub_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.077739: generic_pipe_buf_confirm <-pipe_read
 InputDispatcher-412   [000] 10173.077741: generic_pipe_buf_map <-pipe_read
 InputDispatcher-412   [000] 10173.077743: add_preempt_count <-generic_pipe_buf_map
 InputDispatcher-412   [000] 10173.077746: generic_pipe_buf_unmap <-pipe_read
 InputDispatcher-412   [000] 10173.077747: sub_preempt_count <-generic_pipe_buf_unmap
 InputDispatcher-412   [000] 10173.077750: anon_pipe_buf_release <-pipe_read
 InputDispatcher-412   [000] 10173.077752: mutex_unlock <-pipe_read
 InputDispatcher-412   [000] 10173.077754: __mutex_unlock_slowpath <-mutex_unlock
 InputDispatcher-412   [000] 10173.077757: __wake_up_sync <-pipe_read
 InputDispatcher-412   [000] 10173.077759: __wake_up_sync_key <-__wake_up_sync
 InputDispatcher-412   [000] 10173.077762: _raw_spin_lock_irqsave <-__wake_up_sync_key
 InputDispatcher-412   [000] 10173.077764: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.077766: __wake_up_common <-__wake_up_sync_key
 InputDispatcher-412   [000] 10173.077768: ep_poll_callback <-__wake_up_common
 InputDispatcher-412   [000] 10173.077770: _raw_spin_lock_irqsave <-ep_poll_callback
 InputDispatcher-412   [000] 10173.077772: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.077774: _raw_spin_unlock_irqrestore <-ep_poll_callback
 InputDispatcher-412   [000] 10173.077775: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.077777: _raw_spin_unlock_irqrestore <-__wake_up_sync_key
 InputDispatcher-412   [000] 10173.077779: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.077781: kill_fasync <-pipe_read
 InputDispatcher-412   [000] 10173.077784: touch_atime <-pipe_read
 InputDispatcher-412   [000] 10173.077786: current_fs_time <-touch_atime
 InputDispatcher-412   [000] 10173.077788: current_kernel_time <-current_fs_time
 InputDispatcher-412   [000] 10173.077790: timespec_trunc <-current_fs_time
 InputDispatcher-412   [000] 10173.077793: mnt_want_write <-touch_atime
 InputDispatcher-412   [000] 10173.077795: add_preempt_count <-mnt_want_write
 InputDispatcher-412   [000] 10173.077798: __mnt_is_readonly <-mnt_want_write
 InputDispatcher-412   [000] 10173.077799: sub_preempt_count <-mnt_want_write
 InputDispatcher-412   [000] 10173.077802: __mark_inode_dirty <-touch_atime
 InputDispatcher-412   [000] 10173.077804: mnt_drop_write <-touch_atime
 InputDispatcher-412   [000] 10173.077806: add_preempt_count <-mnt_drop_write
 InputDispatcher-412   [000] 10173.077808: sub_preempt_count <-mnt_drop_write
 InputDispatcher-412   [000] 10173.077811: inotify_inode_queue_event <-vfs_read
 InputDispatcher-412   [000] 10173.077813: __fsnotify_parent <-vfs_read
 InputDispatcher-412   [000] 10173.077815: inotify_dentry_parent_queue_event <-vfs_read
 InputDispatcher-412   [000] 10173.077818: fsnotify <-vfs_read
 InputDispatcher-412   [000] 10173.077820: fput <-sys_read
 InputDispatcher-412   [000] 10173.077826: sys_ioctl <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.077828: fget_light <-sys_ioctl
 InputDispatcher-412   [000] 10173.077830: add_preempt_count <-fget_light
 InputDispatcher-412   [000] 10173.077833: sub_preempt_count <-fget_light
 InputDispatcher-412   [000] 10173.077835: do_vfs_ioctl <-sys_ioctl
 InputDispatcher-412   [000] 10173.077838: vfs_ioctl <-do_vfs_ioctl
 InputDispatcher-412   [000] 10173.077840: ashmem_ioctl <-vfs_ioctl
 InputDispatcher-412   [000] 10173.077842: mutex_lock <-ashmem_ioctl
 InputDispatcher-412   [000] 10173.077844: __might_sleep <-mutex_lock
 InputDispatcher-412   [000] 10173.077847: __mutex_lock_slowpath <-mutex_lock
 InputDispatcher-412   [000] 10173.077849: add_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.077852: sub_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.077854: range_alloc <-ashmem_ioctl
 InputDispatcher-412   [000] 10173.077857: kmem_cache_alloc <-range_alloc
 InputDispatcher-412   [000] 10173.077859: __might_sleep <-kmem_cache_alloc
 InputDispatcher-412   [000] 10173.077864: mutex_unlock <-ashmem_ioctl
 InputDispatcher-412   [000] 10173.077866: __mutex_unlock_slowpath <-mutex_unlock
 InputDispatcher-412   [000] 10173.077869: fput <-sys_ioctl
 InputDispatcher-412   [000] 10173.077881: sys_clock_gettime <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.077883: posix_ktime_get_ts <-sys_clock_gettime
 InputDispatcher-412   [000] 10173.077886: ktime_get_ts <-posix_ktime_get_ts
 InputDispatcher-412   [000] 10173.077888: s5p_sched_timer_read <-ktime_get_ts
 InputDispatcher-412   [000] 10173.077890: set_normalized_timespec <-ktime_get_ts
 InputDispatcher-412   [000] 10173.077894: sys_clock_gettime <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.077896: posix_ktime_get_ts <-sys_clock_gettime
 InputDispatcher-412   [000] 10173.077899: ktime_get_ts <-posix_ktime_get_ts
 InputDispatcher-412   [000] 10173.077901: s5p_sched_timer_read <-ktime_get_ts
 InputDispatcher-412   [000] 10173.077903: set_normalized_timespec <-ktime_get_ts
 InputDispatcher-412   [000] 10173.077910: sys_epoll_wait <-ret_fast_syscall
 InputDispatcher-412   [000] 10173.077913: fget <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077915: add_preempt_count <-fget
 InputDispatcher-412   [000] 10173.077918: sub_preempt_count <-fget
 InputDispatcher-412   [000] 10173.077920: _raw_spin_lock_irqsave <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077923: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.077925: _raw_spin_unlock_irqrestore <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077927: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.077929: ep_scan_ready_list <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077932: mutex_lock <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077934: __might_sleep <-mutex_lock
 InputDispatcher-412   [000] 10173.077936: __mutex_lock_slowpath <-mutex_lock
 InputDispatcher-412   [000] 10173.077938: add_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.077941: sub_preempt_count <-__mutex_lock_slowpath
 InputDispatcher-412   [000] 10173.077944: _raw_spin_lock_irqsave <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077946: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.077948: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077950: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.077952: ep_send_events_proc <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077955: pipe_poll <-ep_send_events_proc
 InputDispatcher-412   [000] 10173.077957: _raw_spin_lock_irqsave <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077959: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.077962: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077964: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.077966: mutex_unlock <-ep_scan_ready_list
 InputDispatcher-412   [000] 10173.077968: __mutex_unlock_slowpath <-mutex_unlock
 InputDispatcher-412   [000] 10173.077971: _raw_spin_lock_irqsave <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077974: add_preempt_count <-_raw_spin_lock_irqsave
 InputDispatcher-412   [000] 10173.077976: _raw_spin_unlock_irqrestore <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077978: sub_preempt_count <-_raw_spin_unlock_irqrestore
 InputDispatcher-412   [000] 10173.077980: schedule_hrtimeout_range <-sys_epoll_wait
 InputDispatcher-412   [000] 10173.077982: schedule_hrtimeout_range_clock <-schedule_hrtimeout_range
 InputDispatcher-412   [000] 10173.077984: schedule <-schedule_hrtimeout_range_clock
 InputDispatcher-412   [000] 10173.077987: add_preempt_count <-schedule
 InputDispatcher-412   [000] 10173.077989: rcu_note_context_switch <-schedule
 InputDispatcher-412   [000] 10173.077991: rcu_sched_qs <-rcu_note_context_switch
 InputDispatcher-412   [000] 10173.077992: _raw_spin_lock_irq <-schedule
 InputDispatcher-412   [000] 10173.077994: add_preempt_count <-_raw_spin_lock_irq
 InputDispatcher-412   [000] 10173.077996: T.1190 <-schedule
 InputDispatcher-412   [000] 10173.077998: dequeue_task <-T.1190
 InputDispatcher-412   [000] 10173.078000: s5p_sched_timer_read <-sched_clock
 InputDispatcher-412   [000] 10173.078002: dequeue_task_fair <-dequeue_task
 InputDispatcher-412   [000] 10173.078003: dequeue_entity <-dequeue_task_fair
 InputDispatcher-412   [000] 10173.078005: update_curr <-dequeue_entity
 InputDispatcher-412   [000] 10173.078007: calc_delta_mine <-update_curr
 InputDispatcher-412   [000] 10173.078009: update_min_vruntime <-update_curr
 InputDispatcher-412   [000] 10173.078010: cpuacct_charge <-update_curr
 InputDispatcher-412   [000] 10173.078012: add_preempt_count <-cpuacct_charge
 InputDispatcher-412   [000] 10173.078014: sub_preempt_count <-cpuacct_charge
 InputDispatcher-412   [000] 10173.078016: clear_buddies <-dequeue_entity
 InputDispatcher-412   [000] 10173.078018: update_min_vruntime <-dequeue_entity
 InputDispatcher-412   [000] 10173.078020: put_prev_task_fair <-schedule
 InputDispatcher-412   [000] 10173.078021: pick_next_task_fair <-schedule
 InputDispatcher-412   [000] 10173.078023: __pick_next_entity <-pick_next_task_fair
 InputDispatcher-412   [000] 10173.078025: clear_buddies <-pick_next_task_fair
 InputDispatcher-412   [000] 10173.078026: set_next_entity <-pick_next_task_fair
 InputDispatcher-412   [000] 10173.078028: __dequeue_entity <-set_next_entity
 InputDispatcher-412   [000] 10173.078033: _raw_spin_unlock_irq <-schedule
 InputDispatcher-412   [000] 10173.078035: sub_preempt_count <-_raw_spin_unlock_irq
 InputDispatcher-412   [000] 10173.078039: atomic_notifier_call_chain <-__switch_to
 InputDispatcher-412   [000] 10173.078040: __atomic_notifier_call_chain <-atomic_notifier_call_chain
 InputDispatcher-412   [000] 10173.078042: add_preempt_count <-__atomic_notifier_call_chain
 InputDispatcher-412   [000] 10173.078044: notifier_call_chain <-__atomic_notifier_call_chain
 InputDispatcher-412   [000] 10173.078046: thumbee_notifier <-notifier_call_chain
 InputDispatcher-412   [000] 10173.078047: vfp_notifier <-notifier_call_chain
 InputDispatcher-412   [000] 10173.078049: sub_preempt_count <-__atomic_notifier_call_chain
 ity.filemanager-713   [000] 10173.078051: T.1196 <-schedule
 ity.filemanager-713   [000] 10173.078053: sub_preempt_count <-schedule
 ity.filemanager-713   [000] 10173.078055: sub_preempt_count <-preempt_schedule
 ity.filemanager-713   [000] 10173.078057: kill_fasync <-pipe_write
 ity.filemanager-713   [000] 10173.078059: file_update_time <-pipe_write
 ity.filemanager-713   [000] 10173.078062: current_fs_time <-file_update_time
 ity.filemanager-713   [000] 10173.078064: current_kernel_time <-current_fs_time
 ity.filemanager-713   [000] 10173.078066: timespec_trunc <-current_fs_time
 ity.filemanager-713   [000] 10173.078069: mnt_want_write_file <-file_update_time
 ity.filemanager-713   [000] 10173.078071: mnt_want_write <-mnt_want_write_file
 ity.filemanager-713   [000] 10173.078073: add_preempt_count <-mnt_want_write
 ity.filemanager-713   [000] 10173.078075: __mnt_is_readonly <-mnt_want_write
 ity.filemanager-713   [000] 10173.078077: sub_preempt_count <-mnt_want_write
 ity.filemanager-713   [000] 10173.078079: __mark_inode_dirty <-file_update_time
 ity.filemanager-713   [000] 10173.078082: mnt_drop_write <-file_update_time
 ity.filemanager-713   [000] 10173.078084: add_preempt_count <-mnt_drop_write
 ity.filemanager-713   [000] 10173.078086: sub_preempt_count <-mnt_drop_write
 ity.filemanager-713   [000] 10173.078089: inotify_inode_queue_event <-vfs_write
 ity.filemanager-713   [000] 10173.078091: __fsnotify_parent <-vfs_write
 ity.filemanager-713   [000] 10173.078093: inotify_dentry_parent_queue_event <-vfs_write
 ity.filemanager-713   [000] 10173.078096: fsnotify <-vfs_write
 ity.filemanager-713   [000] 10173.078098: fput <-sys_write
 ity.filemanager-713   [000] 10173.078110: sys_getpid <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.078112: pid_vnr <-sys_getpid
 ity.filemanager-713   [000] 10173.078115: pid_nr_ns <-pid_vnr
 ity.filemanager-713   [000] 10173.078118: sys_getuid <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.078129: sys_epoll_wait <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.078132: fget <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078134: add_preempt_count <-fget
 ity.filemanager-713   [000] 10173.078137: sub_preempt_count <-fget
 ity.filemanager-713   [000] 10173.078139: _raw_spin_lock_irqsave <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078142: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.078144: _raw_spin_unlock_irqrestore <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078146: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.078148: ep_scan_ready_list <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078151: mutex_lock <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078153: __might_sleep <-mutex_lock
 ity.filemanager-713   [000] 10173.078155: __mutex_lock_slowpath <-mutex_lock
 ity.filemanager-713   [000] 10173.078157: add_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.078160: sub_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.078163: _raw_spin_lock_irqsave <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078165: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.078167: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078169: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.078171: ep_send_events_proc <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078174: pipe_poll <-ep_send_events_proc
 ity.filemanager-713   [000] 10173.078176: pipe_poll <-ep_send_events_proc
 ity.filemanager-713   [000] 10173.078179: _raw_spin_lock_irqsave <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078181: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.078183: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078185: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.078187: mutex_unlock <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078190: __mutex_unlock_slowpath <-mutex_unlock
 ity.filemanager-713   [000] 10173.078193: fput <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078197: sys_read <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.078199: fget_light <-sys_read
 ity.filemanager-713   [000] 10173.078201: add_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.078203: sub_preempt_count <-fget_light
 ity.filemanager-713   [000] 10173.078205: vfs_read <-sys_read
 ity.filemanager-713   [000] 10173.078208: rw_verify_area <-vfs_read
 ity.filemanager-713   [000] 10173.078210: do_sync_read <-vfs_read
 ity.filemanager-713   [000] 10173.078212: pipe_read <-do_sync_read
 ity.filemanager-713   [000] 10173.078215: mutex_lock <-pipe_read
 ity.filemanager-713   [000] 10173.078217: __might_sleep <-mutex_lock
 ity.filemanager-713   [000] 10173.078219: __mutex_lock_slowpath <-mutex_lock
 ity.filemanager-713   [000] 10173.078221: add_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.078224: sub_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.078226: generic_pipe_buf_confirm <-pipe_read
 ity.filemanager-713   [000] 10173.078229: generic_pipe_buf_map <-pipe_read
 ity.filemanager-713   [000] 10173.078231: add_preempt_count <-generic_pipe_buf_map
 ity.filemanager-713   [000] 10173.078233: generic_pipe_buf_unmap <-pipe_read
 ity.filemanager-713   [000] 10173.078235: sub_preempt_count <-generic_pipe_buf_unmap
 ity.filemanager-713   [000] 10173.078237: anon_pipe_buf_release <-pipe_read
 ity.filemanager-713   [000] 10173.078240: mutex_unlock <-pipe_read
 ity.filemanager-713   [000] 10173.078242: __mutex_unlock_slowpath <-mutex_unlock
 ity.filemanager-713   [000] 10173.078245: __wake_up_sync <-pipe_read
 ity.filemanager-713   [000] 10173.078247: __wake_up_sync_key <-__wake_up_sync
 ity.filemanager-713   [000] 10173.078249: _raw_spin_lock_irqsave <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.078252: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.078254: __wake_up_common <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.078256: ep_poll_callback <-__wake_up_common
 ity.filemanager-713   [000] 10173.078258: _raw_spin_lock_irqsave <-ep_poll_callback
 ity.filemanager-713   [000] 10173.078259: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.078261: _raw_spin_unlock_irqrestore <-ep_poll_callback
 ity.filemanager-713   [000] 10173.078263: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.078265: _raw_spin_unlock_irqrestore <-__wake_up_sync_key
 ity.filemanager-713   [000] 10173.078267: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.078269: kill_fasync <-pipe_read
 ity.filemanager-713   [000] 10173.078271: touch_atime <-pipe_read
 ity.filemanager-713   [000] 10173.078273: current_fs_time <-touch_atime
 ity.filemanager-713   [000] 10173.078276: current_kernel_time <-current_fs_time
 ity.filemanager-713   [000] 10173.078278: timespec_trunc <-current_fs_time
 ity.filemanager-713   [000] 10173.078280: mnt_want_write <-touch_atime
 ity.filemanager-713   [000] 10173.078283: add_preempt_count <-mnt_want_write
 ity.filemanager-713   [000] 10173.078285: __mnt_is_readonly <-mnt_want_write
 ity.filemanager-713   [000] 10173.078287: sub_preempt_count <-mnt_want_write
 ity.filemanager-713   [000] 10173.078289: __mark_inode_dirty <-touch_atime
 ity.filemanager-713   [000] 10173.078291: mnt_drop_write <-touch_atime
 ity.filemanager-713   [000] 10173.078293: add_preempt_count <-mnt_drop_write
 ity.filemanager-713   [000] 10173.078296: sub_preempt_count <-mnt_drop_write
 ity.filemanager-713   [000] 10173.078298: inotify_inode_queue_event <-vfs_read
 ity.filemanager-713   [000] 10173.078301: __fsnotify_parent <-vfs_read
 ity.filemanager-713   [000] 10173.078303: inotify_dentry_parent_queue_event <-vfs_read
 ity.filemanager-713   [000] 10173.078305: fsnotify <-vfs_read
 ity.filemanager-713   [000] 10173.078307: fput <-sys_read
 ity.filemanager-713   [000] 10173.078312: sys_clock_gettime <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.078315: posix_ktime_get_ts <-sys_clock_gettime
 ity.filemanager-713   [000] 10173.078317: ktime_get_ts <-posix_ktime_get_ts
 ity.filemanager-713   [000] 10173.078319: s5p_sched_timer_read <-ktime_get_ts
 ity.filemanager-713   [000] 10173.078322: set_normalized_timespec <-ktime_get_ts
 ity.filemanager-713   [000] 10173.078333: sys_epoll_wait <-ret_fast_syscall
 ity.filemanager-713   [000] 10173.078336: fget <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078338: add_preempt_count <-fget
 ity.filemanager-713   [000] 10173.078341: sub_preempt_count <-fget
 ity.filemanager-713   [000] 10173.078343: _raw_spin_lock_irqsave <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078346: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.078348: _raw_spin_unlock_irqrestore <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078350: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.078352: ep_scan_ready_list <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078355: mutex_lock <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078357: __might_sleep <-mutex_lock
 ity.filemanager-713   [000] 10173.078359: __mutex_lock_slowpath <-mutex_lock
 ity.filemanager-713   [000] 10173.078361: add_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.078364: sub_preempt_count <-__mutex_lock_slowpath
 ity.filemanager-713   [000] 10173.078366: _raw_spin_lock_irqsave <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078369: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.078371: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078373: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.078375: ep_send_events_proc <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078377: pipe_poll <-ep_send_events_proc
 ity.filemanager-713   [000] 10173.078380: _raw_spin_lock_irqsave <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078382: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.078384: _raw_spin_unlock_irqrestore <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078386: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.078389: mutex_unlock <-ep_scan_ready_list
 ity.filemanager-713   [000] 10173.078391: __mutex_unlock_slowpath <-mutex_unlock
 ity.filemanager-713   [000] 10173.078394: _raw_spin_lock_irqsave <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078396: add_preempt_count <-_raw_spin_lock_irqsave
 ity.filemanager-713   [000] 10173.078399: _raw_spin_unlock_irqrestore <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078401: sub_preempt_count <-_raw_spin_unlock_irqrestore
 ity.filemanager-713   [000] 10173.078403: schedule_hrtimeout_range <-sys_epoll_wait
 ity.filemanager-713   [000] 10173.078405: schedule_hrtimeout_range_clock <-schedule_hrtimeout_range
 ity.filemanager-713   [000] 10173.078407: schedule <-schedule_hrtimeout_range_clock
 ity.filemanager-713   [000] 10173.078409: add_preempt_count <-schedule
 ity.filemanager-713   [000] 10173.078412: rcu_note_context_switch <-schedule
 ity.filemanager-713   [000] 10173.078413: rcu_sched_qs <-rcu_note_context_switch
 ity.filemanager-713   [000] 10173.078415: _raw_spin_lock_irq <-schedule
 ity.filemanager-713   [000] 10173.078417: add_preempt_count <-_raw_spin_lock_irq
 ity.filemanager-713   [000] 10173.078419: T.1190 <-schedule
 ity.filemanager-713   [000] 10173.078420: dequeue_task <-T.1190
 ity.filemanager-713   [000] 10173.078422: s5p_sched_timer_read <-sched_clock
 ity.filemanager-713   [000] 10173.078424: dequeue_task_fair <-dequeue_task
 ity.filemanager-713   [000] 10173.078426: dequeue_entity <-dequeue_task_fair
 ity.filemanager-713   [000] 10173.078428: update_curr <-dequeue_entity
 ity.filemanager-713   [000] 10173.078429: update_min_vruntime <-update_curr
 ity.filemanager-713   [000] 10173.078431: cpuacct_charge <-update_curr
 ity.filemanager-713   [000] 10173.078433: add_preempt_count <-cpuacct_charge
 ity.filemanager-713   [000] 10173.078435: sub_preempt_count <-cpuacct_charge
 ity.filemanager-713   [000] 10173.078436: clear_buddies <-dequeue_entity
 ity.filemanager-713   [000] 10173.078438: update_min_vruntime <-dequeue_entity
 ity.filemanager-713   [000] 10173.078440: put_prev_task_fair <-schedule
 ity.filemanager-713   [000] 10173.078444: pick_next_task_fair <-schedule
 ity.filemanager-713   [000] 10173.078446: __pick_next_entity <-pick_next_task_fair
 ity.filemanager-713   [000] 10173.078448: clear_buddies <-pick_next_task_fair
 ity.filemanager-713   [000] 10173.078449: set_next_entity <-pick_next_task_fair
 ity.filemanager-713   [000] 10173.078451: __dequeue_entity <-set_next_entity
 ity.filemanager-713   [000] 10173.078453: _raw_spin_unlock_irq <-schedule
 ity.filemanager-713   [000] 10173.078455: sub_preempt_count <-_raw_spin_unlock_irq
 ity.filemanager-713   [000] 10173.078458: atomic_notifier_call_chain <-__switch_to
 ity.filemanager-713   [000] 10173.078460: __atomic_notifier_call_chain <-atomic_notifier_call_chain
 ity.filemanager-713   [000] 10173.078462: add_preempt_count <-__atomic_notifier_call_chain
 ity.filemanager-713   [000] 10173.078463: notifier_call_chain <-__atomic_notifier_call_chain
 ity.filemanager-713   [000] 10173.078465: thumbee_notifier <-notifier_call_chain
 ity.filemanager-713   [000] 10173.078467: vfp_notifier <-notifier_call_chain
 ity.filemanager-713   [000] 10173.078469: sub_preempt_count <-__atomic_notifier_call_chain
        events/0-5     [000] 10173.078472: T.1196 <-schedule
        events/0-5     [000] 10173.078474: sub_preempt_count <-schedule
        events/0-5     [000] 10173.078476: sub_preempt_count <-preempt_schedule
        events/0-5     [000] 10173.078479: _raw_spin_lock_irq <-worker_thread
        events/0-5     [000] 10173.078481: add_preempt_count <-_raw_spin_lock_irq
        events/0-5     [000] 10173.078484: _raw_spin_lock_irqsave <-probe_workqueue_execution
        events/0-5     [000] 10173.078486: add_preempt_count <-_raw_spin_lock_irqsave
        events/0-5     [000] 10173.078488: _raw_spin_unlock_irqrestore <-probe_workqueue_execution
        events/0-5     [000] 10173.078490: sub_preempt_count <-_raw_spin_unlock_irqrestore
        events/0-5     [000] 10173.078491: _raw_spin_unlock_irq <-worker_thread
        events/0-5     [000] 10173.078493: sub_preempt_count <-_raw_spin_unlock_irq
        events/0-5     [000] 10173.078495: a700_ts_poscheck <-worker_thread
        events/0-5     [000] 10173.078498: __gpio_get_value <-a700_ts_poscheck
        events/0-5     [000] 10173.078500: s3c_gpiolib_get <-__gpio_get_value
        events/0-5     [000] 10173.078503: i2c_master_recv <-a700_ts_poscheck
        events/0-5     [000] 10173.078506: i2c_transfer <-i2c_master_recv
        events/0-5     [000] 10173.078508: rt_mutex_lock <-i2c_transfer
        events/0-5     [000] 10173.078511: __might_sleep <-rt_mutex_lock
        events/0-5     [000] 10173.078513: rt_mutex_slowlock <-rt_mutex_lock
        events/0-5     [000] 10173.078516: _raw_spin_lock <-rt_mutex_slowlock
        events/0-5     [000] 10173.078518: add_preempt_count <-_raw_spin_lock
        events/0-5     [000] 10173.078520: try_to_take_rt_mutex <-rt_mutex_slowlock
        events/0-5     [000] 10173.078522: rt_mutex_set_owner <-try_to_take_rt_mutex
        events/0-5     [000] 10173.078524: _raw_spin_unlock <-rt_mutex_slowlock
        events/0-5     [000] 10173.078526: sub_preempt_count <-_raw_spin_unlock
        events/0-5     [000] 10173.078528: s3c24xx_i2c_xfer <-i2c_transfer
        events/0-5     [000] 10173.078531: clk_enable <-s3c24xx_i2c_xfer
        events/0-5     [000] 10173.078533: clk_enable <-clk_enable
        events/0-5     [000] 10173.078535: clk_enable <-clk_enable
        events/0-5     [000] 10173.078537: clk_enable <-clk_enable
        events/0-5     [000] 10173.078540: clk_enable <-clk_enable
        events/0-5     [000] 10173.078542: clk_enable <-clk_enable
        events/0-5     [000] 10173.078544: _raw_spin_lock <-clk_enable
        events/0-5     [000] 10173.078546: add_preempt_count <-_raw_spin_lock
        events/0-5     [000] 10173.078549: _raw_spin_unlock <-clk_enable
        events/0-5     [000] 10173.078550: sub_preempt_count <-_raw_spin_unlock
        events/0-5     [000] 10173.078553: _raw_spin_lock <-clk_enable
        events/0-5     [000] 10173.078555: add_preempt_count <-_raw_spin_lock
        events/0-5     [000] 10173.078557: _raw_spin_unlock <-clk_enable
        events/0-5     [000] 10173.078559: sub_preempt_count <-_raw_spin_unlock
        events/0-5     [000] 10173.078561: _raw_spin_lock <-clk_enable
        events/0-5     [000] 10173.078563: add_preempt_count <-_raw_spin_lock
        events/0-5     [000] 10173.078566: _raw_spin_unlock <-clk_enable
        events/0-5     [000] 10173.078568: sub_preempt_count <-_raw_spin_unlock
        events/0-5     [000] 10173.078570: _raw_spin_lock <-clk_enable
        events/0-5     [000] 10173.078572: add_preempt_count <-_raw_spin_lock
        events/0-5     [000] 10173.078574: _raw_spin_unlock <-clk_enable
        events/0-5     [000] 10173.078576: sub_preempt_count <-_raw_spin_unlock
        events/0-5     [000] 10173.078578: _raw_spin_lock <-clk_enable
        events/0-5     [000] 10173.078580: add_preempt_count <-_raw_spin_lock
        events/0-5     [000] 10173.078583: s5pv210_clk_ip3_ctrl <-clk_enable
        events/0-5     [000] 10173.078585: s5p_gatectrl <-s5pv210_clk_ip3_ctrl
        events/0-5     [000] 10173.078587: _raw_spin_unlock <-clk_enable
        events/0-5     [000] 10173.078588: sub_preempt_count <-_raw_spin_unlock
        events/0-5     [000] 10173.078591: _raw_spin_lock_irq <-s3c24xx_i2c_xfer
        events/0-5     [000] 10173.078594: add_preempt_count <-_raw_spin_lock_irq
        events/0-5     [000] 10173.078596: s3c24xx_i2c_message_start <-s3c24xx_i2c_xfer
        events/0-5     [000] 10173.078601: _raw_spin_unlock_irq <-s3c24xx_i2c_xfer
        events/0-5     [000] 10173.078602: sub_preempt_count <-_raw_spin_unlock_irq
        events/0-5     [000] 10173.078605: prepare_to_wait <-s3c24xx_i2c_xfer
        events/0-5     [000] 10173.078607: _raw_spin_lock_irqsave <-prepare_to_wait
        events/0-5     [000] 10173.078609: add_preempt_count <-_raw_spin_lock_irqsave
        events/0-5     [000] 10173.078612: _raw_spin_unlock_irqrestore <-prepare_to_wait
        events/0-5     [000] 10173.078614: sub_preempt_count <-_raw_spin_unlock_irqrestore
        events/0-5     [000] 10173.078616: schedule_timeout <-s3c24xx_i2c_xfer
        events/0-5     [000] 10173.078618: init_timer_key <-schedule_timeout
        events/0-5     [000] 10173.078621: lock_timer_base <-schedule_timeout
        events/0-5     [000] 10173.078623: _raw_spin_lock_irqsave <-lock_timer_base
        events/0-5     [000] 10173.078626: add_preempt_count <-_raw_spin_lock_irqsave
        events/0-5     [000] 10173.078628: internal_add_timer <-schedule_timeout
        events/0-5     [000] 10173.078630: _raw_spin_unlock_irqrestore <-schedule_timeout
        events/0-5     [000] 10173.078632: sub_preempt_count <-_raw_spin_unlock_irqrestore
        events/0-5     [000] 10173.078635: schedule <-schedule_timeout
        events/0-5     [000] 10173.078637: add_preempt_count <-schedule
        events/0-5     [000] 10173.078639: rcu_note_context_switch <-schedule
        events/0-5     [000] 10173.078641: rcu_sched_qs <-rcu_note_context_switch
        events/0-5     [000] 10173.078642: _raw_spin_lock_irq <-schedule
        events/0-5     [000] 10173.078644: add_preempt_count <-_raw_spin_lock_irq
        events/0-5     [000] 10173.078646: T.1190 <-schedule
        events/0-5     [000] 10173.078648: dequeue_task <-T.1190
        events/0-5     [000] 10173.078650: s5p_sched_timer_read <-sched_clock
        events/0-5     [000] 10173.078652: dequeue_task_fair <-dequeue_task
        events/0-5     [000] 10173.078653: dequeue_entity <-dequeue_task_fair
        events/0-5     [000] 10173.078655: update_curr <-dequeue_entity
        events/0-5     [000] 10173.078657: update_min_vruntime <-update_curr
        events/0-5     [000] 10173.078658: cpuacct_charge <-update_curr
        events/0-5     [000] 10173.078660: add_preempt_count <-cpuacct_charge
        events/0-5     [000] 10173.078662: sub_preempt_count <-cpuacct_charge
        events/0-5     [000] 10173.078664: clear_buddies <-dequeue_entity
        events/0-5     [000] 10173.078666: update_min_vruntime <-dequeue_entity
        events/0-5     [000] 10173.078667: put_prev_task_fair <-schedule
        events/0-5     [000] 10173.078669: pick_next_task_fair <-schedule
        events/0-5     [000] 10173.078671: pick_next_task_rt <-schedule
        events/0-5     [000] 10173.078673: pick_next_task_fair <-schedule
        events/0-5     [000] 10173.078675: pick_next_task_idle <-schedule
        events/0-5     [000] 10173.078677: calc_load_fold_active <-pick_next_task_idle
        events/0-5     [000] 10173.078679: _raw_spin_unlock_irq <-schedule
        events/0-5     [000] 10173.078680: sub_preempt_count <-_raw_spin_unlock_irq
        events/0-5     [000] 10173.078683: atomic_notifier_call_chain <-__switch_to
        events/0-5     [000] 10173.078685: __atomic_notifier_call_chain <-atomic_notifier_call_chain
        events/0-5     [000] 10173.078686: add_preempt_count <-__atomic_notifier_call_chain
        events/0-5     [000] 10173.078688: notifier_call_chain <-__atomic_notifier_call_chain
        events/0-5     [000] 10173.078690: thumbee_notifier <-notifier_call_chain
        events/0-5     [000] 10173.078691: vfp_notifier <-notifier_call_chain
        events/0-5     [000] 10173.078693: sub_preempt_count <-__atomic_notifier_call_chain
          <idle>-0     [000] 10173.078695: T.1196 <-schedule
          <idle>-0     [000] 10173.078697: sub_preempt_count <-schedule
          <idle>-0     [000] 10173.078700: add_preempt_count <-cpu_idle
          <idle>-0     [000] 10173.078702: tick_nohz_stop_sched_tick <-cpu_idle
          <idle>-0     [000] 10173.078705: ktime_get <-tick_nohz_stop_sched_tick
          <idle>-0     [000] 10173.078706: s5p_sched_timer_read <-ktime_get
          <idle>-0     [000] 10173.078709: ktime_add_ns <-ktime_get

# cat trace
# tracer: irqsoff
#
Binder T-600     0d....    1us!: ret_slow_syscall <-trace_hardirqs_off
Binder T-600     0d..1.  106us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1.  108us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1.  109us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1.  111us+: idle_cpu <-irq_enter
Binder T-600     0d..1.  113us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1.  115us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1.  117us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1.  119us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  120us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  122us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2.  124us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2.  126us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2.  128us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2.  130us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  132us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  133us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1.  135us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1.  139us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1.  140us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  142us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  144us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2.  146us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2.  148us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  150us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  151us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1.  153us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2.  155us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2.  157us+: idle_cpu <-irq_exit
Binder T-600     0d..2.  159us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1.  273us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1.  275us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1.  277us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1.  279us+: idle_cpu <-irq_enter
Binder T-600     0d..1.  281us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1.  283us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1.  285us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1.  286us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  288us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  290us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2.  292us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2.  294us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2.  296us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2.  298us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  299us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  301us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1.  303us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1.  306us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1.  308us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  310us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  312us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2.  314us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2.  315us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  317us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  319us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1.  321us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2.  323us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2.  325us+: idle_cpu <-irq_exit
Binder T-600     0d..2.  327us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1.  441us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1.  443us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1.  445us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1.  447us+: idle_cpu <-irq_enter
Binder T-600     0d..1.  449us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1.  451us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1.  453us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1.  455us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  456us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  458us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2.  460us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2.  462us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2.  464us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2.  466us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  468us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  469us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1.  474us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1.  477us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1.  479us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  481us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  483us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2.  485us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2.  487us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  489us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  490us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1.  492us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2.  494us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2.  496us+: idle_cpu <-irq_exit
Binder T-600     0d..2.  498us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1.  613us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1.  615us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1.  617us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1.  618us+: idle_cpu <-irq_enter
Binder T-600     0d..1.  620us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1.  622us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1.  624us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1.  626us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  627us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  629us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2.  631us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2.  633us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2.  635us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2.  637us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  639us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  641us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1.  642us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1.  646us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1.  647us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  649us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  651us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2.  653us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2.  655us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  657us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  658us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1.  660us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2.  662us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2.  664us+: idle_cpu <-irq_exit
Binder T-600     0d..2.  666us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1.  781us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1.  783us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1.  785us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1.  787us+: idle_cpu <-irq_enter
Binder T-600     0d..1.  788us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1.  790us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1.  792us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1.  794us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  795us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  797us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2.  799us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2.  801us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2.  803us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2.  805us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  807us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  809us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1.  810us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1.  813us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1.  815us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  817us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  819us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2.  821us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2.  823us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  824us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  826us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1.  828us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2.  830us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2.  832us+: idle_cpu <-irq_exit
Binder T-600     0d..2.  834us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1.  949us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1.  951us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1.  953us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1.  954us+: idle_cpu <-irq_enter
Binder T-600     0d..1.  956us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1.  958us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1.  960us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1.  962us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  963us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  965us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2.  967us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2.  969us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2.  971us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2.  973us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  975us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  977us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1.  978us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1.  982us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1.  983us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1.  985us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2.  987us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2.  989us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2.  991us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2.  993us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1.  995us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1.  996us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2.  998us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 1000us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 1002us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 1116us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 1118us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 1120us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 1122us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 1124us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 1126us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 1128us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 1130us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1131us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1133us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 1135us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 1137us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 1139us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 1141us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1143us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1144us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 1146us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 1149us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 1151us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1153us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1155us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 1157us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 1159us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1160us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1162us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 1164us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 1166us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 1168us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 1170us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 1284us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 1286us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 1288us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 1290us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 1292us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 1294us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 1296us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 1297us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1299us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1301us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 1303us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 1305us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 1307us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 1309us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1311us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1312us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 1314us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 1317us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 1319us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1321us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1323us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 1325us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 1327us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1328us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1330us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 1332us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 1334us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 1336us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 1338us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 1452us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 1454us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 1456us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 1458us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 1460us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 1462us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 1464us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 1465us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1467us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1469us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 1471us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 1473us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 1477us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 1480us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1481us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1483us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 1485us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 1488us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 1490us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1492us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1494us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 1496us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 1497us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1499us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1501us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 1503us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 1505us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 1507us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 1508us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 1623us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 1625us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 1627us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 1629us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 1631us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 1633us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 1634us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 1636us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1638us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1640us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 1641us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 1643us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 1645us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 1647us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1649us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1651us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 1653us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 1656us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 1658us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1660us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1661us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 1663us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 1665us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1667us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1669us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 1671us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 1673us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 1674us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 1676us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 1791us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 1793us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 1795us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 1797us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 1799us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 1801us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 1803us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 1804us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1806us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1809us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 1810us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 1812us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 1814us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 1816us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1818us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1820us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 1822us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 1825us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 1827us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1828us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1830us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 1832us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 1834us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1836us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1838us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 1839us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 1841us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 1843us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 1845us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 1960us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 1962us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 1964us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 1966us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 1967us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 1969us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 1971us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 1973us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1974us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1977us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 1978us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 1980us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 1982us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 1984us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 1986us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 1988us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 1989us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 1993us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 1995us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 1997us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 1999us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 2000us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 2002us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2004us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2006us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 2008us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 2010us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 2012us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 2014us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 2128us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 2130us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 2132us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 2134us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 2136us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 2138us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 2140us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 2141us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2143us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2145us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 2147us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 2149us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 2151us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 2153us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2155us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2156us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 2158us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 2161us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 2163us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2165us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2167us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 2169us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 2171us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2172us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2174us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 2176us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 2178us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 2180us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 2181us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 2297us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 2299us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 2301us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 2302us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 2304us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 2306us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 2308us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 2310us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2311us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2313us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 2315us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 2317us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 2319us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 2321us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2322us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2325us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 2326us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 2329us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 2331us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2333us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2335us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 2337us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 2338us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2340us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2342us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 2344us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 2346us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 2348us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 2350us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 2465us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 2467us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 2469us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 2470us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 2472us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 2474us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 2476us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 2478us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2482us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2485us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 2486us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 2488us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 2490us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 2492us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2494us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2496us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 2498us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 2501us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 2503us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2504us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2506us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 2508us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 2510us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2512us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2514us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 2516us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 2517us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 2519us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 2521us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 2636us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 2638us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 2640us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 2641us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 2643us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 2645us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 2647us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 2649us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2650us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2653us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 2654us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 2656us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 2658us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 2660us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2662us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2664us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 2665us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 2669us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 2670us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2672us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2674us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 2676us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 2678us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2680us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2681us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 2683us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 2685us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 2687us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 2689us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 2803us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 2805us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 2807us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 2809us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 2811us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 2813us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 2815us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 2816us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2818us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2820us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 2822us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 2824us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 2825us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 2827us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2829us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2831us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 2833us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 2836us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 2838us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2839us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2841us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 2843us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 2845us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2847us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2849us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 2850us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 2852us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 2854us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 2856us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 2971us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 2972us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 2974us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 2976us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 2978us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 2980us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 2982us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 2984us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 2985us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 2987us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 2989us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 2991us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 2993us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 2995us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 2997us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 2999us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 3000us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 3003us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 3005us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 3007us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 3009us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 3011us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 3013us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 3015us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 3016us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 3018us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 3020us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 3022us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 3023us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 3138us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 3140us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 3142us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 3144us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 3146us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 3148us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 3149us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 3151us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 3153us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 3155us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 3157us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 3159us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 3160us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 3163us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 3164us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 3166us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 3168us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 3172us+: note_interrupt <-handle_level_irq
Binder T-600     0d.h1. 3174us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 3176us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 3177us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0d.h2. 3179us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0d.h2. 3181us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 3183us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 3185us+: irq_exit <-asm_do_IRQ
Binder T-600     0d.h1. 3187us+: sub_preempt_count <-irq_exit
Binder T-600     0d..2. 3189us+: rcu_irq_exit <-irq_exit
Binder T-600     0d..2. 3190us+: idle_cpu <-irq_exit
Binder T-600     0d..2. 3192us!: sub_preempt_count <-irq_exit
Binder T-600     0d..1. 3307us+: asm_do_IRQ <-__irq_usr
Binder T-600     0d..1. 3309us+: irq_enter <-asm_do_IRQ
Binder T-600     0d..1. 3311us+: rcu_irq_enter <-irq_enter
Binder T-600     0d..1. 3313us+: idle_cpu <-irq_enter
Binder T-600     0d..1. 3315us+: add_preempt_count <-irq_enter
Binder T-600     0d.h1. 3317us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0d.h1. 3318us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0d.h1. 3320us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0d.h1. 3322us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h2. 3324us+: vic_mask_irq <-handle_level_irq
Binder T-600     0d.h2. 3326us+: irq_to_desc <-vic_mask_irq
Binder T-600     0d.h2. 3328us+: vic_ack_irq <-handle_level_irq
Binder T-600     0d.h2. 3329us+: irq_to_desc <-vic_ack_irq
Binder T-600     0d.h2. 3332us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0d.h2. 3333us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0d.h1. 3335us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0d.h1. 3337us+: s3c24xx_i2c_irq <-handle_IRQ_event
Binder T-600     0d.h1. 3340us+: __wake_up <-s3c24xx_i2c_irq
Binder T-600     0d.h1. 3342us+: _raw_spin_lock_irqsave <-__wake_up
Binder T-600     0d.h1. 3344us+: add_preempt_count <-_raw_spin_lock_irqsave
Binder T-600     0d.h2. 3346us+: __wake_up_common <-__wake_up
Binder T-600     0d.h2. 3349us+: autoremove_wake_function <-__wake_up_common
Binder T-600     0d.h2. 3351us+: default_wake_function <-autoremove_wake_function
Binder T-600     0d.h2. 3353us+: try_to_wake_up <-default_wake_function
Binder T-600     0d.h2. 3355us+: add_preempt_count <-try_to_wake_up
Binder T-600     0d.h3. 3356us+: task_rq_lock <-try_to_wake_up
Binder T-600     0d.h3. 3359us+: _raw_spin_lock <-task_rq_lock
Binder T-600     0d.h3. 3361us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0d.h4. 3363us+: activate_task <-try_to_wake_up
Binder T-600     0d.h4. 3365us+: enqueue_task <-activate_task
Binder T-600     0d.h4. 3368us+: s5p_sched_timer_read <-sched_clock
Binder T-600     0d.h4. 3370us+: enqueue_task_fair <-enqueue_task
Binder T-600     0d.h4. 3372us+: enqueue_entity <-enqueue_task_fair
Binder T-600     0d.h4. 3377us+: update_curr <-enqueue_entity
Binder T-600     0d.h4. 3380us+: update_min_vruntime <-update_curr
Binder T-600     0d.h4. 3382us+: cpuacct_charge <-update_curr
Binder T-600     0d.h4. 3384us+: add_preempt_count <-cpuacct_charge
Binder T-600     0d.h5. 3386us+: sub_preempt_count <-cpuacct_charge
Binder T-600     0d.h4. 3389us+: place_entity <-enqueue_entity
Binder T-600     0d.h4. 3391us+: __enqueue_entity <-enqueue_entity
Binder T-600     0d.h4. 3394us+: check_preempt_wakeup <-try_to_wake_up
Binder T-600     0d.h4. 3396us+: update_curr <-check_preempt_wakeup
Binder T-600     0d.h4. 3398us+: wakeup_preempt_entity <-check_preempt_wakeup
Binder T-600     0d.h4. 3401us+: resched_task <-check_preempt_wakeup
Binder T-600     0dNh4. 3403us+: _raw_spin_unlock_irqrestore <-try_to_wake_up
Binder T-600     0dNh4. 3406us+: sub_preempt_count <-_raw_spin_unlock_irqrestore
Binder T-600     0dNh3. 3408us+: preempt_schedule <-_raw_spin_unlock_irqrestore
Binder T-600     0dNh3. 3410us+: sub_preempt_count <-try_to_wake_up
Binder T-600     0dNh2. 3411us+: preempt_schedule <-try_to_wake_up
Binder T-600     0dNh2. 3413us+: _raw_spin_unlock_irqrestore <-__wake_up
Binder T-600     0dNh2. 3415us+: sub_preempt_count <-_raw_spin_unlock_irqrestore
Binder T-600     0dNh1. 3417us+: preempt_schedule <-_raw_spin_unlock_irqrestore
Binder T-600     0dNh1. 3420us+: note_interrupt <-handle_level_irq
Binder T-600     0dNh1. 3422us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0dNh1. 3424us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0dNh2. 3426us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0dNh2. 3428us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0dNh2. 3430us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0dNh2. 3432us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0dNh1. 3434us+: preempt_schedule <-_raw_spin_unlock
Binder T-600     0dNh1. 3435us+: irq_exit <-asm_do_IRQ
Binder T-600     0dNh1. 3437us+: sub_preempt_count <-irq_exit
Binder T-600     0dN.2. 3439us+: rcu_irq_exit <-irq_exit
Binder T-600     0dN.2. 3441us+: idle_cpu <-irq_exit
Binder T-600     0dN.2. 3443us+: sub_preempt_count <-irq_exit
Binder T-600     0dN.1. 3445us+: asm_do_IRQ <-__irq_usr
Binder T-600     0dN.1. 3447us+: irq_enter <-asm_do_IRQ
Binder T-600     0dN.1. 3449us+: rcu_irq_enter <-irq_enter
Binder T-600     0dN.1. 3450us+: idle_cpu <-irq_enter
Binder T-600     0dN.1. 3452us+: add_preempt_count <-irq_enter
Binder T-600     0dNh1. 3454us+: irq_to_desc <-asm_do_IRQ
Binder T-600     0dNh1. 3456us+: handle_level_irq <-asm_do_IRQ
Binder T-600     0dNh1. 3458us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0dNh1. 3460us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0dNh2. 3462us+: vic_mask_irq <-handle_level_irq
Binder T-600     0dNh2. 3464us+: irq_to_desc <-vic_mask_irq
Binder T-600     0dNh2. 3465us+: vic_ack_irq <-handle_level_irq
Binder T-600     0dNh2. 3467us+: irq_to_desc <-vic_ack_irq
Binder T-600     0dNh2. 3470us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0dNh2. 3472us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0dNh1. 3473us+: preempt_schedule <-_raw_spin_unlock
Binder T-600     0dNh1. 3475us+: handle_IRQ_event <-handle_level_irq
Binder T-600     0dNh1. 3477us+: s5p_tick_timer_interrupt <-handle_IRQ_event
Binder T-600     0dNh1. 3480us+: hrtimer_interrupt <-s5p_tick_timer_interrupt
Binder T-600     0dNh1. 3482us+: ktime_get <-hrtimer_interrupt
Binder T-600     0dNh1. 3484us+: s5p_sched_timer_read <-ktime_get
Binder T-600     0dNh1. 3486us+: ktime_add_ns <-ktime_get
Binder T-600     0dNh1. 3489us+: _raw_spin_lock <-hrtimer_interrupt
Binder T-600     0dNh1. 3490us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0dNh2. 3493us+: __run_hrtimer <-hrtimer_interrupt
Binder T-600     0dNh2. 3495us+: __remove_hrtimer <-__run_hrtimer
Binder T-600     0dNh2. 3498us+: _raw_spin_unlock <-__run_hrtimer
Binder T-600     0dNh2. 3500us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0dNh1. 3502us+: preempt_schedule <-_raw_spin_unlock
Binder T-600     0dNh1. 3504us+: tick_sched_timer <-__run_hrtimer
Binder T-600     0dNh1. 3506us+: ktime_get <-tick_sched_timer
Binder T-600     0dNh1. 3507us+: s5p_sched_timer_read <-ktime_get
Binder T-600     0dNh1. 3509us+: ktime_add_ns <-ktime_get
Binder T-600     0dNh1. 3511us+: tick_do_update_jiffies64 <-tick_sched_timer
Binder T-600     0dNh1. 3513us+: _raw_spin_lock <-tick_do_update_jiffies64
Binder T-600     0dNh1. 3515us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0dNh2. 3518us+: do_timer <-tick_do_update_jiffies64
Binder T-600     0dNh2. 3520us+: update_wall_time <-do_timer
Binder T-600     0dNh2. 3522us+: s5p_sched_timer_read <-update_wall_time
Binder T-600     0dNh2. 3526us+: calc_global_load <-do_timer
Binder T-600     0dNh2. 3528us+: _raw_spin_unlock <-tick_do_update_jiffies64
Binder T-600     0dNh2. 3530us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0dNh1. 3532us+: preempt_schedule <-_raw_spin_unlock
Binder T-600     0dNh1. 3534us+: update_process_times <-tick_sched_timer
Binder T-600     0dNh1. 3536us+: account_process_tick <-update_process_times
Binder T-600     0dNh1. 3538us+: account_user_time <-account_process_tick
Binder T-600     0dNh1. 3540us+: cpuacct_update_stats <-account_user_time
Binder T-600     0dNh1. 3542us+: add_preempt_count <-cpuacct_update_stats
Binder T-600     0dNh2. 3544us+: add_preempt_count <-cpuacct_update_stats
Binder T-600     0dNh3. 3546us+: sub_preempt_count <-cpuacct_update_stats
Binder T-600     0dNh2. 3548us+: preempt_schedule <-cpuacct_update_stats
Binder T-600     0dNh2. 3550us+: add_preempt_count <-cpuacct_update_stats
Binder T-600     0dNh3. 3551us+: sub_preempt_count <-cpuacct_update_stats
Binder T-600     0dNh2. 3553us+: preempt_schedule <-cpuacct_update_stats
Binder T-600     0dNh2. 3555us+: add_preempt_count <-cpuacct_update_stats
Binder T-600     0dNh3. 3557us+: sub_preempt_count <-cpuacct_update_stats
Binder T-600     0dNh2. 3559us+: preempt_schedule <-cpuacct_update_stats
Binder T-600     0dNh2. 3561us+: sub_preempt_count <-cpuacct_update_stats
Binder T-600     0dNh1. 3562us+: preempt_schedule <-cpuacct_update_stats
Binder T-600     0dNh1. 3564us+: run_local_timers <-update_process_times
Binder T-600     0dNh1. 3566us+: hrtimer_run_queues <-run_local_timers
Binder T-600     0dNh1. 3568us+: raise_softirq <-run_local_timers
Binder T-600     0dNh1. 3571us+: softlockup_tick <-run_local_timers
Binder T-600     0dNh1. 3574us+: T.260 <-softlockup_tick
Binder T-600     0dNh1. 3576us+: s5p_sched_timer_read <-sched_clock
Binder T-600     0dNh1. 3578us+: rcu_check_callbacks <-update_process_times
Binder T-600     0dNh1. 3580us+: rcu_sched_qs <-rcu_check_callbacks
Binder T-600     0dNh1. 3582us+: rcu_bh_qs <-rcu_check_callbacks
Binder T-600     0dNh1. 3584us+: __rcu_pending <-rcu_check_callbacks
Binder T-600     0dNh1. 3587us+: cpu_has_callbacks_ready_to_invoke <-__rcu_pending
Binder T-600     0dNh1. 3589us+: cpu_needs_another_gp <-__rcu_pending
Binder T-600     0dNh1. 3591us+: rcu_gp_in_progress <-__rcu_pending
Binder T-600     0dNh1. 3594us+: __rcu_pending <-rcu_check_callbacks
Binder T-600     0dNh1. 3596us+: raise_softirq <-rcu_check_callbacks
Binder T-600     0dNh1. 3598us+: printk_tick <-update_process_times
Binder T-600     0dNh1. 3601us+: scheduler_tick <-update_process_times
Binder T-600     0dNh1. 3603us+: _raw_spin_lock <-scheduler_tick
Binder T-600     0dNh1. 3604us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0dNh2. 3607us+: s5p_sched_timer_read <-sched_clock
Binder T-600     0dNh2. 3609us+: task_tick_fair <-scheduler_tick
Binder T-600     0dNh2. 3611us+: update_curr <-task_tick_fair
Binder T-600     0dNh2. 3613us+: update_min_vruntime <-update_curr
Binder T-600     0dNh2. 3615us+: cpuacct_charge <-update_curr
Binder T-600     0dNh2. 3617us+: add_preempt_count <-cpuacct_charge
Binder T-600     0dNh3. 3619us+: sub_preempt_count <-cpuacct_charge
Binder T-600     0dNh2. 3621us+: preempt_schedule <-cpuacct_charge
Binder T-600     0dNh2. 3623us+: sched_slice <-task_tick_fair
Binder T-600     0dNh2. 3625us+: calc_delta_mine <-sched_slice
Binder T-600     0dNh2. 3628us+: __pick_next_entity <-task_tick_fair
Binder T-600     0dNh2. 3630us+: resched_task <-task_tick_fair
Binder T-600     0dNh2. 3632us+: _raw_spin_unlock <-scheduler_tick
Binder T-600     0dNh2. 3634us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0dNh1. 3636us+: preempt_schedule <-_raw_spin_unlock
Binder T-600     0dNh1. 3638us+: run_posix_cpu_timers <-update_process_times
Binder T-600     0dNh1. 3640us+: profile_tick <-tick_sched_timer
Binder T-600     0dNh1. 3642us+: hrtimer_forward <-tick_sched_timer
Binder T-600     0dNh1. 3644us+: ktime_add_safe <-hrtimer_forward
Binder T-600     0dNh1. 3646us+: ktime_add_safe <-hrtimer_forward
Binder T-600     0dNh1. 3648us+: _raw_spin_lock <-__run_hrtimer
Binder T-600     0dNh1. 3650us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0dNh2. 3652us+: enqueue_hrtimer <-__run_hrtimer
Binder T-600     0dNh2. 3654us+: _raw_spin_unlock <-hrtimer_interrupt
Binder T-600     0dNh2. 3656us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0dNh1. 3658us+: preempt_schedule <-_raw_spin_unlock
Binder T-600     0dNh1. 3660us+: tick_program_event <-hrtimer_interrupt
Binder T-600     0dNh1. 3662us+: tick_dev_program_event <-tick_program_event
Binder T-600     0dNh1. 3664us+: ktime_get <-tick_dev_program_event
Binder T-600     0dNh1. 3666us+: s5p_sched_timer_read <-ktime_get
Binder T-600     0dNh1. 3668us+: ktime_add_ns <-ktime_get
Binder T-600     0dNh1. 3670us+: clockevents_program_event <-tick_dev_program_event
Binder T-600     0dNh1. 3672us+: s5p_tick_set_next_event <-clockevents_program_event
Binder T-600     0dNh1. 3674us+: s5p_tick_timer_start <-s5p_tick_set_next_event
Binder T-600     0dNh1. 3677us+: note_interrupt <-handle_level_irq
Binder T-600     0dNh1. 3679us+: _raw_spin_lock <-handle_level_irq
Binder T-600     0dNh1. 3681us+: add_preempt_count <-_raw_spin_lock
Binder T-600     0dNh2. 3683us+: vic_unmask_irq <-handle_level_irq
Binder T-600     0dNh2. 3685us+: irq_to_desc <-vic_unmask_irq
Binder T-600     0dNh2. 3687us+: _raw_spin_unlock <-handle_level_irq
Binder T-600     0dNh2. 3689us+: sub_preempt_count <-_raw_spin_unlock
Binder T-600     0dNh1. 3691us+: preempt_schedule <-_raw_spin_unlock
Binder T-600     0dNh1. 3692us+: irq_exit <-asm_do_IRQ
Binder T-600     0dNh1. 3694us+: sub_preempt_count <-irq_exit
Binder T-600     0dN.2. 3696us+: __do_softirq <-irq_exit
Binder T-600     0dN.2. 3698us+: __local_bh_disable <-__do_softirq
Binder T-600     0dNs2. 3701us+: __do_softirq <-trace_hardirqs_on
Binder T-600     0dNs2. 3706us+: trace_hardirqs_on <-trace_hardirqs_on
Binder T-600     0dNs2. 3708us : <stack trace>
 => trace_hardirqs_on
 => __do_softirq
 => irq_exit
 => asm_do_IRQ
 => __irq_usr
#

# tracer: preemptirqsoff
#
   <...>-502     0d....    1us!: ret_fast_syscall <-trace_hardirqs_off
   <...>-502     0d..1.  168us+: asm_do_IRQ <-__irq_usr
   <...>-502     0d..1.  171us+: irq_enter <-asm_do_IRQ
   <...>-502     0d..1.  173us+: rcu_irq_enter <-irq_enter
   <...>-502     0d..1.  175us+: idle_cpu <-irq_enter
   <...>-502     0d..1.  176us+: add_preempt_count <-irq_enter
   <...>-502     0d.h1.  178us+: irq_to_desc <-asm_do_IRQ
   <...>-502     0d.h1.  180us : handle_level_irq <-asm_do_IRQ
   <...>-502     0d.h1.  181us+: _raw_spin_lock <-handle_level_irq
   <...>-502     0d.h1.  183us+: add_preempt_count <-_raw_spin_lock
   <...>-502     0d.h2.  185us : vic_mask_irq <-handle_level_irq
   <...>-502     0d.h2.  187us+: irq_to_desc <-vic_mask_irq
   <...>-502     0d.h2.  188us : vic_ack_irq <-handle_level_irq
   <...>-502     0d.h2.  190us+: irq_to_desc <-vic_ack_irq
   <...>-502     0d.h2.  192us+: _raw_spin_unlock <-handle_level_irq
   <...>-502     0d.h2.  193us+: sub_preempt_count <-_raw_spin_unlock
   <...>-502     0d.h1.  195us+: handle_IRQ_event <-handle_level_irq
   <...>-502     0d.h1.  196us+: s5p_tick_timer_interrupt <-handle_IRQ_event
   <...>-502     0d.h1.  199us+: hrtimer_interrupt <-s5p_tick_timer_interrupt
   <...>-502     0d.h1.  200us+: ktime_get <-hrtimer_interrupt
   <...>-502     0d.h1.  202us+: s5p_sched_timer_read <-ktime_get
   <...>-502     0d.h1.  204us+: ktime_add_ns <-ktime_get
   <...>-502     0d.h1.  205us+: _raw_spin_lock <-hrtimer_interrupt
   <...>-502     0d.h1.  207us+: add_preempt_count <-_raw_spin_lock
   <...>-502     0d.h2.  209us : _raw_spin_unlock <-hrtimer_interrupt
   <...>-502     0d.h2.  210us+: sub_preempt_count <-_raw_spin_unlock
   <...>-502     0d.h1.  212us : tick_program_event <-hrtimer_interrupt
   <...>-502     0d.h1.  213us+: tick_dev_program_event <-tick_program_event
......
.Process-583     0dN.1. 3893us : __slab_free <-kmem_cache_free
.Process-583     0dN.1. 3894us+: add_preempt_count <-__slab_free
.Process-583     0dN.2. 3896us : sub_preempt_count <-__slab_free
.Process-583     0dN.1. 3897us+: preempt_schedule <-__slab_free
.Process-583     0.N.1. 3902us+: exit_mmap <-sub_preempt_count
.Process-583     0.N.1. 3905us+: trace_preempt_on <-sub_preempt_count
.Process-583     0.N.1. 3907us : <stack trace>
 => trace_preempt_on
 => sub_preempt_count
 => exit_mmap
 => mmput
 => exit_mm
 => do_exit
 => do_group_exit
 => get_signal_to_deliver

# tracer: sched_switch
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |
     InputReader-413   [000]  2751.017921:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.017936:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.017945:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.018015:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.018029:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.018038:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.018108:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.018122:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.018131:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.018194:    413:112:R   + [000]   412:112:S InputDispatcher
     InputReader-413   [000]  2751.018236:    413:112:S ==> [000]   412:112:R InputDispatcher
 InputDispatcher-412   [000]  2751.018294:    412:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.018306:      5:120:S ==> [000]     0:120:R <idle>
          <idle>-0     [000]  2751.021046:      0:120:R   + [000]     5:120:S events/0
          <idle>-0     [000]  2751.021068:      0:120:R ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.021098:      5:120:D ==> [000]     0:120:R <idle>
          <idle>-0     [000]  2751.023303:      0:120:R   + [000]    30:  0:S vsync_workqueue
          <idle>-0     [000]  2751.023319:      0:120:R ==> [000]    30:  0:R vsync_workqueue
 vsync_workqueue-30    [000]  2751.023339:     30:  0:S ==> [000]     0:120:R <idle>
          <idle>-0     [000]  2751.024924:      0:120:R   + [000]     5:120:D events/0
          <idle>-0     [000]  2751.024938:      0:120:R ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.024986:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.024995:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025070:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025085:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025094:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025165:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025179:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025188:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025258:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025272:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025281:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025351:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025366:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025375:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025445:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025459:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025468:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025537:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025552:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025561:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025630:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025645:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025654:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025723:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025737:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025746:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025816:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025831:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025840:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.025909:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.025923:      5:120:R   + [000]   413:112:S InputReader
        events/0-5     [000]  2751.025932:      5:120:R ==> [000]   413:112:R InputReader
     InputReader-413   [000]  2751.026012:    413:112:S ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.026025:      5:120:S ==> [000]     0:120:R <idle>
          <idle>-0     [000]  2751.027318:      0:120:R   + [000]   412:112:S InputDispatcher
          <idle>-0     [000]  2751.027330:      0:120:R ==> [000]   412:112:R InputDispatcher
 InputDispatcher-412   [000]  2751.027387:    412:112:R   + [000]   439:120:S inity.qlauncher
 InputDispatcher-412   [000]  2751.027419:    412:112:R   + [000]   411:118:S WindowManagerPo
 InputDispatcher-412   [000]  2751.027460:    412:112:S ==> [000]   439:120:R inity.qlauncher
 inity.qlauncher-439   [000]  2751.027599:    439:120:R   + [000]   412:112:S InputDispatcher
 inity.qlauncher-439   [000]  2751.027667:    439:120:S ==> [000]   411:118:R WindowManagerPo
 WindowManagerPo-411   [000]  2751.027844:    411:118:S ==> [000]   412:112:R InputDispatcher
 InputDispatcher-412   [000]  2751.027942:    412:112:S ==> [000]     0:120:R <idle>
          <idle>-0     [000]  2751.028861:      0:120:R   + [000]     5:120:S events/0
          <idle>-0     [000]  2751.028882:      0:120:R ==> [000]     5:120:R events/0
        events/0-5     [000]  2751.028912:      5:120:D ==> [000]     0:120:R <idle>

# cat trace
# tracer: wakeup
#
# wakeup latency trace v1.1.5 on 2.6.35.7+
# --------------------------------------------------------------------
# latency: 12076 us, #5144/5144, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0)
#    -----------------
#    | task: SensorService-391 (uid:1000 nice:-8 policy:0 rt_prio:0)
#    -----------------
#
#                  _------=> CPU#
#                 / _-----=> irqs-off
#                | / _----=> need-resched
#                || / _---=> hardirq/softirq
#                ||| / _--=> preempt-depth
#                |||| /_--=> lock-depth
#                |||||/     delay
#  cmd     pid   |||||| time  |   caller
#     \   /      ||||||   \   |   /
Binder T-519     0d.h5.    1us+:    519:120:R   + [000]   391:112:D SensorService
Binder T-519     0d.h5.    5us+: probe_wakeup <-probe_wakeup
Binder T-519     0d.h4.    7us+: check_preempt_wakeup <-try_to_wake_up
Binder T-519     0d.h4.    9us+: update_curr <-check_preempt_wakeup
Binder T-519     0d.h4.   11us+: wakeup_preempt_entity <-check_preempt_wakeup
Binder T-519     0d.h4.   13us+: calc_delta_mine <-wakeup_preempt_entity
Binder T-519     0d.h4.   15us+: resched_task <-check_preempt_wakeup
Binder T-519     0dNh4.   17us+: _raw_spin_unlock_irqrestore <-try_to_wake_up
Binder T-519     0dNh4.   19us+: sub_preempt_count <-_raw_spin_unlock_irqrestore
Binder T-519     0dNh3.   20us+: preempt_schedule <-_raw_spin_unlock_irqrestore
Binder T-519     0dNh3.   22us+: sub_preempt_count <-try_to_wake_up
Binder T-519     0dNh2.   24us+: preempt_schedule <-try_to_wake_up
Binder T-519     0dNh2.   25us+: _raw_spin_unlock_irqrestore <-__wake_up
Binder T-519     0dNh2.   27us+: sub_preempt_count <-_raw_spin_unlock_irqrestore
Binder T-519     0dNh1.   29us+: preempt_schedule <-_raw_spin_unlock_irqrestore
Binder T-519     0dNh1.   32us+: note_interrupt <-handle_level_irq
Binder T-519     0dNh1.   33us+: _raw_spin_lock <-handle_level_irq
Binder T-519     0dNh1.   35us+: add_preempt_count <-_raw_spin_lock
Binder T-519     0dNh2.   37us+: vic_unmask_irq <-handle_level_irq
Binder T-519     0dNh2.   38us+: irq_to_desc <-vic_unmask_irq
Binder T-519     0dNh2.   40us+: _raw_spin_unlock <-handle_level_irq
Binder T-519     0dNh2.   42us+: sub_preempt_count <-_raw_spin_unlock
Binder T-519     0dNh1.   43us+: preempt_schedule <-_raw_spin_unlock
Binder T-519     0dNh1.   45us+: irq_exit <-asm_do_IRQ
Binder T-519     0dNh1.   47us+: sub_preempt_count <-irq_exit
Binder T-519     0dN.2.   48us+: rcu_irq_exit <-irq_exit
Binder T-519     0dN.2.   50us+: idle_cpu <-irq_exit
Binder T-519     0dN.2.   52us+: sub_preempt_count <-irq_exit
Binder T-519     0dN...   54us+: schedule <-ret_slow_syscall
Binder T-519     0dN...   56us+: add_preempt_count <-schedule
Binder T-519     0dN.1.   58us+: rcu_note_context_switch <-schedule
Binder T-519     0dN.1.   60us+: rcu_sched_qs <-rcu_note_context_switch
Binder T-519     0dN.1.   62us+: _raw_spin_lock_irq <-schedule
Binder T-519     0dN.1.   63us+: add_preempt_count <-_raw_spin_lock_irq
Binder T-519     0d..2.   65us+: s5p_sched_timer_read <-sched_clock
Binder T-519     0d..2.   67us+: put_prev_task_fair <-schedule
Binder T-519     0d..2.   69us+: update_curr <-put_prev_task_fair
Binder T-519     0d..2.   71us+: update_min_vruntime <-update_curr
Binder T-519     0d..2.   72us+: cpuacct_charge <-update_curr
Binder T-519     0d..2.   74us+: add_preempt_count <-cpuacct_charge
Binder T-519     0d..3.   76us+: sub_preempt_count <-cpuacct_charge
Binder T-519     0d..2.   77us+: __enqueue_entity <-put_prev_task_fair
Binder T-519     0d..2.   79us+: pick_next_task_fair <-schedule
Binder T-519     0d..2.   81us+: __pick_next_entity <-pick_next_task_fair
Binder T-519     0d..2.   85us+: wakeup_preempt_entity <-pick_next_task_fair
Binder T-519     0d..2.   87us+: clear_buddies <-pick_next_task_fair
Binder T-519     0d..2.   89us+: set_next_entity <-pick_next_task_fair
Binder T-519     0d..2.   90us+: __dequeue_entity <-set_next_entity
Binder T-519     0d..2.   92us+: _raw_spin_unlock_irq <-schedule
Binder T-519     0...2.   94us+: sub_preempt_count <-_raw_spin_unlock_irq
Binder T-519     0...1.   96us+: sub_preempt_count <-schedule
Binder T-519     0.....  124us+: sys_getpid <-ret_fast_syscall
Binder T-519     0.....  126us+: pid_vnr <-sys_getpid
Binder T-519     0.....  128us+: pid_nr_ns <-pid_vnr
Binder T-519     0.....  131us+: sys_gettid <-ret_fast_syscall
Binder T-519     0.....  133us+: __task_pid_nr_ns <-sys_gettid
Binder T-519     0.....  134us+: add_preempt_count <-__task_pid_nr_ns
Binder T-519     0...1.  137us+: pid_nr_ns <-__task_pid_nr_ns
Binder T-519     0...1.  138us+: sub_preempt_count <-__task_pid_nr_ns
Binder T-519     0.....  144us+: sys_ioctl <-ret_fast_syscall
Binder T-519     0.....  145us+: fget_light <-sys_ioctl
Binder T-519     0.....  147us+: add_preempt_count <-fget_light
Binder T-519     0...1.  149us+: sub_preempt_count <-fget_light
Binder T-519     0.....  151us+: do_vfs_ioctl <-sys_ioctl
Binder T-519     0.....  153us+: vfs_ioctl <-do_vfs_ioctl
Binder T-519     0.....  155us+: binder_ioctl <-vfs_ioctl
Binder T-519     0.....  157us+: mutex_lock <-binder_ioctl
Binder T-519     0.....  159us+: __might_sleep <-mutex_lock
Binder T-519     0.....  160us+: __mutex_lock_slowpath <-mutex_lock
Binder T-519     0.....  162us+: add_preempt_count <-__mutex_lock_slowpath
Binder T-519     0...1.  165us+: sub_preempt_count <-__mutex_lock_slowpath
Binder T-519     0.....  167us+: binder_get_thread <-binder_ioctl
Binder T-519     0.....  170us+: binder_thread_write <-binder_ioctl
Binder T-519     0.....  172us+: binder_transaction <-binder_thread_write
Binder T-519     0.....  174us+: binder_transaction_log_add <-binder_transaction
Binder T-519     0.....  176us+: binder_get_ref <-binder_transaction
Binder T-519     0.....  178us+: kmem_cache_alloc_notrace <-binder_transaction
Binder T-519     0.....  180us+: __might_sleep <-kmem_cache_alloc_notrace
Binder T-519     0.....  182us+: kmem_cache_alloc_notrace <-binder_transaction
Binder T-519     0.....  184us+: __might_sleep <-kmem_cache_alloc_notrace
Binder T-519     0.....  187us+: task_nice <-binder_transaction
Binder T-519     0.....  189us+: binder_buffer_size <-binder_transaction
Binder T-519     0.....  190us+: binder_buffer_size <-binder_transaction
Binder T-519     0.....  192us+: binder_update_page_range <-binder_transaction
Binder T-519     0.....  194us+: binder_insert_free_buffer <-binder_transaction
Binder T-519     0.....  196us+: binder_buffer_size <-binder_insert_free_buffer
Binder T-519     0.....  198us+: binder_inc_node <-binder_transaction


Reference

Oprofile

http://hi.baidu.com/snownight/blog/item/6d81c3ce305fc11193457e56.html
http://blog.csdn.net/nanjianhui/article/details/6454812
http://www.huomo.cn/developer/article-168e1.html

Traceview:

http://developer.android.com

Ftrace:

http://www.ibm.com/developerworks/cn/linux/l-cn-ftrace1/index.html?ca=drs-

http://www.ibm.com/developerworks/cn/linux/l-cn-ftrace2/index.html

http://www.ibm.com/developerworks/cn/linux/l-cn-ftrace3/index.html?ca=drs-


Android下的一些调试手段(含kernel调试办法)

标签:android   kernel   调试   profiling   

原文地址:http://blog.csdn.net/jackjones_008/article/details/42394705

(0)
(0)
   
举报
评论 一句话评论(0
登录后才能评论!
© 2014 mamicode.com 版权所有  联系我们:gaon5@hotmail.com
迷上了代码!