标签：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
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:
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 调试 profiling
原文地址：http://blog.csdn.net/jackjones_008/article/details/42394705
