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