1 !! 1 p m - g r a p h
2 _ __ _ __ ___ __ _ _ __ __ _ _ __ <<
3 | '_ \| '_ ` _ \ _____ / _` | '__/ _` | '_ <<
4 | |_) | | | | | |_____| (_| | | | (_| | |_) <<
5 | .__/|_| |_| |_| \__, |_| \__,_| .__ <<
6 |_| |___/ |_| <<
7 2
8 pm-graph: suspend/resume/boot timing analys 3 pm-graph: suspend/resume/boot timing analysis tools
9 Version: 5.11 !! 4 Version: 5.5
10 Author: Todd Brandt <todd.e.brandt@intel.c 5 Author: Todd Brandt <todd.e.brandt@intel.com>
11 Home Page: https://www.intel.com/content/www !! 6 Home Page: https://01.org/pm-graph
12 7
13 Report bugs/issues at bugzilla.kernel.org Too 8 Report bugs/issues at bugzilla.kernel.org Tools/pm-graph
14 - https://bugzilla.kernel.org/buglist. 9 - https://bugzilla.kernel.org/buglist.cgi?component=pm-graph&product=Tools
15 10
16 Full documentation available online & in man 11 Full documentation available online & in man pages
17 - Getting Started: 12 - Getting Started:
18 https://www.intel.com/content/www/us !! 13 https://01.org/pm-graph/documentation/getting-started
19 14
20 - Feature Summary: !! 15 - Config File Format:
21 https://www.intel.com/content/www/us !! 16 https://01.org/pm-graph/documentation/3-config-file-format
22 17
23 - upstream version in git: 18 - upstream version in git:
24 git clone https://github.com/intel/p !! 19 https://github.com/intel/pm-graph/
>> 20
>> 21 Requirements:
>> 22 - runs with python2 or python3, choice is made by /usr/bin/python link
>> 23 - python2 now requires python-configparser be installed
25 24
26 Table of Contents 25 Table of Contents
27 - Overview 26 - Overview
28 - Setup 27 - Setup
29 - Usage 28 - Usage
30 - Basic Usage 29 - Basic Usage
31 - Dev Mode Usage 30 - Dev Mode Usage
32 - Proc Mode Usage 31 - Proc Mode Usage
33 - Endurance Testing <<
34 - Usage Examples <<
35 - Configuration Files 32 - Configuration Files
36 - Usage Examples 33 - Usage Examples
37 - Config File Options 34 - Config File Options
38 - Custom Timeline Entries 35 - Custom Timeline Entries
39 - Adding/Editing Timeline Func 36 - Adding/Editing Timeline Functions
40 - Adding/Editing Dev Timeline 37 - Adding/Editing Dev Timeline Source Functions
41 - Verifying your Custom Functi 38 - Verifying your Custom Functions
42 - Testing on consumer linux Operating 39 - Testing on consumer linux Operating Systems
43 - Android 40 - Android
44 41
45 ---------------------------------------------- 42 ------------------------------------------------------------------
46 | OVERVIEW 43 | OVERVIEW |
47 ---------------------------------------------- 44 ------------------------------------------------------------------
48 45
49 This tool suite is designed to assist kernel 46 This tool suite is designed to assist kernel and OS developers in optimizing
50 their linux stack's suspend/resume & boot tim 47 their linux stack's suspend/resume & boot time. Using a kernel image built
51 with a few extra options enabled, the tools w 48 with a few extra options enabled, the tools will execute a suspend or boot,
52 and will capture dmesg and ftrace data. This 49 and will capture dmesg and ftrace data. This data is transformed into a set of
53 timelines and a callgraph to give a quick and 50 timelines and a callgraph to give a quick and detailed view of which devices
54 and kernel processes are taking the most time 51 and kernel processes are taking the most time in suspend/resume & boot.
55 52
56 ---------------------------------------------- 53 ------------------------------------------------------------------
57 | SETUP 54 | SETUP |
58 ---------------------------------------------- 55 ------------------------------------------------------------------
59 56
60 Package Requirements !! 57 These packages are required to execute the scripts
61 - runs with python2 or python3, choice <<
62 - python 58 - python
63 - python-configparser (for python2 slee !! 59 - python-requests
64 - python-requests (for stresstester.py) <<
65 - linux-tools-common (for turbostat usa <<
66 60
67 Ubuntu: 61 Ubuntu:
68 sudo apt-get install python python-c !! 62 sudo apt-get install python python-requests
69 63
70 Fedora: 64 Fedora:
71 sudo dnf install python python-confi !! 65 sudo dnf install python python-requests
72 66
73 The tools can most easily be installed via 67 The tools can most easily be installed via git clone and make install
74 68
75 $> git clone http://github.com/intel/pm-gr 69 $> git clone http://github.com/intel/pm-graph.git
76 $> cd pm-graph 70 $> cd pm-graph
77 $> sudo make install 71 $> sudo make install
78 $> man sleepgraph ; man bootgraph 72 $> man sleepgraph ; man bootgraph
79 73
80 Setup involves some minor kernel configura 74 Setup involves some minor kernel configuration
81 75
82 The following kernel build options are req 76 The following kernel build options are required for all kernels:
83 CONFIG_DEVMEM=y 77 CONFIG_DEVMEM=y
84 CONFIG_PM_DEBUG=y 78 CONFIG_PM_DEBUG=y
85 CONFIG_PM_SLEEP_DEBUG=y 79 CONFIG_PM_SLEEP_DEBUG=y
86 CONFIG_FTRACE=y 80 CONFIG_FTRACE=y
87 CONFIG_FUNCTION_TRACER=y 81 CONFIG_FUNCTION_TRACER=y
88 CONFIG_FUNCTION_GRAPH_TRACER=y 82 CONFIG_FUNCTION_GRAPH_TRACER=y
89 CONFIG_KPROBES=y 83 CONFIG_KPROBES=y
90 CONFIG_KPROBES_ON_FTRACE=y 84 CONFIG_KPROBES_ON_FTRACE=y
91 85
92 In kernel 3.15.0, two patches were ups 86 In kernel 3.15.0, two patches were upstreamed which enable the
93 v3.0 behavior. These patches allow the 87 v3.0 behavior. These patches allow the tool to read all the
94 data from trace events instead of from 88 data from trace events instead of from dmesg. You can enable
95 this behavior on earlier kernels with 89 this behavior on earlier kernels with these patches:
96 90
97 (kernel/pre-3.15/enable_trace_events_s 91 (kernel/pre-3.15/enable_trace_events_suspend_resume.patch)
98 (kernel/pre-3.15/enable_trace_events_d 92 (kernel/pre-3.15/enable_trace_events_device_pm_callback.patch)
99 93
100 If you're using bootgraph, or sleepgra !! 94 If you're using a kernel older than 3.15.0, the following
101 the following additional kerne !! 95 additional kernel parameters are required:
102 (e.g. in file /etc/default/grub) 96 (e.g. in file /etc/default/grub)
103 GRUB_CMDLINE_LINUX_DEFAULT="... initca 97 GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=32M ..."
104 98
105 If you're using a kernel older than 3. 99 If you're using a kernel older than 3.11-rc2, the following simple
106 patch must be applied to enabl 100 patch must be applied to enable ftrace data:
107 in file: kernel/power/suspend.c 101 in file: kernel/power/suspend.c
108 in function: int suspend_devices_and_e 102 in function: int suspend_devices_and_enter(suspend_state_t state)
109 remove call to "ftrace_stop();" 103 remove call to "ftrace_stop();"
110 remove call to "ftrace_start();" 104 remove call to "ftrace_start();"
111 105
112 There is a patch which does this for k 106 There is a patch which does this for kernel v3.8.0:
113 (kernel/pre-3.11-rc2/enable_ftrace_in_ 107 (kernel/pre-3.11-rc2/enable_ftrace_in_suspendresume.patch)
114 108
115 109
116 110
117 ---------------------------------------------- 111 ------------------------------------------------------------------
118 | USAGE 112 | USAGE |
119 ---------------------------------------------- 113 ------------------------------------------------------------------
120 114
121 Basic Usage 115 Basic Usage
122 ___________ 116 ___________
123 117
124 1) First configure a kernel using the instruc 118 1) First configure a kernel using the instructions from the previous sections.
125 Then build, install, and boot with it. 119 Then build, install, and boot with it.
126 2) Open up a terminal window and execute the 120 2) Open up a terminal window and execute the mode list command:
127 121
128 %> sudo ./sleepgraph.py -modes 122 %> sudo ./sleepgraph.py -modes
129 ['freeze', 'mem', 'disk'] 123 ['freeze', 'mem', 'disk']
130 124
131 Execute a test using one of the available pow 125 Execute a test using one of the available power modes, e.g. mem (S3):
132 126
133 %> sudo ./sleepgraph.py -m mem -rtcwak 127 %> sudo ./sleepgraph.py -m mem -rtcwake 15
134 128
135 or with a config file 129 or with a config file
136 130
137 %> sudo ./sleepgraph.py -config config 131 %> sudo ./sleepgraph.py -config config/suspend.cfg
138 132
139 When the system comes back you'll see the scr 133 When the system comes back you'll see the script finishing up and
140 creating the output files in the test subdir. 134 creating the output files in the test subdir. It generates output
141 files in subdirectory: suspend-mmddyy-HHMMSS. 135 files in subdirectory: suspend-mmddyy-HHMMSS. The ftrace file can
142 be used to regenerate the html timeline with 136 be used to regenerate the html timeline with different options
143 137
144 HTML output: <hostname 138 HTML output: <hostname>_<mode>.html
145 raw dmesg output: <hostname 139 raw dmesg output: <hostname>_<mode>_dmesg.txt
146 raw ftrace output: <hostname 140 raw ftrace output: <hostname>_<mode>_ftrace.txt
147 141
148 View the html in firefox or chrome. 142 View the html in firefox or chrome.
149 143
150 144
151 Dev Mode Usage 145 Dev Mode Usage
152 ______________ 146 ______________
153 147
154 Developer mode adds information on low level 148 Developer mode adds information on low level source calls to the timeline.
155 The tool sets kprobes on all delay and mutex 149 The tool sets kprobes on all delay and mutex calls to see which devices
156 are waiting for something and when. It also s 150 are waiting for something and when. It also sets a suite of kprobes on
157 subsystem dependent calls to better fill out 151 subsystem dependent calls to better fill out the timeline.
158 152
159 The tool will also expose kernel threads that 153 The tool will also expose kernel threads that don't normally show up in the
160 timeline. This is useful in discovering depen 154 timeline. This is useful in discovering dependent threads to get a better
161 idea of what each device is waiting for. For 155 idea of what each device is waiting for. For instance, the scsi_eh thread,
162 a.k.a. scsi resume error handler, is what eac 156 a.k.a. scsi resume error handler, is what each SATA disk device waits for
163 before it can continue resume. 157 before it can continue resume.
164 158
165 The timeline will be much larger if run with 159 The timeline will be much larger if run with dev mode, so it can be useful
166 to set the -mindev option to clip out any dev 160 to set the -mindev option to clip out any device blocks that are too small
167 to see easily. The following command will giv 161 to see easily. The following command will give a nice dev mode run:
168 162
169 %> sudo ./sleepgraph.py -m mem -rtcwake 15 -m 163 %> sudo ./sleepgraph.py -m mem -rtcwake 15 -mindev 1 -dev
170 164
171 or with a config file 165 or with a config file
172 166
173 %> sudo ./sleepgraph.py -config config/suspen 167 %> sudo ./sleepgraph.py -config config/suspend-dev.cfg
174 168
175 169
176 Proc Mode Usage 170 Proc Mode Usage
177 _______________ 171 _______________
178 172
179 Proc mode adds user process info to the timel 173 Proc mode adds user process info to the timeline. This is done in a manner
180 similar to the bootchart utility, which graph 174 similar to the bootchart utility, which graphs init processes and their
181 execution as the system boots. This tool opti 175 execution as the system boots. This tool option does the same thing but for
182 the period before and after suspend/resume. 176 the period before and after suspend/resume.
183 177
184 In order to see any process info, there needs 178 In order to see any process info, there needs to be some delay before or
185 after resume since processes are frozen in su 179 after resume since processes are frozen in suspend_prepare and thawed in
186 resume_complete. The predelay and postdelay a 180 resume_complete. The predelay and postdelay args allow you to do this. It
187 can also be useful to run in x2 mode with an 181 can also be useful to run in x2 mode with an x2 delay, this way you can
188 see process activity before and after resume, 182 see process activity before and after resume, and in between two
189 successive suspend/resumes. 183 successive suspend/resumes.
190 184
191 The command can be run like this: 185 The command can be run like this:
192 186
193 %> sudo ./sleepgraph.py -m mem -rtcwake 15 -x 187 %> sudo ./sleepgraph.py -m mem -rtcwake 15 -x2 -x2delay 1000 -predelay 1000 -postdelay 1000 -proc
194 188
195 or with a config file 189 or with a config file
196 190
197 %> sudo ./sleepgraph.py -config config/suspen 191 %> sudo ./sleepgraph.py -config config/suspend-proc.cfg
198 192
199 ---------------------------------------------- <<
200 | ENDURANCE TESTING <<
201 ---------------------------------------------- <<
202 <<
203 The best way to gauge the health of a system <<
204 suspend/resumes over an extended period and a <<
205 accomplished with sleepgraph's -multi argumen <<
206 number of tests to run OR the duration in day <<
207 delay in seconds between them. For instance, <<
208 a 5 second delay between each, or -multi 24h <<
209 period with no delay between tests. You can i <<
210 to generate the data you want. It's most usef <<
211 as the kprobes don't alter the performance mu <<
212 <<
213 On completion, the output folder contains a s <<
214 individual test data and a set of summary pag <<
215 file is a tabular list of the tests with rele <<
216 summary-issue.html and summary-devices.html f <<
217 all tests on kernel issues and device perform <<
218 <<
219 suspend-xN-{date}-{time}: <<
220 summary.html <<
221 summary-issues.html <<
222 summary-devices.html <<
223 suspend-{date}-{time} (1) <<
224 suspend-{date}-{time} (2) <<
225 ... <<
226 <<
227 These are the relevant arguments to use for t <<
228 <<
229 -m mode <<
230 Mode to initiate for suspend e.g. mem, <<
231 <<
232 -rtcwake t <<
233 Use rtcwake to autoresume after t seco <<
234 <<
235 -gzip (optional) <<
236 Gzip the trace and dmesg logs to save <<
237 gzipped logs for processing. This redu <<
238 <<
239 -dev (optional) <<
240 Add kernel source calls and threads to <<
241 <<
242 -multi n d <<
243 Execute n consecutive tests at d secon <<
244 created in a new subdirectory: suspend <<
245 run is done, the -summary command is c <<
246 html files for all the data (unless yo <<
247 speed up the testing by not creating t <<
248 can then run the tool again at a later <<
249 create the timelines. <<
250 <<
251 -skiphtml (optional) <<
252 Run the test and capture the trace log <<
253 html generation. This can greatly spee <<
254 copy the data to a faster host machine <<
255 generate the timelines and summary. <<
256 <<
257 These are the relevant commands to use after <<
258 <<
259 -summary indir <<
260 Generate or regenerate the summary for <<
261 files: summary.html, summary-issues.ht <<
262 current folder. summary.html is a tabl <<
263 by kernel/host/mode, and links to the <<
264 is a list of kernel issues found in dm <<
265 summary-devices.html is a list of devi <<
266 <<
267 -genhtml <<
268 Used with -summary to regenerate any <<
269 dmesg and ftrace logs. This will requi <<
270 there are thousands of tests. <<
271 <<
272 Usage Examples <<
273 _______________ <<
274 <<
275 A multitest is initiated like this: <<
276 <<
277 %> sudo ./sleepgraph.py -m mem -rtcwake 10 - <<
278 <<
279 or you can skip timeline generation in <<
280 <<
281 %> sudo ./sleepgraph.py -m mem -rtcwake 10 - <<
282 <<
283 The tool will produce an output folder with a <<
284 Each test subfolder contains the dmesg/ftrace <<
285 depending on whether you used the -skiphtml o <<
286 the summary.html files. <<
287 <<
288 The summary for an existing multitest is gene <<
289 <<
290 %> cd suspend-x2000-{date}-{time} <<
291 %> sleepgraph.py -summary . <<
292 <<
293 or if you need to generate the html ti <<
294 <<
295 %> cd suspend-xN-{date}-{time} <<
296 %> sleepgraph.py -summary . -genhtml <<
297 193
298 ---------------------------------------------- 194 ------------------------------------------------------------------
299 | CONFIGURATION FILES 195 | CONFIGURATION FILES |
300 ---------------------------------------------- 196 ------------------------------------------------------------------
301 197
302 Since 4.0 we've moved to using config files i 198 Since 4.0 we've moved to using config files in lieu of command line options.
303 The config folder contains a collection of ty 199 The config folder contains a collection of typical use cases.
304 There are corresponding configs for other pow 200 There are corresponding configs for other power modes:
305 201
306 Simple suspend/resume with basic timel 202 Simple suspend/resume with basic timeline (mem/freeze/standby)
307 config/suspend.cfg 203 config/suspend.cfg
308 config/freeze.cfg 204 config/freeze.cfg
309 config/standby.cfg 205 config/standby.cfg
310 206
311 Dev mode suspend/resume with dev timel 207 Dev mode suspend/resume with dev timeline (mem/freeze/standby)
312 config/suspend-dev.cfg 208 config/suspend-dev.cfg
313 config/freeze-dev.cfg 209 config/freeze-dev.cfg
314 config/standby-dev.cfg 210 config/standby-dev.cfg
315 211
316 Simple suspend/resume with timeline an 212 Simple suspend/resume with timeline and callgraph (mem/freeze/standby)
317 config/suspend-callgraph.cfg 213 config/suspend-callgraph.cfg
318 config/freeze-callgraph.cfg 214 config/freeze-callgraph.cfg
319 config/standby-callgraph.cfg 215 config/standby-callgraph.cfg
320 216
321 Sample proc mode x2 run using mem susp 217 Sample proc mode x2 run using mem suspend
322 config/suspend-x2-proc.cfg 218 config/suspend-x2-proc.cfg
323 219
324 Sample for editing timeline funcs (mov 220 Sample for editing timeline funcs (moves internal functions into config)
325 config/custom-timeline-functio 221 config/custom-timeline-functions.cfg
326 222
327 Sample debug config for serio subsyste 223 Sample debug config for serio subsystem
328 config/debug-serio-suspend.cfg 224 config/debug-serio-suspend.cfg
329 225
330 226
331 Usage Examples 227 Usage Examples
332 ______________ 228 ______________
333 229
334 Run a simple mem suspend: 230 Run a simple mem suspend:
335 %> sudo ./sleepgraph.py -config config/suspen 231 %> sudo ./sleepgraph.py -config config/suspend.cfg
336 232
337 Run a mem suspend with callgraph data: 233 Run a mem suspend with callgraph data:
338 %> sudo ./sleepgraph.py -config config/suspen 234 %> sudo ./sleepgraph.py -config config/suspend-callgraph.cfg
339 235
340 Run a mem suspend with dev mode detail: 236 Run a mem suspend with dev mode detail:
341 %> sudo ./sleepgraph.py -config config/suspen 237 %> sudo ./sleepgraph.py -config config/suspend-dev.cfg
342 238
343 239
344 Config File Options 240 Config File Options
345 ___________________ 241 ___________________
346 242
347 [Settings] 243 [Settings]
348 244
349 # Verbosity: print verbose messages (def: fal 245 # Verbosity: print verbose messages (def: false)
350 verbose: false 246 verbose: false
351 247
352 # Suspend Mode: e.g. standby, mem, freeze, di 248 # Suspend Mode: e.g. standby, mem, freeze, disk (def: mem)
353 mode: mem 249 mode: mem
354 250
355 # Output Directory Format: {hostname}, {date} 251 # Output Directory Format: {hostname}, {date}, {time} give current values
356 output-dir: suspend-{hostname}-{date}-{time} 252 output-dir: suspend-{hostname}-{date}-{time}
357 253
358 # Automatic Wakeup: use rtcwake to wakeup aft 254 # Automatic Wakeup: use rtcwake to wakeup after X seconds (def: infinity)
359 rtcwake: 15 255 rtcwake: 15
360 256
361 # Add Logs: add the dmesg and ftrace log to t 257 # Add Logs: add the dmesg and ftrace log to the html output (def: false)
362 addlogs: false 258 addlogs: false
363 259
364 # Sus/Res Gap: insert a gap between sus & res 260 # Sus/Res Gap: insert a gap between sus & res in the timeline (def: false)
365 srgap: false 261 srgap: false
366 262
367 # Custom Command: Command to execute in lieu 263 # Custom Command: Command to execute in lieu of suspend (def: "")
368 command: echo mem > /sys/power/state 264 command: echo mem > /sys/power/state
369 265
370 # Proc mode: graph user processes and cpu usa 266 # Proc mode: graph user processes and cpu usage in the timeline (def: false)
371 proc: false 267 proc: false
372 268
373 # Dev mode: graph source functions in the tim 269 # Dev mode: graph source functions in the timeline (def: false)
374 dev: false 270 dev: false
375 271
376 # Suspend/Resume x2: run 2 suspend/resumes ba 272 # Suspend/Resume x2: run 2 suspend/resumes back to back (def: false)
377 x2: false 273 x2: false
378 274
379 # x2 Suspend Delay: time delay between the tw 275 # x2 Suspend Delay: time delay between the two test runs in ms (def: 0 ms)
380 x2delay: 0 276 x2delay: 0
381 277
382 # Pre Suspend Delay: nclude an N ms delay bef 278 # Pre Suspend Delay: nclude an N ms delay before (1st) suspend (def: 0 ms)
383 predelay: 0 279 predelay: 0
384 280
385 # Post Resume Delay: include an N ms delay af 281 # Post Resume Delay: include an N ms delay after (last) resume (def: 0 ms)
386 postdelay: 0 282 postdelay: 0
387 283
388 # Min Device Length: graph only dev callbacks 284 # Min Device Length: graph only dev callbacks longer than min (def: 0.001 ms)
389 mindev: 0.001 285 mindev: 0.001
390 286
391 # Callgraph: gather ftrace callgraph data on 287 # Callgraph: gather ftrace callgraph data on all timeline events (def: false)
392 callgraph: false 288 callgraph: false
393 289
394 # Expand Callgraph: pre-expand the callgraph 290 # Expand Callgraph: pre-expand the callgraph treeviews in html (def: false)
395 expandcg: false 291 expandcg: false
396 292
397 # Min Callgraph Length: show callgraphs only 293 # Min Callgraph Length: show callgraphs only if longer than min (def: 1 ms)
398 mincg: 1 294 mincg: 1
399 295
400 # Timestamp Precision: number of sig digits i 296 # Timestamp Precision: number of sig digits in timestamps (0:S, [3:ms], 6:us)
401 timeprec: 3 297 timeprec: 3
402 298
403 # Device Filter: show only devs whose name/dr 299 # Device Filter: show only devs whose name/driver includes one of these strings
404 devicefilter: _cpu_up,_cpu_down,i915,usb 300 devicefilter: _cpu_up,_cpu_down,i915,usb
405 301
406 # Override default timeline entries: 302 # Override default timeline entries:
407 # Do not use the internal default functions f 303 # Do not use the internal default functions for timeline entries (def: false)
408 # Set this to true if you intend to only use 304 # Set this to true if you intend to only use the ones defined in the config
409 override-timeline-functions: true 305 override-timeline-functions: true
410 306
411 # Override default dev timeline entries: 307 # Override default dev timeline entries:
412 # Do not use the internal default functions f 308 # Do not use the internal default functions for dev timeline entries (def: false)
413 # Set this to true if you intend to only use 309 # Set this to true if you intend to only use the ones defined in the config
414 override-dev-timeline-functions: true 310 override-dev-timeline-functions: true
415 311
416 # Call Loop Max Gap (dev mode only) 312 # Call Loop Max Gap (dev mode only)
417 # merge loops of the same call if each is les 313 # merge loops of the same call if each is less than maxgap apart (def: 100us)
418 callloop-maxgap: 0.0001 314 callloop-maxgap: 0.0001
419 315
420 # Call Loop Max Length (dev mode only) 316 # Call Loop Max Length (dev mode only)
421 # merge loops of the same call if each is les 317 # merge loops of the same call if each is less than maxlen in length (def: 5ms)
422 callloop-maxlen: 0.005 318 callloop-maxlen: 0.005
423 319
424 ---------------------------------------------- 320 ------------------------------------------------------------------
425 | CUSTOM TIMELINE ENTRIES 321 | CUSTOM TIMELINE ENTRIES |
426 ---------------------------------------------- 322 ------------------------------------------------------------------
427 323
428 Adding or Editing Timeline Functions 324 Adding or Editing Timeline Functions
429 ____________________________________ 325 ____________________________________
430 326
431 The tool uses an array of function names to f 327 The tool uses an array of function names to fill out empty spaces in the
432 timeline where device callbacks don't appear. 328 timeline where device callbacks don't appear. For instance, in suspend_prepare
433 the tool adds the sys_sync and freeze_process 329 the tool adds the sys_sync and freeze_processes calls as virtual device blocks
434 in the timeline to show you where the time is 330 in the timeline to show you where the time is going. These calls should fill
435 the timeline with contiguous data so that mos 331 the timeline with contiguous data so that most kernel execution is covered.
436 332
437 It is possible to add new function calls to t 333 It is possible to add new function calls to the timeline by adding them to
438 the config. It's also possible to copy the in 334 the config. It's also possible to copy the internal timeline functions into
439 the config so that you can override and edit 335 the config so that you can override and edit them. Place them in the
440 timeline_functions_ARCH section with the name 336 timeline_functions_ARCH section with the name of your architecture appended.
441 i.e. for x86_64: [timeline_functions_x86_64] 337 i.e. for x86_64: [timeline_functions_x86_64]
442 338
443 Use the override-timeline-functions option if 339 Use the override-timeline-functions option if you only want to use your
444 custom calls, or leave it false to append the 340 custom calls, or leave it false to append them to the internal ones.
445 341
446 This section includes a list of functions (se 342 This section includes a list of functions (set using kprobes) which use both
447 symbol data and function arg data. The args a 343 symbol data and function arg data. The args are pulled directly from the
448 stack using this architecture's registers and 344 stack using this architecture's registers and stack formatting. Each entry
449 can include up to four pieces of info: The fu 345 can include up to four pieces of info: The function name, a format string,
450 an argument list, and a color. But only a fun 346 an argument list, and a color. But only a function name is required.
451 347
452 For a full example config, see config/custom- 348 For a full example config, see config/custom-timeline-functions.cfg. It pulls
453 all the internal timeline functions into the 349 all the internal timeline functions into the config and allows you to edit
454 them. 350 them.
455 351
456 Entry format: 352 Entry format:
457 353
458 function: format{fn_arg1}_{fn_arg2} fn_arg 354 function: format{fn_arg1}_{fn_arg2} fn_arg1 fn_arg2 ... [color=purple]
459 355
460 Required Arguments: 356 Required Arguments:
461 357
462 function: The symbol name for the function 358 function: The symbol name for the function you want probed, this is the
463 minimum required for an entry, i 359 minimum required for an entry, it will show up as the function
464 name with no arguments. 360 name with no arguments.
465 361
466 example: _cpu_up: 362 example: _cpu_up:
467 363
468 Optional Arguments: 364 Optional Arguments:
469 365
470 format: The format to display the data on 366 format: The format to display the data on the timeline in. Use braces to
471 enclose the arg names. 367 enclose the arg names.
472 368
473 example: CPU_ON[{cpu}] 369 example: CPU_ON[{cpu}]
474 370
475 color: The color of the entry block in the 371 color: The color of the entry block in the timeline. The default color is
476 transparent, so the entry shares th 372 transparent, so the entry shares the phase color. The color is an
477 html color string, either a word, o 373 html color string, either a word, or an RGB.
478 374
479 example: [color=#CC00CC] 375 example: [color=#CC00CC]
480 376
481 arglist: A list of arguments from register 377 arglist: A list of arguments from registers/stack addresses. See URL:
482 https://www.kernel.org/doc/Docume 378 https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt
483 379
484 example: cpu=%di:s32 380 example: cpu=%di:s32
485 381
486 Here is a full example entry. It displays cpu 382 Here is a full example entry. It displays cpu resume calls in the timeline
487 in orange. They will appear as CPU_ON[0], CPU 383 in orange. They will appear as CPU_ON[0], CPU_ON[1], etc.
488 384
489 [timeline_functions_x86_64] 385 [timeline_functions_x86_64]
490 _cpu_up: CPU_ON[{cpu}] cpu=%di:s32 [color=or 386 _cpu_up: CPU_ON[{cpu}] cpu=%di:s32 [color=orange]
491 387
492 388
493 Adding or Editing Dev Mode Timeline Source Fun 389 Adding or Editing Dev Mode Timeline Source Functions
494 ______________________________________________ 390 ____________________________________________________
495 391
496 In dev mode, the tool uses an array of functi 392 In dev mode, the tool uses an array of function names to monitor source
497 execution within the timeline entries. 393 execution within the timeline entries.
498 394
499 The function calls are displayed inside the m 395 The function calls are displayed inside the main device/call blocks in the
500 timeline. However, if a function call is not 396 timeline. However, if a function call is not within a main timeline event,
501 it will spawn an entirely new event named aft 397 it will spawn an entirely new event named after the caller's kernel thread.
502 These asynchronous kernel threads will popula 398 These asynchronous kernel threads will populate in a separate section
503 beneath the main device/call section. 399 beneath the main device/call section.
504 400
505 The tool has a set of hard coded calls which 401 The tool has a set of hard coded calls which focus on the most common use
506 cases: msleep, udelay, schedule_timeout, mute 402 cases: msleep, udelay, schedule_timeout, mutex_lock_slowpath, etc. These are
507 the functions that add a hardcoded time delay 403 the functions that add a hardcoded time delay to the suspend/resume path.
508 The tool also includes some common functions 404 The tool also includes some common functions native to important
509 subsystems: ata, i915, and ACPI, etc. 405 subsystems: ata, i915, and ACPI, etc.
510 406
511 It is possible to add new function calls to t 407 It is possible to add new function calls to the dev timeline by adding them
512 to the config. It's also possible to copy the 408 to the config. It's also possible to copy the internal dev timeline
513 functions into the config so that you can ove 409 functions into the config so that you can override and edit them. Place them
514 in the dev_timeline_functions_ARCH section wi 410 in the dev_timeline_functions_ARCH section with the name of your architecture
515 appended. i.e. for x86_64: [dev_timeline_func 411 appended. i.e. for x86_64: [dev_timeline_functions_x86_64]
516 412
517 Use the override-dev-timeline-functions optio 413 Use the override-dev-timeline-functions option if you only want to use your
518 custom calls, or leave it false to append the 414 custom calls, or leave it false to append them to the internal ones.
519 415
520 The format is the same as the timeline_functi 416 The format is the same as the timeline_functions_x86_64 section. It's a
521 list of functions (set using kprobes) which u 417 list of functions (set using kprobes) which use both symbol data and function
522 arg data. The args are pulled directly from t 418 arg data. The args are pulled directly from the stack using this
523 architecture's registers and stack formatting 419 architecture's registers and stack formatting. Each entry can include up
524 to four pieces of info: The function name, a 420 to four pieces of info: The function name, a format string, an argument list,
525 and a color. But only the function name is re 421 and a color. But only the function name is required.
526 422
527 For a full example config, see config/custom- 423 For a full example config, see config/custom-timeline-functions.cfg. It pulls
528 all the internal dev timeline functions into 424 all the internal dev timeline functions into the config and allows you to edit
529 them. 425 them.
530 426
531 Here is a full example entry. It displays the 427 Here is a full example entry. It displays the ATA port reset calls as
532 ataN_port_reset in the timeline. This is wher 428 ataN_port_reset in the timeline. This is where most of the SATA disk resume
533 time goes, so it can be helpful to see the lo 429 time goes, so it can be helpful to see the low level call.
534 430
535 [dev_timeline_functions_x86_64] 431 [dev_timeline_functions_x86_64]
536 ata_eh_recover: ata{port}_port_reset port=+3 432 ata_eh_recover: ata{port}_port_reset port=+36(%di):s32 [color=#CC00CC]
537 433
538 434
539 Verifying your custom functions 435 Verifying your custom functions
540 _______________________________ 436 _______________________________
541 437
542 Once you have a set of functions (kprobes) de 438 Once you have a set of functions (kprobes) defined, it can be useful to
543 perform a quick check to see if you formatted 439 perform a quick check to see if you formatted them correctly and if the system
544 actually supports them. To do this, run the t 440 actually supports them. To do this, run the tool with your config file
545 and the -status option. The tool will go thro 441 and the -status option. The tool will go through all the kprobes (both
546 custom and internal if you haven't overridden 442 custom and internal if you haven't overridden them) and actually attempts
547 to set them in ftrace. It will then print out 443 to set them in ftrace. It will then print out success or fail for you.
548 444
549 Note that kprobes which don't actually exist 445 Note that kprobes which don't actually exist in the kernel won't stop the
550 tool, they just wont show up. 446 tool, they just wont show up.
551 447
552 For example: 448 For example:
553 449
554 sudo ./sleepgraph.py -config config/custom-ti 450 sudo ./sleepgraph.py -config config/custom-timeline-functions.cfg -status
555 Checking this system (myhostname)... 451 Checking this system (myhostname)...
556 have root access: YES 452 have root access: YES
557 is sysfs mounted: YES 453 is sysfs mounted: YES
558 is "mem" a valid power mode: YES 454 is "mem" a valid power mode: YES
559 is ftrace supported: YES 455 is ftrace supported: YES
560 are kprobes supported: YES 456 are kprobes supported: YES
561 timeline data source: FTRACE (all trace ev 457 timeline data source: FTRACE (all trace events found)
562 is rtcwake supported: YES 458 is rtcwake supported: YES
563 verifying timeline kprobes work: 459 verifying timeline kprobes work:
564 _cpu_down: YES 460 _cpu_down: YES
565 _cpu_up: YES 461 _cpu_up: YES
566 acpi_pm_finish: YES 462 acpi_pm_finish: YES
567 acpi_pm_prepare: YES 463 acpi_pm_prepare: YES
568 freeze_kernel_threads: YES 464 freeze_kernel_threads: YES
569 freeze_processes: YES 465 freeze_processes: YES
570 sys_sync: YES 466 sys_sync: YES
571 thaw_processes: YES 467 thaw_processes: YES
572 verifying dev kprobes work: 468 verifying dev kprobes work:
573 __const_udelay: YES 469 __const_udelay: YES
574 __mutex_lock_slowpath: YES 470 __mutex_lock_slowpath: YES
575 acpi_os_stall: YES 471 acpi_os_stall: YES
576 acpi_ps_parse_aml: YES 472 acpi_ps_parse_aml: YES
577 intel_opregion_init: NO 473 intel_opregion_init: NO
578 intel_opregion_register: NO 474 intel_opregion_register: NO
579 intel_opregion_setup: NO 475 intel_opregion_setup: NO
580 msleep: YES 476 msleep: YES
581 schedule_timeout: YES 477 schedule_timeout: YES
582 schedule_timeout_uninterruptible: YES 478 schedule_timeout_uninterruptible: YES
583 usleep_range: YES 479 usleep_range: YES
584 480
585 481
586 ---------------------------------------------- 482 ------------------------------------------------------------------
587 | TESTING ON CONSUMER LINUX OPERATIN 483 | TESTING ON CONSUMER LINUX OPERATING SYSTEMS |
588 ---------------------------------------------- 484 ------------------------------------------------------------------
589 485
590 Android 486 Android
591 _______ 487 _______
592 488
593 The easiest way to execute on an android devi 489 The easiest way to execute on an android device is to run the android.sh
594 script on the device, then pull the ftrace lo 490 script on the device, then pull the ftrace log back to the host and run
595 sleepgraph.py on it. 491 sleepgraph.py on it.
596 492
597 Here are the steps: 493 Here are the steps:
598 494
599 [download and install the tool on the device] 495 [download and install the tool on the device]
600 496
601 host%> wget https://raw.githubusercont 497 host%> wget https://raw.githubusercontent.com/intel/pm-graph/master/tools/android.sh
602 host%> adb connect 192.168.1.6 498 host%> adb connect 192.168.1.6
603 host%> adb root 499 host%> adb root
604 # push the script to a writeable locat 500 # push the script to a writeable location
605 host%> adb push android.sh /sdcard/ 501 host%> adb push android.sh /sdcard/
606 502
607 [check whether the tool will run on your devi 503 [check whether the tool will run on your device]
608 504
609 host%> adb shell 505 host%> adb shell
610 dev%> cd /sdcard 506 dev%> cd /sdcard
611 dev%> sh android.sh status 507 dev%> sh android.sh status
612 host : asus_t100 508 host : asus_t100
613 kernel : 3.14.0-i386-dirty 509 kernel : 3.14.0-i386-dirty
614 modes : freeze mem 510 modes : freeze mem
615 rtcwake : supported 511 rtcwake : supported
616 ftrace : supported 512 ftrace : supported
617 trace events { 513 trace events {
618 suspend_resume: found 514 suspend_resume: found
619 device_pm_callback_end: fo 515 device_pm_callback_end: found
620 device_pm_callback_start: 516 device_pm_callback_start: found
621 } 517 }
622 # the above is what you see on a syste 518 # the above is what you see on a system that's properly patched
623 519
624 [execute the suspend] 520 [execute the suspend]
625 521
626 # NOTE: The suspend will only work if 522 # NOTE: The suspend will only work if the screen isn't timed out,
627 # so you have to press some keys first 523 # so you have to press some keys first to wake it up b4 suspend)
628 dev%> sh android.sh suspend mem 524 dev%> sh android.sh suspend mem
629 ------------------------------------ 525 ------------------------------------
630 Suspend/Resume timing test initiated 526 Suspend/Resume timing test initiated
631 ------------------------------------ 527 ------------------------------------
632 hostname : asus_t100 528 hostname : asus_t100
633 kernel : 3.14.0-i386-dirty 529 kernel : 3.14.0-i386-dirty
634 mode : mem 530 mode : mem
635 ftrace out : /mnt/shell/emulated/0/ftr 531 ftrace out : /mnt/shell/emulated/0/ftrace.txt
636 dmesg out : /mnt/shell/emulated/0/dme 532 dmesg out : /mnt/shell/emulated/0/dmesg.txt
637 log file : /mnt/shell/emulated/0/log 533 log file : /mnt/shell/emulated/0/log.txt
638 ------------------------------------ 534 ------------------------------------
639 INITIALIZING FTRACE........DONE 535 INITIALIZING FTRACE........DONE
640 STARTING FTRACE 536 STARTING FTRACE
641 SUSPEND START @ 21:24:02 (rtcwake in 1 537 SUSPEND START @ 21:24:02 (rtcwake in 10 seconds)
642 <adb connection will now terminate> 538 <adb connection will now terminate>
643 539
644 [retrieve the data from the device] 540 [retrieve the data from the device]
645 541
646 # I find that you have to actually kil 542 # I find that you have to actually kill the adb process and
647 # reconnect sometimes in order for the 543 # reconnect sometimes in order for the connection to work post-suspend
648 host%> adb connect 192.168.1.6 544 host%> adb connect 192.168.1.6
649 # (required) get the ftrace data, this 545 # (required) get the ftrace data, this is the most important piece
650 host%> adb pull /sdcard/ftrace.txt 546 host%> adb pull /sdcard/ftrace.txt
651 # (optional) get the dmesg data, this 547 # (optional) get the dmesg data, this is for debugging
652 host%> adb pull /sdcard/dmesg.txt 548 host%> adb pull /sdcard/dmesg.txt
653 # (optional) get the log, which just l 549 # (optional) get the log, which just lists some test times for comparison
654 host%> adb pull /sdcard/log.txt 550 host%> adb pull /sdcard/log.txt
655 551
656 [create an output html file using sleepgraph. 552 [create an output html file using sleepgraph.py]
657 553
658 host%> sleepgraph.py -ftrace ftrace.tx 554 host%> sleepgraph.py -ftrace ftrace.txt
659 555
660 You should now have an output.html with the a 556 You should now have an output.html with the android data, enjoy!
Linux® is a registered trademark of Linus Torvalds in the United States and other countries.
TOMOYO® is a registered trademark of NTT DATA CORPORATION.