-
Notifications
You must be signed in to change notification settings - Fork 92
Home
Welcome to guider wiki!
- What is guider?
Do you struggle to improve system performance or to find root cause that makes system abnormal?
Guider is made to measure amount of system resource usage and to trace system behavior.
You can analyze your performance issues effectively with this tool.
Guider pursues three characteristics as bellow.
1. easy to use: just run without installation or setting
2. measure correctly: time in ms, size in MB
3. integrate features: show as much information as possible
Document are available.
- Introducing guider (https://github.com/iipeace/guider/files/1149974/guider_20170715.pdf)
- Introducing guider (http://events.linuxfoundation.org/sites/events/files/slides/guider_20170715.pdf)
- How to use
Input command as bellow to start accurate profiling in thread mode
# guider.py record
Input command as bellow to start realtime profiling in top mode
$ guider.py top
Input "Ctrl + c" key to finish profiling
Input command as bellow to see more examples
$ guider.py -h -a
- Options
[record mode]
top [top]
record [thread]
record -y [system]
record -f [function]
record -F [file]
view [page]
[control mode]
list
start|stop|send [pid]
[record options]
-e [enable_optionsPerMode:bellowCharacters]
[function] {m(em)|b(lock)|h(eap)|p(ipe)|g(raph)}
[thread] {m(em)|b(lock)|i(rq)|l(og)|n(et)|p(ipe)|r(eset)|g(raph)|f(utex)}
[top] {t(hread)|d(isk)|w(fc)|W(chan)|s(tack)|m(em)|I(mage)|g(raph)|r(eport)|f(ile)}
-d [disable_optionsPerMode:bellowCharacters]
[thread] {c(pu)}
[function] {c(pu)|u(ser)}
[top] {r(ss)|v(ss)}
-s [save_traceData:dir/file]
-S [sort_output:c(pu)/m(em)/b(lock)/w(fc)/p(id)/n(ew)/r(untime)]
-u [run_inBackground]
-W [wait_forSignal]
-R [record_repeatedly:interval,count]
-b [set_bufferSize:kb]
-D [trace_threadDependency]
-t [trace_syscall:syscalls]
-T [set_fontPath]
-H [set_functionDepth]
-j [set_reportPath:dir]
-U [set_userEvent:name:func|addr:file]
-K [set_kernelEvent:name:func|addr{:%reg/argtype:rettype}]
-C [set_commandScriptPath:file]
-w [set_customRecordCommand:BEFORE|AFTER|STOP:file:value]
-x [set_addressForLocalServer:{ip:}port]
-X [set_requestToRemoteServer:{req@ip:port}]
-N [set_addressForReport:req@ip:port]
-n [set_addressForPrint:ip:port]
-m [set_objdumpPath:file]
[analysis options]
-o [save_outputData:dir]
-P [group_perProcessBasis]
-p [show_preemptInfo:tids]
-l [set_addr2linePath:files]
-r [set_targetRootPath:dir]
-I [set_inputValue:file|addr]
-q [configure_taskList]
-L [convert_textToImage]
[common options]
-a [show_allInfo]
-Q [print_allRows]
-i [set_interval:sec]
-g [set_filter:comms|tids{:file}]
-A [set_arch:arm|x86|x64]
-c [set_customEvent:event:filter]
-E [set_errorLogPath:file]
-v [verbose]
-
Mode
-
Thread mode
[Thread Info] [ Elapsed: 2.050 ] [ Start: 2849868.198 ] [ Running: 112 ] [ CtxSwc: 3357 ] [ LogSize: 4054 KB ] [ Unit: Sec/MB/NR ] ========================================================================================================================================================== __________Thread Info___________|_____________CPU Info______________|______SCHED Info______|________BLOCK Info________|_____________MEM Info_____________| | | | | | Name( Tid/ Pid)|LF|Usage( %)|Delay( Max)|Pri| IRQ | Yld| Lose|Steal| Mig| Read( MB/ Cnt)|WCnt( MB)| Sum(Usr/Buf/Ker)|Rcl|Wst|DRcl(Nr)| ========================================================================================================================================================== # CPU: 12 CORE/0(-----/-----)|--| 0.00( 0.1)| 0.00( 0.00)| 0| 0.00| 7| -| -| -| 0.00( 0/ 1)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/1(-----/-----)|--| 0.00( 0.1)| 0.10( 0.00)| 0| 0.00| 147| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/2(-----/-----)|--| 0.00( 0.1)| 0.16( 0.00)| 0| 0.00| 211| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/3(-----/-----)|--| 0.00( 0.1)| 0.11( 0.00)| 0| 0.00| 181| -| -| -| 0.00( 0/ 0)| 32( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/4(-----/-----)|--| 0.00( 0.1)| 0.11( 0.00)| 0| 0.00| 232| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/5(-----/-----)|--| 0.30( 14.8)| 0.18( 0.00)| 0| 0.00| 179| -| -| -| 1.26( 6/ 495)| 19( 0)| 61( 57/ 0/ 3)| 0| 0|0.00( 0)| CORE/6(-----/-----)|--| 0.00( 0.0)| 0.35( 0.00)| 0| 0.00| 57| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/7(-----/-----)|--| 0.00( 0.0)| 0.60( 0.00)| 0| 0.00| 100| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/8(-----/-----)|--| 0.00( 0.0)| 0.44( 0.00)| 0| 0.00| 59| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/9(-----/-----)|--| 0.00( 0.0)| 1.94( 0.00)| 0| 0.00| 37| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/10(-----/-----)|--| 0.07( 3.4)| 0.00( 0.00)| 0| 0.00| 2| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/11(-----/-----)|--| 0.00( 0.0)| 2.05( 0.00)| 0| 0.00| 39| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| ---------------------------------------------------------------------------------------------------------------------------------------------------------- # Hot: 4 synergyc( 3604/ 3602)| | 0.17( 8.5)| 0.00( 0.00)| 0| 0.00| 3| 14| 3| 0| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| arm-starfish-li(16087/16087)| | 0.13( 6.3)| 0.00( 0.00)| 0| 0.00| 0| 20| 157| 4| 1.26( 6/ 496)| 0( 0)| 61( 57/ 0/ 3)| 0| 0|0.00( 0)| guider(16088/16088)| | 0.07( 3.4)| 0.00( 0.00)|R90| 0.00| 2| 0| 2| 0| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| ----------------------------------------------------------------------------------------------------------------------------------------------------------
This is a main output in thread mode.
User can analyze resource usage of threads accurately.[CPU Info] section includes bellow information.
Usage: cpu time(ms) that a thread has been running
Delay: total time(ms) that a thread has been being preempted
Pri: highest priority that a thread has been running at
IRQ: cpu time(ms) that a thread has been running in interupt context[SCHED Info] section includes bellow information.
Yld: yield number
Lose: preempted number
Steal: preemption number
Mig: migration number[BLOCK Info] section includes bellow information.
Read: total time(ms) that a thread has been being blocked for disk read
MB: total size(MB) that a thread has been reading from disk
Cnt: total number that a thread has been reading from disk
WCnt: total number that a thread has been writing to disk
MB: total size(MB) that a thread has been writing to disk[MEM Info] section includes bellow information.
Sum: total size(MB) that a thread has been allocating to memory(PAGE)
Usr: user-space size(MB) that a thread has been allocating to memory(PAGE)
Buf: page cache size(MB) that a thread has been allocating to memory(PAGE)
Ker: kernel-space size(MB) that a thread has been allocating to memory(PAGE)
Rcl: total size(MB) that a thread has been being reclaimed by other threads
Wst: wasting size(MB) that a thread has been allocating to memory(PAGE) in kernel space
Drcl(Nr): total time(ms) and number that a thread has been reclaiming directly
+ Interval Info [-i option] `````````````````````````````````````````` [Thread Interval Info] [ Unit: 1 Sec ] ========================================================================================================================================================== Name( Tid/ Pid): 1 2 2.05 ========================================================================================================================================================== # Total(%/MB/Cnt) CORE/0( 0/-----): 0 0 0 CORE/1( 0/-----): 0 0 0 CORE/2( 0/-----): 0 0 0 CORE/3( 0/-----): 0 0 0 CORE/4( 0/-----): 0 0 0 CORE/5( 0/-----): 20 8 5 CORE/6( 0/-----): 0 0 0 CORE/7( 0/-----): 0 0 0 CORE/8( 0/-----): 0 0 0 CORE/9( 0/-----): 0 0 0 CORE/10( 0/-----): 6 0 0 CORE/11( 0/-----): 0 0 0 MEM( 0/-----): 15 44 1 BLK_RD( 0/-----): 3 3 0 BLK_WR( 0/-----): 0 0 0 ---------------------------------------------------------------------------------------------------------------------------------------------------------- # CPU(%) synergyc( 3604/ 3602): 17 0 0 arm-starfish-li(16087/16087): 4 8 5 guider(16088/16088): 6 0 0 KnottyUI(15896/15896): 0 0 0 ---------------------------------------------------------------------------------------------------------------------------------------------------------- # Delay(%) arm-starfish-li(16087/16087): 0 0 0 ---------------------------------------------------------------------------------------------------------------------------------------------------------- # MEM(MB) arm-starfish-li(16087/16087): 15 44 1 guider(16088/16088): 0 0 0 ---------------------------------------------------------------------------------------------------------------------------------------------------------- # BLK_RD(MB) arm-starfish-li(16087/16087): 3 3 0 Plex Media Serv( 2965/ 2956): 0 0 0 ---------------------------------------------------------------------------------------------------------------------------------------------------------- # BLK_WR(MB) Plex Media Serv( 2965/ 2956): 0 0 0 ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` This is interval output about resource usage in thread mode. User can analyze resource usage of threads in each specific seconds. + Graph Info [-i -e g option] ![guider_interval](https://cloud.githubusercontent.com/assets/15862689/23349234/a6894a6a-fcf4-11e6-911f-7d2df9e1d571.png) This is graphical output about resource usage in thread mode. User can analyze resource usage of threads in graphical image. + IRQ Info [-a -e i option] `````````````````````````````````````````` [Thread IRQ Info] ========================================================================================================================================================== IRQ ( Name ): Count Usage ProcMax ProcMin InterMax InterMin ========================================================================================================================================================== # IRQ(9) / Total( 0.004) / Cnt(1226) irq/88( ahci ): 527 0.001570 0.000013 0.000002 0.035694 0.000010 irq/90( eth0 ): 6 0.000010 0.000002 0.000001 0.879542 0.000073 irq/92( nouveau ): 35 0.000535 0.000024 0.000014 0.016661 0.001491 softirq/1( TIMER ): 85 0.000118 0.000005 0.000001 0.231687 0.000002 softirq/3( NET_RX ): 6 0.000084 0.000033 0.000001 0.879542 0.000073 softirq/4( BLOCK ): 527 0.001180 0.000019 0.000001 0.035696 0.000010 softirq/7( SCHED ): 24 0.000050 0.000014 0.000001 0.231684 0.007992 softirq/8( HRTIMER ): 1 0.000004 0.000004 0.000004 0.000000 0.000000 softirq/9( RCU ): 15 0.000006 0.000001 0.000000 0.299594 0.003970 ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` This is output about interrupt details in thread mode. + Syscall Info [-t option] `````````````````````````````````````````` [Thread Syscall Info] ========================================================================================================================================================== Name( Tid) Syscall SysId Usage Count Min Max Avg ========================================================================================================================================================== Chrome_ChildIOT(4264) sys_recvmsg 47 0.000 2 0.000002 0.000010 0.000006 sys_futex 202 0.000 1 0.000010 0.000010 0.000010 sys_gettid 186 0.000 1 0.000001 0.000001 0.000001 sys_epoll_wait 232 0.000 2 0.000000 0.000001 0.000000 ---------------------------------------------------------------------------------------------------------------------------------------------------------- Chrome_IOThread(3735) sys_sendmsg 46 0.000 1 0.000015 0.000015 0.000015 sys_read 0 0.000 2 0.000001 0.000011 0.000006 sys_epoll_ctl 233 0.000 2 0.000001 0.000009 0.000005 sys_epoll_wait 232 0.000 2 0.000001 0.000001 0.000001 ---------------------------------------------------------------------------------------------------------------------------------------------------------- Plex DLNA Serve(23531) sys_futex 202 1.100 47 0.000001 0.099949 0.023407 ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` `````````````````````````````````````````` [Thread Syscall History] ========================================================================================================================================================== Name( Tid) Time Diff Type Syscall SysId Core Return Parameter ========================================================================================================================================================== guider(13089) 0.005889 0.000000 exit sys_write 1 11 1 - guider(13089) 0.005892 0.000002 both sys_close 3 11 0 (3, 7f4f84292000, 7f4f84293000, 4f43e0, 252e7a0, 7f4f84267740) guider(13089) 0.005897 0.000007 both sys_munmap 11 11 0 (7f4f84292000, 1000, 0, 4f43e0, 252e7a0, 7f4f84267740) guider(13089) 0.005924 0.000013 both sys_open 2 11 -2 (1f83f20, 241, 1b6, 91a870, 208d106, 240) guider(13089) 0.005981 0.000011 both sys_open 2 11 3 (1f83f20, 241, 1b6, 91a870, 208d106, 240) guider(13089) 0.005994 0.000001 both sys_fstat 5 11 0 (3, 7ffdf528fa60, 7ffdf528fa60, 1, 0, 240) guider(13089) 0.005998 0.000000 both sys_fstat 5 11 0 (3, 7ffdf528fa70, 7ffdf528fa70, d, 252e7a0, 7f4f84215414) guider(13089) 0.005999 0.000004 both sys_mmap 9 11 139979496431616 (0, 1000, 3, 22, ffffffff, 0) guider(13089) 0.006009 0.000183 both sys_write 1 11 1 (3, 7f4f84292000, 1, 4f43e0, 252e7a0, 7f4f84267740) guider(13089) 0.006194 0.000001 both sys_close 3 11 0 (3, 7f4f84292000, 7f4f84293000, 4f43e0, 252e7a0, 7f4f84267740) guider(13089) 0.006198 0.000007 both sys_munmap 11 11 0 (7f4f84292000, 1000, 0, 4f43e0, 252e7a0, 7f4f84267740) guider(13089) 0.006222 0.000012 both sys_open 2 11 3 (1f83f20, 241, 1b6, 91a870, 208d106, 240) guider(13089) 0.006235 0.000001 both sys_fstat 5 11 0 (3, 7ffdf528fa60, 7ffdf528fa60, 1, 0, 240) guider(13089) 0.006239 0.000000 both sys_fstat 5 11 0 (3, 7ffdf528fa70, 7ffdf528fa70, d, 252e7a0, 7f4f84215414) `````````````````````````````````````````` This is output about system call details in thread mode. + Module Info [-a option] `````````````````````````````````````````` [Thread Module Info] ========================================================================================================================================================== _Type_|_Time_|_____Module_____|__Thread Name___( Tid )|Elapsed| ========================================================================================================================================================== FREE | 1.892| psmouse | rmmod(13336)| LOAD | 3.525| psmouse | insmod(13339)| 0.003| FREE | 5.545| psmouse | rmmod(13342)| ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` This is output about kernel module details in thread mode. + Creation Info [-a option] `````````````````````````````````````````` [Thread Creation Info] [Alive: +] [Die: -] [CreatedTime: //] [ChildCount: ||] [CpuUsage: <>] [WaitTimeForChilds: {}] [WaitTimeOfParent: []] ========================================================================================================================================================== + Plex DLNA Serve(3249) <0.001> |2| - Plex(13345) /4.641/ <0.002> |1| - Plex(13346) /6.643/ <0.004> + Plex(13348) /6.707/ <0.000> + Plex DLNA Serve(3243) <0.000> |3| - Plex(13343) /6.138/ <0.000> - Plex(13344) /6.138/ <0.000> - Plex(13347) /6.694/ <0.001> + systemd-udevd(449) <0.002> |2| + systemd-udevd(13337) /1.892/ <0.001> + systemd-udevd(13338) /1.893/ <0.001> + bash(27395) <0.010> |4| - rmmod(13336) /0.392/ <0.002> - insmod(13339) /2.018/ <0.010> - rmmod(13342) /4.045/ <0.002> + guider(13349) /6.441/ <0.104> + kthreadd(2) <0.000> |2| - kthreadd(13340) /3.525/ <0.000> + kthreadd(13341) /3.534/ <0.000> ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` This is output about thread creation details in thread mode. User can analyze thread tree and wait time that a parent thread waits its child threads. + Preemption Info [-p option] `````````````````````````````````````````` [Thread Info] [ Elapsed: 2.742 ] [ Start: 75.657 ] [ Running: 139 ] [ CtxSwc: 20255 ] [ LogSize: 5500 KB ] [ Unit: Sec/MB/NR ] ========================================================================================================================================================== __________Thread Info___________|_____________CPU Info______________|______SCHED Info______|________BLOCK Info________|_____________MEM Info_____________| | | | | | Name( Tid/ Pid)|LF|Usage( %)|Delay( Max)|Pri| IRQ | Yld| Lose|Steal| Mig| Read( MB/ Cnt)|WCnt( MB)| Sum(Usr/Buf/Ker)|Rcl|Wst|DRcl(Nr)| ========================================================================================================================================================== # CPU: 4 CORE/0(-----/-----)|--| 0.19( 6.8)| 0.00( 0.00)| 0| 0.00| 0| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/1(-----/-----)|--| 0.21( 7.5)| 0.00( 0.00)| 0| 0.00| 0| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/2(-----/-----)|--| 0.40( 14.6)| 0.00( 0.00)| 0| 0.00| 0| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| CORE/3(-----/-----)|--| 0.17( 6.4)| 0.65( 0.00)| 0| 0.00| 1| -| -| -| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| ---------------------------------------------------------------------------------------------------------------------------------------------------------- # Hot: 9 surface-manager( 1615/ 1615)| | 0.29( 10.7)| 0.02( 0.00)| 0| 0.00| 161| 314| 77| 4| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| guider( 3474/ 3474)| | 0.06( 2.3)| 0.01( 0.00)| 0| 0.00| 2| 40| 1| 1| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| tWindowCore( 1442/ 1407)| | 0.06( 2.3)| 0.01( 0.00)| 0| 0.00| 333| 200| 314| 3| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| mali-renderer( 1681/ 1615)| | 0.05( 1.9)| 0.00( 0.00)| 0| 0.00| 559| 101| 540| 10| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| guider( 4875/ 4875)| | 0.05( 1.7)| 0.00( 0.00)| 0| 0.00| 2| 10| 2| 0| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| tvideoCC( 2422/ 1613)| | 0.04( 1.4)| 0.00( 0.00)| 0| 0.00| 285| 7| 268| 2| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| pq_thread( 2558/ 1613)| | 0.04( 1.3)| 0.00( 0.00)| 0| 0.00| 103| 30| 97| 0| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| n0000028( 2450/ 1613)| | 0.03( 1.0)| 0.00( 0.00)| 0| 0.00| 529| 3| 473| 5| 0.00( 0/ 0)| 0( 0)| 0( 0/ 0/ 0)| 0| 0|0.00( 0)| ---------------------------------------------------------------------------------------------------------------------------------------------------------- # PRT: Tid(1615) / Comm(surface-manager) / Total( 0.017) / Threads(45) mali-renderer( 1681/ 0)| | 0.01( 40.5) com.webos.app.i( 1785/ 0)| | 0.00( 10.9) n0000034( 2512/ 0)| | 0.00( 7.0) tHDMI5V( 2458/ 0)| | 0.00( 6.7) tvideoCC( 2422/ 0)| | 0.00( 4.4) n0000028( 2450/ 0)| | 0.00( 4.1) sdx( 4858/ 0)| | 0.00( 2.8) tAUDATV( 2470/ 0)| | 0.00( 2.7) tCMState( 2490/ 0)| | 0.00( 2.5) tAVD( 2454/ 0)| | 0.00( 2.0) tAUDHDMI( 2469/ 0)| | 0.00( 1.6) kworker/u9:1( 1524/ 0)| | 0.00( 1.4) rcu_preempt( 7/ 0)| | 0.00( 1.1) sleepd( 2251/ 0)| | 0.00( 0.9) n0000005( 2226/ 0)| | 0.00( 0.9) tHDMI1( 2459/ 0)| | 0.00( 0.8) hdmi20_rx_video( 2451/ 0)| | 0.00( 0.8) te_monitor( 940/ 0)| | 0.00( 0.8) mali-event-hnd( 1676/ 0)| | 0.00( 0.8) physical-device( 3010/ 0)| | 0.00( 0.7) HSM Read Map( 2548/ 0)| | 0.00( 0.6) tHDMI3( 2461/ 0)| | 0.00( 0.5) tHDMI4( 2462/ 0)| | 0.00( 0.4) tHDMI2( 2460/ 0)| | 0.00( 0.4) ACCT00( 2524/ 0)| | 0.00( 0.4) tSettingsDone( 2563/ 0)| | 0.00( 0.4) ARTIMER_T( 2473/ 0)| | 0.00( 0.4) `````````````````````````````````````````` This is output about preemption details in thread mode. User can analyze which threads had preempted a specific thread. + Signal Info [-a option] `````````````````````````````````````````` [Thread Signal Info] ========================================================================================================================================================== TYPE TIME SENDER( TID) SIGNAL RECEIVER( TID) ========================================================================================================================================================== RECV 0.394702 SIGCHLD bash(27395) SEND 1.892381 rmmod(13336) SIGCHLD bash(27395) RECV 2.027533 SIGCHLD bash(27395) SEND 3.525273 insmod(13339) SIGCHLD bash(27395) RECV 4.047565 SIGCHLD bash(27395) SEND 5.545286 rmmod(13342) SIGCHLD bash(27395) RECV 6.547838 SIGCHLD bash(27395) SEND 7.946579 swapper/4( 0[4]) SIGALRM screen( 7400) RECV 7.946588 SIGALRM screen( 7400) SEND 8.042445 guider(13349) SIGINT guider(13335) RECV 8.042476 SIGINT guider(13335) ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` This is output about signal traffic in thread mode. + Dependency Info [-D option] `````````````````````````````````````````` [Thread Dependency Info] ========================================================================================================================================================== Total/Inter From( Tid) -> To( Tid) Event ========================================================================================================================================================== # Dep: 182 0.002/0.000 guider(3474) -> mali-renderer(1681) kick 0.002/0.000 mali-renderer(1681) -> tHDMI4(2462) kick 0.003/0.000 guider(3474) -> sdx(4858) kick 0.003/0.000 n0000028(2450) -> ACCT00(2524) kick 0.004/0.001 mali-renderer(1681) wakeup 0.012/0.008 guider(3474) -> qosm(3484) kick 0.012/0.001 PmLogDaemon(1417) recv 0.019/0.007 mali-renderer(1681) wakeup 0.137/0.118 mali-renderer(1681) wakeup 0.139/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 0.152/0.014 surface-manager(1615) -> mali-renderer(1681) kick 0.154/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 0.169/0.015 surface-manager(1615) -> mali-renderer(1681) kick 0.171/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 0.185/0.015 surface-manager(1615) -> mali-renderer(1681) kick 0.187/0.002 mali-renderer(1681) wakeup 0.204/0.017 mali-event-hnd(1676) -> mali-renderer(1681) kick 0.221/0.017 mali-event-hnd(1676) -> MICOM(2380) kick 0.221/0.000 mali-event-hnd(1676) -> mali-renderer(1681) kick 0.269/0.048 surface-manager(1615) -> mali-renderer(1681) kick 0.371/0.102 mali-event-hnd(1676) -> mali-renderer(1681) kick 0.654/0.283 mali-renderer(1681) wakeup 0.669/0.015 surface-manager(1615) -> mali-renderer(1681) kick 0.804/0.135 mali-event-hnd(1676) -> mali-renderer(1681) kick 1.002/0.198 surface-manager(1615) -> mali-renderer(1681) kick 1.004/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 1.018/0.015 surface-manager(1615) -> mali-renderer(1681) kick 1.021/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 1.035/0.015 surface-manager(1615) -> mali-renderer(1681) kick 1.037/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 1.052/0.015 surface-manager(1615) -> mali-renderer(1681) kick 1.054/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 1.068/0.014 surface-manager(1615) -> mali-renderer(1681) kick 1.071/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 1.085/0.015 surface-manager(1615) -> mali-renderer(1681) kick 1.087/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 1.102/0.015 surface-manager(1615) -> mali-renderer(1681) kick 1.104/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick 1.118/0.015 surface-manager(1615) -> mali-renderer(1681) kick 1.121/0.002 mali-event-hnd(1676) -> mali-renderer(1681) kick `````````````````````````````````````````` This is output about dependency of each threads in thread mode.
-
Function mode [-f option]
[Function Thread Info] [ Elapsed: 3.569 ] [ Start: 2858278.707 ] [ Threads: 23 ] [ LogSize: 1541 KB ] ========================================================================================================================================================== _______________________Thread________________________|__CPU__|_________________________PAGE_________________________|__HEAP__|______BLOCK_______|_CUSTOM_| | | | | | | ______Name______|__Tid__|__Pid__|_Target_|_DIE_|_NEW_|__PER__|__ALLOC__(__USER__/__BUF___/__KERN__)|__FREE__|_UFREE_|__EXP___|__READ__|__WRITE__|___NR___| ========================================================================================================================================================== a.out| 15939| 15939| * | | v | 98.3%| 11416K( 3140K/ 0K/ 8276K)| 104K| 84K| 0K| 0K| 0K| 0| Plex DLNA Serve| 23531| 3010| * | | | 0.2%| 0K( 0K/ 0K/ 0K)| 0K| 0K| 0K| 0K| 0K| 0| Plex DLNA Serve| 15944| -----| * | v | v | 0.2%| 0K( 0K/ 0K/ 0K)| 2024K| 0K| 0K| 0K| 0K| 0| Plex DLNA Serve| 9871| 3010| * | | | 0.2%| 0K( 0K/ 0K/ 0K)| 0K| 0K| 0K| 0K| 0K| 0| guider| 15936| 15936| * | | | 0.2%| 0K( 0K/ 0K/ 0K)| 188K| 120K| 0K| 0K| 0K| 0| bash| 4011| 4011| * | | | 0.2%| 92K( 84K/ 0K/ 8K)| 0K| 0K| 0K| 0K| 0K| 0| ksoftirqd/1| 37| 37| * | | | 0.2%| 0K( 0K/ 0K/ 0K)| 0K| 0K| 0K| 0K| 0K| 0| compiz| 2571| 2571| * | | | 0.2%| 12K( 12K/ 0K/ 0K)| 0K| 0K| 0K| 0K| 0K| 0| Plex DLNA Serve| 15943| -----| * | v | v | 0.0%| 0K( 0K/ 0K/ 0K)| 0K| 0K| 0K| 0K| 0K| 0| Plex DLNA Serve| 8385| 3010| * | | | 0.0%| 0K( 0K/ 0K/ 0K)| 4K| 0K| 0K| 0K| 0K| 0| Plex DLNA Serve| 15941| -----| * | v | v | 0.0%| 0K( 0K/ 0K/ 0K)| 0K| 0K| 0K| 0K| 0K| 0| kworker/u24:2| 679| 679| * | | | 0.0%| 4K( 0K/ 0K/ 4K)| 0K| 0K| 0K| 0K| 64K| 0| Xorg| 1636| 1636| * | | | 0.0%| 8K( 0K/ 0K/ 8K)| 40K| 8K| 0K| 0K| 0K| 0| chromium-browse| 4273| 4273| * | | | 0.0%| 4K( 4K/ 0K/ 0K)| 0K| 0K| 0K| 0K| 0K| 0| chromium-browse| 4507| 4507| * | | | 0.0%| 4K( 4K/ 0K/ 0K)| 0K| 0K| 0K| 0K| 0K| 0| rcuos/3| 11| 11| * | | | 0.0%| 0K( 0K/ 0K/ 0K)| 8K| 0K| 0K| 0K| 0K| 0| screen| 3565| 3565| * | | | 0.0%| 4K( 0K/ 0K/ 4K)| 40K| 4K| 0K| 0K| 0K| 0| Plex DLNA Serve| 3243| 3010| * | | | 0.0%| 40K( 0K/ 0K/ 40K)| 0K| 0K| 0K| 0K| 0K| 0| kworker/2:0| 13550| 13550| * | | | 0.0%| 0K( 0K/ 0K/ 0K)| 516K| 12K| 0K| 0K| 0K| 0| Plex DLNA Serve| 3246| 3010| * | | | 0.0%| 8K( 0K/ 0K/ 8K)| 0K| 0K| 0K| 0K| 0K| 0| rcuos/8| 16| 16| * | | | 0.0%| 0K( 0K/ 0K/ 0K)| 16K| 0K| 0K| 0K| 0K| 0| ----------------------------------------------------------------------------------------------------------------------------------------------------------
This is output about thread list profiled in function mode.
User can select specific threads with -g option and analyze resource usage by function.
But symbol of threads that already died will not be shown.
+ CPU Info `````````````````````````````````````````` [Function CPU Info] [Cnt: 394] [Interval: 8ms] (USER) ========================================================================================================================================================== __Usage__|___________________Function____________________|_____________________________________________Binary_____________________________________________ ========================================================================================================================================================== 99.0% | cpuTest | /media/disk/work/test/a.out + 100.0% | <- startTest [/media/disk/work/test/a.out] <- main [/media/disk/work/test/a.out] <- __libc_start_main [/lib/x86_64-linux-gnu/libc-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 0.5% | memset | /lib/x86_64-linux-gnu/libc-2.19.so + 100.0% | <- startTest [/media/disk/work/test/a.out] <- main [/media/disk/work/test/a.out] <- __libc_start_main [/lib/x86_64-linux-gnu/libc-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 0.3% | _int_malloc | /lib/x86_64-linux-gnu/libc-2.19.so ---------------------------------------------------------------------------------------------------------------------------------------------------------- 0.3% | 00007f756e3e7ee4 | ?? + 100.0% | <- 000000000044676f [/media/disk/work/test/a.out] ---------------------------------------------------------------------------------------------------------------------------------------------------------- [Function CPU Info] [Cnt: 394] [Interval: 8ms] (KERNEL) ========================================================================================================================================================== __Usage__|____________________________________________________________________Function____________________________________________________________________ ========================================================================================================================================================== 100.0% | hrtimer_interrupt + 99.5% | <- local_apic_timer_interrupt <- smp_apic_timer_interrupt <- apic_timer_interrupt + 0.3% | <- local_apic_timer_interrupt <- smp_apic_timer_interrupt <- apic_timer_interrupt <- do_page_fault <- page_fault + 0.3% | <- local_apic_timer_interrupt <- smp_apic_timer_interrupt <- apic_timer_interrupt <- __do_fault <- handle_mm_fault <- __do_page_fault <- do_page_fault <- page_fault ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` This is output about cpu usage of specific threads by function in function mode. + Mem Info [-e m option] `````````````````````````````````````````` [Function Page Info] [Total: 11416KB] [Alloc: 11444KB(817)] [Free: 188KB(47)] (USER) ========================================================================================================================================================== Usage ( Usr / Buf / Ker )|___________________Function____________________|________________LifeTime________________|______________Binary_______________ ========================================================================================================================================================== 10256K( 2048/ 0/ 8208)| memset | AVR: 1.563 / MIN: 1.560 / MAX: 1.568 | /lib/x86_64-linux-gnu/libc-2.19.so + 10256K( 2048/ 0/ 8208)| <- startTest [/media/disk/work/test/a.out] <- main [/media/disk/work/test/a.out] <- __libc_start_main [/lib/x86_64-linux-gnu/libc-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 960K( 956/ 0/ 4)| _int_malloc | AVR: 1.559 / MIN: 1.554 / MAX: 1.560 | /lib/x86_64-linux-gnu/libc-2.19.so ---------------------------------------------------------------------------------------------------------------------------------------------------------- 56K( 16/ 0/ 40)| 00007f756e3e81e7 | AVR: 1.569 / MIN: 1.568 / MAX: 1.569 | ?? ---------------------------------------------------------------------------------------------------------------------------------------------------------- 44K( 36/ 0/ 8)| sysmalloc | AVR: 1.560 / MIN: 1.558 / MAX: 1.568 | /lib/x86_64-linux-gnu/libc-2.19.so ---------------------------------------------------------------------------------------------------------------------------------------------------------- 12K( 12/ 0/ 0)| elf_machine_rela_relative | AVR: 1.568 / MIN: 1.568 / MAX: 1.568 | /lib/x86_64-linux-gnu/ld-2.19.so + 12K( 12/ 0/ 0)| <- dl_main [/lib/x86_64-linux-gnu/ld-2.19.so] <- _dl_sysdep_start [/lib/x86_64-linux-gnu/ld-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 8K( 8/ 0/ 0)| realloc | AVR: 1.568 / MIN: 1.568 / MAX: 1.568 | /lib/x86_64-linux-gnu/ld-2.19.so + 4K( 4/ 0/ 0)| <- _dl_map_object [/lib/x86_64-linux-gnu/ld-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 8K( 4/ 0/ 4)| dl_main | AVR: 1.568 / MIN: 1.568 / MAX: 1.568 | /lib/x86_64-linux-gnu/ld-2.19.so + 8K( 4/ 0/ 4)| <- _dl_sysdep_start [/lib/x86_64-linux-gnu/ld-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- [Function Page Info] [Total: 11416KB] [Alloc: 11444KB(817)] [Free: 188KB(47)] (KERNEL) ========================================================================================================================================================== Usage ( Usr / Buf / Ker )|___________________Function____________________|__________________________________LifeTime__________________________________ ========================================================================================================================================================== 8192K( 0/ 0/ 8192)| do_huge_pmd_anonymous_page | AVR: 1.563 / MIN: 1.562 / MAX: 1.564 + 8192K( 0/ 0/ 8192)| <- handle_mm_fault <- __do_page_fault <- do_page_fault <- page_fault ---------------------------------------------------------------------------------------------------------------------------------------------------------- 3084K( 3084/ 0/ 0)| handle_mm_fault | AVR: 1.563 / MIN: 1.554 / MAX: 1.569 + 3076K( 3076/ 0/ 0)| <- __do_page_fault <- do_page_fault <- page_fault + 4K( 4/ 0/ 0)| <- __get_user_pages <- get_user_pages <- copy_strings.isra.17 <- copy_strings_kernel <- do_execve_common.isra.23 <- SyS_execve <- stub_execve + 4K( 4/ 0/ 0)| <- __do_page_fault <- do_page_fault <- page_fault <- load_elf_binary <- search_binary_handler <- do_execve_common.isra.23 <- SyS_execve <- stub_execve ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` This is output about memory usage of specific threads by function in function mode. + Heap Info [-e h option] `````````````````````````````````````````` [Function Heap Info] [Total: 18913KB] [Alloc: 19074KB(16)] [Free: 161KB(1)] (USER) ========================================================================================================================================================== __Usage__|___________________Function____________________|_____________________Binary______________________|____________________Source____________________ ========================================================================================================================================================== 10244K | mmap64 | /lib/x86_64-linux-gnu/libc-2.19.so | /build/eglibc-oGUzwX/eglibc-2.19/misc/../sysdeps/unix/syscall-template.S:81 ---------------------------------------------------------------------------------------------------------------------------------------------------------- 4752K | __brk | /lib/x86_64-linux-gnu/ld-2.19.so | /build/eglibc-oGUzwX/eglibc-2.19/elf/../sysdeps/unix/sysv/linux/x86_64/brk.c:31 ---------------------------------------------------------------------------------------------------------------------------------------------------------- 3917K | realloc | /lib/x86_64-linux-gnu/ld-2.19.so | /build/eglibc-oGUzwX/eglibc-2.19/misc/../sysdeps/unix/syscall-template.S:81 + 3897K | <- _dl_map_object [/lib/x86_64-linux-gnu/ld-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- [Function Heap History] [Cnt: 15] ========================================================================================================================================================== _____________VAddr______________|____Size____|__Size(KB)__|__Size(MB)__|______COMM_______(__TID__)|__CORE__|______TIME_______| ========================================================================================================================================================== 139733299458048 | 8192 | 8 | 0 | a.out( 16284)| 5 | 2858989.603987 | ------------------------------------------------------------------------------------------------------------------------------ [User] | realloc[/lib/x86_64-linux-gnu/ld-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 139733293277184 | 3949248 | 3856 | 3 | a.out( 16284)| 5 | 2858989.604134 | ------------------------------------------------------------------------------------------------------------------------------ [User] | realloc[/lib/x86_64-linux-gnu/ld-2.19.so] <- _dl_map_object[/lib/x86_64-linux-gnu/ld-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 139733297184768 | 24576 | 24 | 0 | a.out( 16284)| 5 | 2858989.604164 | ------------------------------------------------------------------------------------------------------------------------------ [User] | realloc[/lib/x86_64-linux-gnu/ld-2.19.so] <- _dl_map_object[/lib/x86_64-linux-gnu/ld-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 139733297209344 | 17088 | 16 | 0 | a.out( 16284)| 5 | 2858989.604191 | ------------------------------------------------------------------------------------------------------------------------------ [User] | realloc[/lib/x86_64-linux-gnu/ld-2.19.so] <- _dl_map_object[/lib/x86_64-linux-gnu/ld-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 139733299286016 | 4096 | 4 | 0 | a.out( 16284)| 5 | 2858989.604241 | ------------------------------------------------------------------------------------------------------------------------------ [User] | realloc[/lib/x86_64-linux-gnu/ld-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` This is output about heap usage of specific threads by function in function mode. + Block Info [-e b option] `````````````````````````````````````````` [Function BLK_RD Info] [Size: 10396KB] [Cnt: 90] (USER) ========================================================================================================================================================== __Usage__|___________________Function____________________|_____________________Binary______________________|____________________Source____________________ ========================================================================================================================================================== 10384K | __read | /lib/x86_64-linux-gnu/libc-2.19.so | /build/eglibc-oGUzwX/eglibc-2.19/io/../sysdeps/unix/syscall-template.S:81 + 10384K | <- startTest [/media/disk/work/test/a.out] <- main [/media/disk/work/test/a.out] <- __libc_start_main [/lib/x86_64-linux-gnu/libc-2.19.so] ---------------------------------------------------------------------------------------------------------------------------------------------------------- 12K | 00007f756e3e81e7 | ?? | ---------------------------------------------------------------------------------------------------------------------------------------------------------- [Function BLK_RD Info] [Size: 10396KB] [Cnt: 90] (KERNEL) ========================================================================================================================================================== __Usage__|____________________________________________________________________Function____________________________________________________________________ ========================================================================================================================================================== 10396K | submit_bio + 10016K | <- mpage_readpages <- ext4_readpages <- __do_page_cache_readahead <- ondemand_readahead <- page_cache_async_readahead <- generic_file_aio_read <- do_sync_read <- vfs_read <- SyS_read <- tracesys + 128K | <- mpage_readpages <- ext4_readpages <- __do_page_cache_readahead <- ondemand_readahead <- page_cache_sync_readahead <- generic_file_aio_read <- do_sync_read <- vfs_read <- SyS_read <- tracesys + 96K | <- do_mpage_readpage <- mpage_readpages <- ext4_readpages <- __do_page_cache_readahead <- ondemand_readahead <- page_cache_async_readahead <- generic_file_aio_read <- do_sync_read <- vfs_read <- SyS_read <- tracesys + 80K | <- do_mpage_readpage <- mpage_readpages <- ext4_readpages <- __do_page_cache_readahead <- ondemand_readahead <- page_cache_sync_readahead <- generic_file_aio_read <- do_sync_read <- vfs_read <- SyS_read <- tracesys + 48K | <- do_mpage_readpage <- mpage_readpages <- ext4_readpages <- __do_page_cache_readahead <- ondemand_readahead <- page_cache_sync_readahead <- generic_file_aio_read <- do_sync_read <- vfs_read <- SyS_read <- tracesys + 12K | <- _submit_bh <- bh_submit_read <- ext4_get_branch <- ext4_ind_map_blocks <- ext4_map_blocks <- _ext4_get_block <- ext4_get_block <- do_mpage_readpage <- mpage_readpages <- ext4_readpages <- __do_page_cache_readahead <- ondemand_readahead <- page_cache_async_readahead <- generic_file_aio_read <- do_sync_read <- vfs_read <- SyS_read <- tracesys + 12K | <- mpage_readpages <- ext4_readpages <- __do_page_cache_readahead <- ondemand_readahead <- page_cache_sync_readahead <- generic_file_aio_read <- do_sync_read <- vfs_read <- kernel_read <- prepare_binprm <- do_execve_common.isra.23 <- SyS_execve <- stub_execve + 4K | <- _submit_bh <- bh_submit_read <- ext4_get_branch <- ext4_ind_map_blocks <- ext4_map_blocks <- _ext4_get_block <- ext4_get_block <- do_mpage_readpage <- mpage_readpages <- ext4_readpages <- __do_page_cache_readahead <- ondemand_readahead <- page_cache_sync_readahead <- generic_file_aio_read <- do_sync_read <- vfs_read <- SyS_read <- tracesys ---------------------------------------------------------------------------------------------------------------------------------------------------------- `````````````````````````````````````````` This is output about disk(block) usage of specific threads by function in function mode.
-
Top mode
This is output about resource usage of processes profiled in top mode.
User can analyze resource usage of process / thread(with -e t) in real-time.
[option] top
This is output about file usage of system profiled in top mode.
User can analyze file usage of system.
[option] top -e f
This is output about summarized resource usage of system profiled in top mode.
User can analyze summarized resource usage of system.
[option] top -o
This is a graph about resource usage of system profiled in top mode.
User can analyze resource usage of process / thread(with -e t) by graph.
[option] top -I [output file] -e g -
File mode
This is output about file usage of processes profiled in file mode.
User can analyze file usage (on-memory) of process.
[option] -F -
System mode
This is output about system information in system mode.
[option] -y
-