我知道之前有人问过,但我担心“systrace使用扩展ftrace的atrace,所以在这里检查ftrace格式”对我来说还不够.我正在了解一些systrace特定标签/格式的更多细节.我有一些我没有信心的猜测,因此我需要一个真正知道他们确认/否定的人.
以下是我在trace.HTML中找到的一些结果.
# tracer: nop\n\#\n\# entrIEs-in-buffer/entrIEs-written: 393636/393636 #P:1\n\#\n\# _-----=> irqs-off\n\# / _----=> need-resched\n\# | / _---=> hardirq/softirq\n\# || / _--=> preempt-depth\n\# ||| / delay\n\# TASK-PID cpu# |||| TIMESTAMP FUNCTION\n\# | | | |||| | |\n\ atrace-27768 [000] ...2 17184.509740: sched_switch: prev_comm=atrace prev_pID=27768 prev_prio=120 prev_state=S ==> next_comm=swapper/0 next_pID=0 next_prio=120\n\ Thread-117-16753 [001] ...1 17184.510251: tracing_mark_write: B|4237|eglSwapBuffers\n\ <IDle>-0 [000] d.h4 17184.510329: sched_wakeup: comm=AudioOut_2 pID=608 prio=101 success=1 target_cpu=000\n\ <IDle>-0 [000] ...2 17184.510338: sched_switch: prev_comm=swapper/0 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=AudioOut_2 next_pID=608 next_prio=101\n\ AudioOut_2-608 [000] d..4 17184.510393: sched_wakeup: comm=AudioTrack pID=16778 prio=104 success=1 target_cpu=000\n\ AudioOut_2-608 [000] ...2 17184.510446: sched_switch: prev_comm=AudioOut_2 prev_pID=608 prev_prio=101 prev_state=S ==> next_comm=AudioTrack next_pID=16778 next_prio=104\n\ Thread-117-16753 [001] ...1 17184.510610: tracing_mark_write: B|4237|queueBuffer\n\ Thread-117-16753 [001] d..4 17184.510648: sched_wakeup: comm=Binder_2 pID=189 prio=120 success=1 target_cpu=001\n\ Thread-117-16753 [001] ...2 17184.510656: sched_switch: prev_comm=Thread-117 prev_pID=16753 prev_prio=120 prev_state=R+ ==> next_comm=Binder_2 next_pID=189 next_prio=120\n\ Binder_2-189 [001] ...2 17184.510664: sched_switch: prev_comm=Binder_2 prev_pID=189 prev_prio=120 prev_state=D ==> next_comm=Thread-117 next_pID=16753 next_prio=120\n\ Thread-117-16753 [001] d..4 17184.510670: sched_wakeup: comm=Binder_2 pID=189 prio=120 success=1 target_cpu=001\n\ Thread-117-16753 [001] ...2 17184.510673: sched_switch: prev_comm=Thread-117 prev_pID=16753 prev_prio=120 prev_state=R+ ==> next_comm=Binder_2 next_pID=189 next_prio=120\n\ Binder_2-189 [001] ...1 17184.510722: tracing_mark_write: B|147|queueBuffer\n\ Binder_2-189 [001] ...1 17184.510729: tracing_mark_write: B|147|SurfaceVIEw: 0\n\ Binder_2-189 [001] ...1 17184.510734: tracing_mark_write: E\n\ Binder_2-189 [001] ...1 17184.510753: tracing_mark_write: C|147|SurfaceVIEw|1\n\ Binder_2-189 [001] d..4 17184.510772: sched_wakeup: comm=EventThread pID=255 prio=111 success=1 target_cpu=001\n\ Binder_2-189 [001] ...1 17184.510781: tracing_mark_write: E\n\ Binder_2-189 [001] ...2 17184.510810: sched_switch: prev_comm=Binder_2 prev_pID=189 prev_prio=120 prev_state=S ==> next_comm=EventThread next_pID=255 next_prio=111\n\ EventThread-255 [001] d..4 17184.510828: sched_wakeup: comm=dispSync pID=186 prio=111 success=1 target_cpu=001\n\ EventThread-255 [001] ...1 17184.510840: tracing_mark_write: C|147|VsyncOn|1\n\ EventThread-255 [001] ...2 17184.510852: sched_switch: prev_comm=EventThread prev_pID=255 prev_prio=111 prev_state=S ==> next_comm=dispSync next_pID=186 next_prio=111\n\ dispSync-186 [001] ...2 17184.510867: sched_switch: prev_comm=dispSync prev_pID=186 prev_prio=111 prev_state=S ==> next_comm=Thread-117 next_pID=16753 next_prio=120\n\ Thread-117-16753 [001] ...1 17184.510885: tracing_mark_write: E\n\ Thread-117-16753 [001] ...1 17184.510893: tracing_mark_write: B|4237|query\n\ Thread-117-16753 [001] ...1 17184.510899: tracing_mark_write: E\n\ Thread-117-16753 [001] ...1 17184.510906: tracing_mark_write: B|4237|query\n\ Thread-117-16753 [001] ...1 17184.510911: tracing_mark_write: E\n\ Thread-117-16753 [001] ...1 17184.510924: tracing_mark_write: E\n\ AudioTrack-16778 [000] d.h7 17184.510984: sched_wakeup: comm=Fastmixer pID=330 prio=96 success=1 target_cpu=000\n\ AudioTrack-16778 [000] ...2 17184.511000: sched_switch: prev_comm=AudioTrack prev_pID=16778 prev_prio=104 prev_state=R+ ==> next_comm=Fastmixer next_pID=330 next_prio=96\n\ Thread-117-16753 [001] ...1 17184.511012: tracing_mark_write: B|4237|dequeueBuffer\n\ Thread-117-16753 [001] d..4 17184.511034: sched_wakeup: comm=Binder_1 pID=185 prio=120 success=1 target_cpu=001\n\ Thread-117-16753 [001] ...2 17184.511041: sched_switch: prev_comm=Thread-117 prev_pID=16753 prev_prio=120 prev_state=R+ ==> next_comm=Binder_1 next_pID=185 next_prio=120\n\ Binder_1-185 [001] ...2 17184.511053: sched_switch: prev_comm=Binder_1 prev_pID=185 prev_prio=120 prev_state=D ==> next_comm=Thread-117 next_pID=16753 next_prio=120\n\ Thread-117-16753 [001] d..4 17184.511059: sched_wakeup: comm=Binder_1 pID=185 prio=120 success=1 target_cpu=001\n\ Thread-117-16753 [001] ...2 17184.511062: sched_switch: prev_comm=Thread-117 prev_pID=16753 prev_prio=120 prev_state=R+ ==> next_comm=Binder_1 next_pID=185 next_prio=120\n\ Fastmixer-330 [000] ...2 17184.511070: sched_switch: prev_comm=Fastmixer prev_pID=330 prev_prio=96 prev_state=S ==> next_comm=AudioTrack next_pID=16778 next_prio=104\n\ AudioTrack-16778 [000] ...2 17184.511087: sched_switch: prev_comm=AudioTrack prev_pID=16778 prev_prio=104 prev_state=S ==> next_comm=swapper/0 next_pID=0 next_prio=120\n\ Binder_1-185 [001] ...1 17184.511093: tracing_mark_write: B|147|dequeueBuffer\n\ Binder_1-185 [001] ...1 17184.511102: tracing_mark_write: B|147|SurfaceVIEw: 1\n\ Binder_1-185 [001] ...1 17184.511105: tracing_mark_write: E\n\ Binder_1-185 [001] ...1 17184.511110: tracing_mark_write: E\n\ Binder_1-185 [001] ...2 17184.511131: sched_switch: prev_comm=Binder_1 prev_pID=185 prev_prio=120 prev_state=S ==> next_comm=Thread-117 next_pID=16753 next_prio=120\n\ Thread-117-16753 [001] ...1 17184.511143: tracing_mark_write: E\n\ <IDle>-0 [000] d.h4 17184.512011: sched_wakeup: comm=Thread-117 pID=16780 prio=120 success=1 target_cpu=000\n\ <IDle>-0 [000] ...2 17184.512021: sched_switch: prev_comm=swapper/0 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=Thread-117 next_pID=16780 next_prio=120\n\ Thread-117-16780 [000] ...2 17184.512047: sched_switch: prev_comm=Thread-117 prev_pID=16780 prev_prio=120 prev_state=S ==> next_comm=swapper/0 next_pID=0 next_prio=120\n\ <IDle>-0 [000] d.h4 17184.513414: sched_wakeup: comm=Thread-117 pID=17201 prio=120 success=1 target_cpu=000\n\ <IDle>-0 [000] ...2 17184.513425: sched_switch: prev_comm=swapper/0 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=Thread-117 next_pID=17201 next_prio=120\n\ Thread-117-17201 [000] ...2 17184.513441: sched_switch: prev_comm=Thread-117 prev_pID=17201 prev_prio=120 prev_state=S ==> next_comm=swapper/0 next_pID=0 next_prio=120\n\ Thread-117-16753 [001] ...2 17184.516369: sched_switch: prev_comm=Thread-117 prev_pID=16753 prev_prio=120 prev_state=S ==> next_comm=swapper/1 next_pID=0 next_prio=120\n\ <IDle>-0 [000] d.h6 17184.517936: sched_wakeup: comm=kworker/0:3 pID=27267 prio=120 success=1 target_cpu=000\n\ <IDle>-0 [000] ...2 17184.517947: sched_switch: prev_comm=swapper/0 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=kworker/0:3 next_pID=27267 next_prio=120\n\ kworker/0:3-27267 [000] ...2 17184.518045: sched_switch: prev_comm=kworker/0:3 prev_pID=27267 prev_prio=120 prev_state=S ==> next_comm=swapper/0 next_pID=0 next_prio=120\n\ <IDle>-0 [000] d.h7 17184.520977: sched_wakeup: comm=Fastmixer pID=330 prio=96 success=1 target_cpu=000\n\ <IDle>-0 [000] ...2 17184.520986: sched_switch: prev_comm=swapper/0 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=Fastmixer next_pID=330 next_prio=96\n\ Fastmixer-330 [000] ...2 17184.521041: sched_switch: prev_comm=Fastmixer prev_pID=330 prev_prio=96 prev_state=S ==> next_comm=swapper/0 next_pID=0 next_prio=120\n\ <IDle>-0 [000] d.h6 17184.521117: sched_wakeup: comm=kworker/0:3 pID=27267 prio=120 success=1 target_cpu=000\n\ <IDle>-0 [000] ...2 17184.521122: sched_switch: prev_comm=swapper/0 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=kworker/0:3 next_pID=27267 next_prio=120\n\ kworker/0:3-27267 [000] d..4 17184.521130: sched_wakeup: comm=hwc_eventmon pID=246 prio=100 success=1 target_cpu=000\n\ kworker/0:3-27267 [000] ...2 17184.521135: sched_switch: prev_comm=kworker/0:3 prev_pID=27267 prev_prio=120 prev_state=S ==> next_comm=hwc_eventmon next_pID=246 next_prio=100\n\ hwc_eventmon-246 [000] ...2 17184.521155: sched_switch: prev_comm=hwc_eventmon prev_pID=246 prev_prio=100 prev_state=S ==> next_comm=swapper/0 next_pID=0 next_prio=120\n\ <IDle>-0 [000] d.s5 17184.521414: sched_wakeup: comm=cfinteractive pID=88 prio=0 success=1 target_cpu=000\n\ <IDle>-0 [000] ...2 17184.521420: sched_switch: prev_comm=swapper/0 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=cfinteractive next_pID=88 next_prio=0\n\ cfinteractive-88 [000] ...2 17184.521440: sched_switch: prev_comm=cfinteractive prev_pID=88 prev_prio=0 prev_state=S ==> next_comm=swapper/0 next_pID=0 next_prio=120\n\ <IDle>-0 [001] d.h4 17184.525814: sched_wakeup: comm=dispSync pID=186 prio=111 success=1 target_cpu=001\n\ <IDle>-0 [001] ...2 17184.525821: sched_switch: prev_comm=swapper/1 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=dispSync next_pID=186 next_prio=111\n\ dispSync-186 [001] d..4 17184.525842: sched_wakeup: comm=EventThread pID=255 prio=111 success=1 target_cpu=001\n\ dispSync-186 [001] ...2 17184.525851: sched_switch: prev_comm=dispSync prev_pID=186 prev_prio=111 prev_state=S ==> next_comm=EventThread next_pID=255 next_prio=111\n\ <IDle>-0 [000] d.h3 17184.525884: sched_wakeup: comm=surfaceflinger pID=147 prio=112 success=1 target_cpu=000\n\ <IDle>-0 [000] ...2 17184.525890: sched_switch: prev_comm=swapper/0 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=surfaceflinger next_pID=147 next_prio=112\n\ EventThread-255 [001] ...2 17184.525892: sched_switch: prev_comm=EventThread prev_pID=255 prev_prio=111 prev_state=S ==> next_comm=swapper/1 next_pID=0 next_prio=120\n\Q1：为什么“线程”带有不同的PID,有时会被安排在不同的cpu上同时运行,例如：螺纹117？ “线程”在这里真正意味着什么？
Binder_1-185 [001] ...2 17184.511131: sched_switch: prev_comm=Binder_1 prev_pID=185 prev_prio=120 prev_state=S ==> next_comm=Thread-117 next_pID=16753 next_prio=120\n\ Thread-117-16753 [001] ...1 17184.511143: tracing_mark_write: E\n\ <IDle>-0 [000] d.h4 17184.512011: sched_wakeup: comm=Thread-117 pID=16780 prio=120 success=1 target_cpu=000\n\ <IDle>-0 [000] ...2 17184.512021: sched_switch: prev_comm=swapper/0 prev_pID=0 prev_prio=120 prev_state=R ==> next_comm=Thread-117 next_pID=16780 next_prio=120\n\ Thread-117-16780 [000] ...2 17184.512047: sched_switch: prev_comm=Thread-117 prev_pID=16780 prev_prio=120 prev_state=S ==> next_comm=swapper/0 next_pID=0 next_prio=120\n\Q2：“sched_switch”中的“prev_state”是什么意思？ “S,D,R,R”分别在这个变量中是指什么？
Q3：“tracing_mark_write”使用B表示开始,C表示更改,E表示结束.但是E标签没有跟踪名称.如何确定它对应哪个B标签？它是否在调用堆栈样式liFO中工作？如果是这样,只有当“线程”是一个无法拆分为在两个cpu上连贯运行的真实线程时,才能保证这一点.这导致我们回到Q1.
任何帮助表示赞赏！
解决方法:
A1：它显示了你将从设备上的ps -t看到的线程名称,该名称由进程设置.未命名的Dalvik线程被命名为“Thread-N”,其中N是由Thread类跟踪的序列号(与Binder线程池创建的“Binder_1”相同).所以“Thread-117”中的“117”与系统pID或tID没有关系;它就是调用线程的内容.它不能保证是唯一的 – 您可以在一个进程中或在单独的进程中拥有多个实例.
A2：状态与你在ps输出中看到的相同.请参阅linux手册页的“PROCESS STATE CODES”部分：
D uninterruptible sleep (usually IO) R running or runnable (on run queue) S interruptible sleep (waiting for an event to complete) ...A3：是的,liFO,单线程.这与公共android.os.Trace API相匹配. (对于“asynchronous” traces,有一个不同的(非公开的)API,您可以为开始和结束提供相同的标记和“cookie”,但它并没有被广泛使用.)
总结以上是内存溢出为你收集整理的android – 读取systrace日志全部内容，希望文章能够帮你解决android – 读取systrace日志所遇到的程序开发问题。
如果觉得内存溢出网站内容还不错，欢迎将内存溢出网站推荐给程序员好友。
欢迎分享，转载请注明来源：内存溢出
微信扫一扫
支付宝扫一扫
评论列表（0条）