README 20 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557
  1. p m - g r a p h
  2. pm-graph: suspend/resume/boot timing analysis tools
  3. Version: 5.5
  4. Author: Todd Brandt <todd.e.brandt@intel.com>
  5. Home Page: https://01.org/pm-graph
  6. Report bugs/issues at bugzilla.kernel.org Tools/pm-graph
  7. - https://bugzilla.kernel.org/buglist.cgi?component=pm-graph&product=Tools
  8. Full documentation available online & in man pages
  9. - Getting Started:
  10. https://01.org/pm-graph/documentation/getting-started
  11. - Config File Format:
  12. https://01.org/pm-graph/documentation/3-config-file-format
  13. - upstream version in git:
  14. https://github.com/intel/pm-graph/
  15. Requirements:
  16. - runs with python2 or python3, choice is made by /usr/bin/python link
  17. - python2 now requires python-configparser be installed
  18. Table of Contents
  19. - Overview
  20. - Setup
  21. - Usage
  22. - Basic Usage
  23. - Dev Mode Usage
  24. - Proc Mode Usage
  25. - Configuration Files
  26. - Usage Examples
  27. - Config File Options
  28. - Custom Timeline Entries
  29. - Adding/Editing Timeline Functions
  30. - Adding/Editing Dev Timeline Source Functions
  31. - Verifying your Custom Functions
  32. - Testing on consumer linux Operating Systems
  33. - Android
  34. ------------------------------------------------------------------
  35. | OVERVIEW |
  36. ------------------------------------------------------------------
  37. This tool suite is designed to assist kernel and OS developers in optimizing
  38. their linux stack's suspend/resume & boot time. Using a kernel image built
  39. with a few extra options enabled, the tools will execute a suspend or boot,
  40. and will capture dmesg and ftrace data. This data is transformed into a set of
  41. timelines and a callgraph to give a quick and detailed view of which devices
  42. and kernel processes are taking the most time in suspend/resume & boot.
  43. ------------------------------------------------------------------
  44. | SETUP |
  45. ------------------------------------------------------------------
  46. These packages are required to execute the scripts
  47. - python
  48. - python-requests
  49. Ubuntu:
  50. sudo apt-get install python python-requests
  51. Fedora:
  52. sudo dnf install python python-requests
  53. The tools can most easily be installed via git clone and make install
  54. $> git clone http://github.com/intel/pm-graph.git
  55. $> cd pm-graph
  56. $> sudo make install
  57. $> man sleepgraph ; man bootgraph
  58. Setup involves some minor kernel configuration
  59. The following kernel build options are required for all kernels:
  60. CONFIG_DEVMEM=y
  61. CONFIG_PM_DEBUG=y
  62. CONFIG_PM_SLEEP_DEBUG=y
  63. CONFIG_FTRACE=y
  64. CONFIG_FUNCTION_TRACER=y
  65. CONFIG_FUNCTION_GRAPH_TRACER=y
  66. CONFIG_KPROBES=y
  67. CONFIG_KPROBES_ON_FTRACE=y
  68. In kernel 3.15.0, two patches were upstreamed which enable the
  69. v3.0 behavior. These patches allow the tool to read all the
  70. data from trace events instead of from dmesg. You can enable
  71. this behavior on earlier kernels with these patches:
  72. (kernel/pre-3.15/enable_trace_events_suspend_resume.patch)
  73. (kernel/pre-3.15/enable_trace_events_device_pm_callback.patch)
  74. If you're using a kernel older than 3.15.0, the following
  75. additional kernel parameters are required:
  76. (e.g. in file /etc/default/grub)
  77. GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=32M ..."
  78. If you're using a kernel older than 3.11-rc2, the following simple
  79. patch must be applied to enable ftrace data:
  80. in file: kernel/power/suspend.c
  81. in function: int suspend_devices_and_enter(suspend_state_t state)
  82. remove call to "ftrace_stop();"
  83. remove call to "ftrace_start();"
  84. There is a patch which does this for kernel v3.8.0:
  85. (kernel/pre-3.11-rc2/enable_ftrace_in_suspendresume.patch)
  86. ------------------------------------------------------------------
  87. | USAGE |
  88. ------------------------------------------------------------------
  89. Basic Usage
  90. ___________
  91. 1) First configure a kernel using the instructions from the previous sections.
  92. Then build, install, and boot with it.
  93. 2) Open up a terminal window and execute the mode list command:
  94. %> sudo ./sleepgraph.py -modes
  95. ['freeze', 'mem', 'disk']
  96. Execute a test using one of the available power modes, e.g. mem (S3):
  97. %> sudo ./sleepgraph.py -m mem -rtcwake 15
  98. or with a config file
  99. %> sudo ./sleepgraph.py -config config/suspend.cfg
  100. When the system comes back you'll see the script finishing up and
  101. creating the output files in the test subdir. It generates output
  102. files in subdirectory: suspend-mmddyy-HHMMSS. The ftrace file can
  103. be used to regenerate the html timeline with different options
  104. HTML output: <hostname>_<mode>.html
  105. raw dmesg output: <hostname>_<mode>_dmesg.txt
  106. raw ftrace output: <hostname>_<mode>_ftrace.txt
  107. View the html in firefox or chrome.
  108. Dev Mode Usage
  109. ______________
  110. Developer mode adds information on low level source calls to the timeline.
  111. The tool sets kprobes on all delay and mutex calls to see which devices
  112. are waiting for something and when. It also sets a suite of kprobes on
  113. subsystem dependent calls to better fill out the timeline.
  114. The tool will also expose kernel threads that don't normally show up in the
  115. timeline. This is useful in discovering dependent threads to get a better
  116. idea of what each device is waiting for. For instance, the scsi_eh thread,
  117. a.k.a. scsi resume error handler, is what each SATA disk device waits for
  118. before it can continue resume.
  119. The timeline will be much larger if run with dev mode, so it can be useful
  120. to set the -mindev option to clip out any device blocks that are too small
  121. to see easily. The following command will give a nice dev mode run:
  122. %> sudo ./sleepgraph.py -m mem -rtcwake 15 -mindev 1 -dev
  123. or with a config file
  124. %> sudo ./sleepgraph.py -config config/suspend-dev.cfg
  125. Proc Mode Usage
  126. _______________
  127. Proc mode adds user process info to the timeline. This is done in a manner
  128. similar to the bootchart utility, which graphs init processes and their
  129. execution as the system boots. This tool option does the same thing but for
  130. the period before and after suspend/resume.
  131. In order to see any process info, there needs to be some delay before or
  132. after resume since processes are frozen in suspend_prepare and thawed in
  133. resume_complete. The predelay and postdelay args allow you to do this. It
  134. can also be useful to run in x2 mode with an x2 delay, this way you can
  135. see process activity before and after resume, and in between two
  136. successive suspend/resumes.
  137. The command can be run like this:
  138. %> sudo ./sleepgraph.py -m mem -rtcwake 15 -x2 -x2delay 1000 -predelay 1000 -postdelay 1000 -proc
  139. or with a config file
  140. %> sudo ./sleepgraph.py -config config/suspend-proc.cfg
  141. ------------------------------------------------------------------
  142. | CONFIGURATION FILES |
  143. ------------------------------------------------------------------
  144. Since 4.0 we've moved to using config files in lieu of command line options.
  145. The config folder contains a collection of typical use cases.
  146. There are corresponding configs for other power modes:
  147. Simple suspend/resume with basic timeline (mem/freeze/standby)
  148. config/suspend.cfg
  149. config/freeze.cfg
  150. config/standby.cfg
  151. Dev mode suspend/resume with dev timeline (mem/freeze/standby)
  152. config/suspend-dev.cfg
  153. config/freeze-dev.cfg
  154. config/standby-dev.cfg
  155. Simple suspend/resume with timeline and callgraph (mem/freeze/standby)
  156. config/suspend-callgraph.cfg
  157. config/freeze-callgraph.cfg
  158. config/standby-callgraph.cfg
  159. Sample proc mode x2 run using mem suspend
  160. config/suspend-x2-proc.cfg
  161. Sample for editing timeline funcs (moves internal functions into config)
  162. config/custom-timeline-functions.cfg
  163. Sample debug config for serio subsystem
  164. config/debug-serio-suspend.cfg
  165. Usage Examples
  166. ______________
  167. Run a simple mem suspend:
  168. %> sudo ./sleepgraph.py -config config/suspend.cfg
  169. Run a mem suspend with callgraph data:
  170. %> sudo ./sleepgraph.py -config config/suspend-callgraph.cfg
  171. Run a mem suspend with dev mode detail:
  172. %> sudo ./sleepgraph.py -config config/suspend-dev.cfg
  173. Config File Options
  174. ___________________
  175. [Settings]
  176. # Verbosity: print verbose messages (def: false)
  177. verbose: false
  178. # Suspend Mode: e.g. standby, mem, freeze, disk (def: mem)
  179. mode: mem
  180. # Output Directory Format: {hostname}, {date}, {time} give current values
  181. output-dir: suspend-{hostname}-{date}-{time}
  182. # Automatic Wakeup: use rtcwake to wakeup after X seconds (def: infinity)
  183. rtcwake: 15
  184. # Add Logs: add the dmesg and ftrace log to the html output (def: false)
  185. addlogs: false
  186. # Sus/Res Gap: insert a gap between sus & res in the timeline (def: false)
  187. srgap: false
  188. # Custom Command: Command to execute in lieu of suspend (def: "")
  189. command: echo mem > /sys/power/state
  190. # Proc mode: graph user processes and cpu usage in the timeline (def: false)
  191. proc: false
  192. # Dev mode: graph source functions in the timeline (def: false)
  193. dev: false
  194. # Suspend/Resume x2: run 2 suspend/resumes back to back (def: false)
  195. x2: false
  196. # x2 Suspend Delay: time delay between the two test runs in ms (def: 0 ms)
  197. x2delay: 0
  198. # Pre Suspend Delay: nclude an N ms delay before (1st) suspend (def: 0 ms)
  199. predelay: 0
  200. # Post Resume Delay: include an N ms delay after (last) resume (def: 0 ms)
  201. postdelay: 0
  202. # Min Device Length: graph only dev callbacks longer than min (def: 0.001 ms)
  203. mindev: 0.001
  204. # Callgraph: gather ftrace callgraph data on all timeline events (def: false)
  205. callgraph: false
  206. # Expand Callgraph: pre-expand the callgraph treeviews in html (def: false)
  207. expandcg: false
  208. # Min Callgraph Length: show callgraphs only if longer than min (def: 1 ms)
  209. mincg: 1
  210. # Timestamp Precision: number of sig digits in timestamps (0:S, [3:ms], 6:us)
  211. timeprec: 3
  212. # Device Filter: show only devs whose name/driver includes one of these strings
  213. devicefilter: _cpu_up,_cpu_down,i915,usb
  214. # Override default timeline entries:
  215. # Do not use the internal default functions for timeline entries (def: false)
  216. # Set this to true if you intend to only use the ones defined in the config
  217. override-timeline-functions: true
  218. # Override default dev timeline entries:
  219. # Do not use the internal default functions for dev timeline entries (def: false)
  220. # Set this to true if you intend to only use the ones defined in the config
  221. override-dev-timeline-functions: true
  222. # Call Loop Max Gap (dev mode only)
  223. # merge loops of the same call if each is less than maxgap apart (def: 100us)
  224. callloop-maxgap: 0.0001
  225. # Call Loop Max Length (dev mode only)
  226. # merge loops of the same call if each is less than maxlen in length (def: 5ms)
  227. callloop-maxlen: 0.005
  228. ------------------------------------------------------------------
  229. | CUSTOM TIMELINE ENTRIES |
  230. ------------------------------------------------------------------
  231. Adding or Editing Timeline Functions
  232. ____________________________________
  233. The tool uses an array of function names to fill out empty spaces in the
  234. timeline where device callbacks don't appear. For instance, in suspend_prepare
  235. the tool adds the sys_sync and freeze_processes calls as virtual device blocks
  236. in the timeline to show you where the time is going. These calls should fill
  237. the timeline with contiguous data so that most kernel execution is covered.
  238. It is possible to add new function calls to the timeline by adding them to
  239. the config. It's also possible to copy the internal timeline functions into
  240. the config so that you can override and edit them. Place them in the
  241. timeline_functions_ARCH section with the name of your architecture appended.
  242. i.e. for x86_64: [timeline_functions_x86_64]
  243. Use the override-timeline-functions option if you only want to use your
  244. custom calls, or leave it false to append them to the internal ones.
  245. This section includes a list of functions (set using kprobes) which use both
  246. symbol data and function arg data. The args are pulled directly from the
  247. stack using this architecture's registers and stack formatting. Each entry
  248. can include up to four pieces of info: The function name, a format string,
  249. an argument list, and a color. But only a function name is required.
  250. For a full example config, see config/custom-timeline-functions.cfg. It pulls
  251. all the internal timeline functions into the config and allows you to edit
  252. them.
  253. Entry format:
  254. function: format{fn_arg1}_{fn_arg2} fn_arg1 fn_arg2 ... [color=purple]
  255. Required Arguments:
  256. function: The symbol name for the function you want probed, this is the
  257. minimum required for an entry, it will show up as the function
  258. name with no arguments.
  259. example: _cpu_up:
  260. Optional Arguments:
  261. format: The format to display the data on the timeline in. Use braces to
  262. enclose the arg names.
  263. example: CPU_ON[{cpu}]
  264. color: The color of the entry block in the timeline. The default color is
  265. transparent, so the entry shares the phase color. The color is an
  266. html color string, either a word, or an RGB.
  267. example: [color=#CC00CC]
  268. arglist: A list of arguments from registers/stack addresses. See URL:
  269. https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt
  270. example: cpu=%di:s32
  271. Here is a full example entry. It displays cpu resume calls in the timeline
  272. in orange. They will appear as CPU_ON[0], CPU_ON[1], etc.
  273. [timeline_functions_x86_64]
  274. _cpu_up: CPU_ON[{cpu}] cpu=%di:s32 [color=orange]
  275. Adding or Editing Dev Mode Timeline Source Functions
  276. ____________________________________________________
  277. In dev mode, the tool uses an array of function names to monitor source
  278. execution within the timeline entries.
  279. The function calls are displayed inside the main device/call blocks in the
  280. timeline. However, if a function call is not within a main timeline event,
  281. it will spawn an entirely new event named after the caller's kernel thread.
  282. These asynchronous kernel threads will populate in a separate section
  283. beneath the main device/call section.
  284. The tool has a set of hard coded calls which focus on the most common use
  285. cases: msleep, udelay, schedule_timeout, mutex_lock_slowpath, etc. These are
  286. the functions that add a hardcoded time delay to the suspend/resume path.
  287. The tool also includes some common functions native to important
  288. subsystems: ata, i915, and ACPI, etc.
  289. It is possible to add new function calls to the dev timeline by adding them
  290. to the config. It's also possible to copy the internal dev timeline
  291. functions into the config so that you can override and edit them. Place them
  292. in the dev_timeline_functions_ARCH section with the name of your architecture
  293. appended. i.e. for x86_64: [dev_timeline_functions_x86_64]
  294. Use the override-dev-timeline-functions option if you only want to use your
  295. custom calls, or leave it false to append them to the internal ones.
  296. The format is the same as the timeline_functions_x86_64 section. It's a
  297. list of functions (set using kprobes) which use both symbol data and function
  298. arg data. The args are pulled directly from the stack using this
  299. architecture's registers and stack formatting. Each entry can include up
  300. to four pieces of info: The function name, a format string, an argument list,
  301. and a color. But only the function name is required.
  302. For a full example config, see config/custom-timeline-functions.cfg. It pulls
  303. all the internal dev timeline functions into the config and allows you to edit
  304. them.
  305. Here is a full example entry. It displays the ATA port reset calls as
  306. ataN_port_reset in the timeline. This is where most of the SATA disk resume
  307. time goes, so it can be helpful to see the low level call.
  308. [dev_timeline_functions_x86_64]
  309. ata_eh_recover: ata{port}_port_reset port=+36(%di):s32 [color=#CC00CC]
  310. Verifying your custom functions
  311. _______________________________
  312. Once you have a set of functions (kprobes) defined, it can be useful to
  313. perform a quick check to see if you formatted them correctly and if the system
  314. actually supports them. To do this, run the tool with your config file
  315. and the -status option. The tool will go through all the kprobes (both
  316. custom and internal if you haven't overridden them) and actually attempts
  317. to set them in ftrace. It will then print out success or fail for you.
  318. Note that kprobes which don't actually exist in the kernel won't stop the
  319. tool, they just wont show up.
  320. For example:
  321. sudo ./sleepgraph.py -config config/custom-timeline-functions.cfg -status
  322. Checking this system (myhostname)...
  323. have root access: YES
  324. is sysfs mounted: YES
  325. is "mem" a valid power mode: YES
  326. is ftrace supported: YES
  327. are kprobes supported: YES
  328. timeline data source: FTRACE (all trace events found)
  329. is rtcwake supported: YES
  330. verifying timeline kprobes work:
  331. _cpu_down: YES
  332. _cpu_up: YES
  333. acpi_pm_finish: YES
  334. acpi_pm_prepare: YES
  335. freeze_kernel_threads: YES
  336. freeze_processes: YES
  337. sys_sync: YES
  338. thaw_processes: YES
  339. verifying dev kprobes work:
  340. __const_udelay: YES
  341. __mutex_lock_slowpath: YES
  342. acpi_os_stall: YES
  343. acpi_ps_parse_aml: YES
  344. intel_opregion_init: NO
  345. intel_opregion_register: NO
  346. intel_opregion_setup: NO
  347. msleep: YES
  348. schedule_timeout: YES
  349. schedule_timeout_uninterruptible: YES
  350. usleep_range: YES
  351. ------------------------------------------------------------------
  352. | TESTING ON CONSUMER LINUX OPERATING SYSTEMS |
  353. ------------------------------------------------------------------
  354. Android
  355. _______
  356. The easiest way to execute on an android device is to run the android.sh
  357. script on the device, then pull the ftrace log back to the host and run
  358. sleepgraph.py on it.
  359. Here are the steps:
  360. [download and install the tool on the device]
  361. host%> wget https://raw.githubusercontent.com/intel/pm-graph/master/tools/android.sh
  362. host%> adb connect 192.168.1.6
  363. host%> adb root
  364. # push the script to a writeable location
  365. host%> adb push android.sh /sdcard/
  366. [check whether the tool will run on your device]
  367. host%> adb shell
  368. dev%> cd /sdcard
  369. dev%> sh android.sh status
  370. host : asus_t100
  371. kernel : 3.14.0-i386-dirty
  372. modes : freeze mem
  373. rtcwake : supported
  374. ftrace : supported
  375. trace events {
  376. suspend_resume: found
  377. device_pm_callback_end: found
  378. device_pm_callback_start: found
  379. }
  380. # the above is what you see on a system that's properly patched
  381. [execute the suspend]
  382. # NOTE: The suspend will only work if the screen isn't timed out,
  383. # so you have to press some keys first to wake it up b4 suspend)
  384. dev%> sh android.sh suspend mem
  385. ------------------------------------
  386. Suspend/Resume timing test initiated
  387. ------------------------------------
  388. hostname : asus_t100
  389. kernel : 3.14.0-i386-dirty
  390. mode : mem
  391. ftrace out : /mnt/shell/emulated/0/ftrace.txt
  392. dmesg out : /mnt/shell/emulated/0/dmesg.txt
  393. log file : /mnt/shell/emulated/0/log.txt
  394. ------------------------------------
  395. INITIALIZING FTRACE........DONE
  396. STARTING FTRACE
  397. SUSPEND START @ 21:24:02 (rtcwake in 10 seconds)
  398. <adb connection will now terminate>
  399. [retrieve the data from the device]
  400. # I find that you have to actually kill the adb process and
  401. # reconnect sometimes in order for the connection to work post-suspend
  402. host%> adb connect 192.168.1.6
  403. # (required) get the ftrace data, this is the most important piece
  404. host%> adb pull /sdcard/ftrace.txt
  405. # (optional) get the dmesg data, this is for debugging
  406. host%> adb pull /sdcard/dmesg.txt
  407. # (optional) get the log, which just lists some test times for comparison
  408. host%> adb pull /sdcard/log.txt
  409. [create an output html file using sleepgraph.py]
  410. host%> sleepgraph.py -ftrace ftrace.txt
  411. You should now have an output.html with the android data, enjoy!