1 2 _ __ _ __ ___ __ _ _ __ __ _ _ __ 3 | '_ \| '_ ` _ \ _____ / _` | '__/ _` | '_ 4 | |_) | | | | | |_____| (_| | | | (_| | |_) 5 | .__/|_| |_| |_| \__, |_| \__,_| .__ 6 |_| |___/ |_| 7 8 pm-graph: suspend/resume/boot timing analys 9 Version: 5.11 10 Author: Todd Brandt <todd.e.brandt@intel.c 11 Home Page: https://www.intel.com/content/www 12 13 Report bugs/issues at bugzilla.kernel.org Too 14 - https://bugzilla.kernel.org/buglist. 15 16 Full documentation available online & in man 17 - Getting Started: 18 https://www.intel.com/content/www/us 19 20 - Feature Summary: 21 https://www.intel.com/content/www/us 22 23 - upstream version in git: 24 git clone https://github.com/intel/p 25 26 Table of Contents 27 - Overview 28 - Setup 29 - Usage 30 - Basic Usage 31 - Dev Mode Usage 32 - Proc Mode Usage 33 - Endurance Testing 34 - Usage Examples 35 - Configuration Files 36 - Usage Examples 37 - Config File Options 38 - Custom Timeline Entries 39 - Adding/Editing Timeline Func 40 - Adding/Editing Dev Timeline 41 - Verifying your Custom Functi 42 - Testing on consumer linux Operating 43 - Android 44 45 ---------------------------------------------- 46 | OVERVIEW 47 ---------------------------------------------- 48 49 This tool suite is designed to assist kernel 50 their linux stack's suspend/resume & boot tim 51 with a few extra options enabled, the tools w 52 and will capture dmesg and ftrace data. This 53 timelines and a callgraph to give a quick and 54 and kernel processes are taking the most time 55 56 ---------------------------------------------- 57 | SETUP 58 ---------------------------------------------- 59 60 Package Requirements 61 - runs with python2 or python3, choice 62 - python 63 - python-configparser (for python2 slee 64 - python-requests (for stresstester.py) 65 - linux-tools-common (for turbostat usa 66 67 Ubuntu: 68 sudo apt-get install python python-c 69 70 Fedora: 71 sudo dnf install python python-confi 72 73 The tools can most easily be installed via 74 75 $> git clone http://github.com/intel/pm-gr 76 $> cd pm-graph 77 $> sudo make install 78 $> man sleepgraph ; man bootgraph 79 80 Setup involves some minor kernel configura 81 82 The following kernel build options are req 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 ups 93 v3.0 behavior. These patches allow the 94 data from trace events instead of from 95 this behavior on earlier kernels with 96 97 (kernel/pre-3.15/enable_trace_events_s 98 (kernel/pre-3.15/enable_trace_events_d 99 100 If you're using bootgraph, or sleepgra 101 the following additional kerne 102 (e.g. in file /etc/default/grub) 103 GRUB_CMDLINE_LINUX_DEFAULT="... initca 104 105 If you're using a kernel older than 3. 106 patch must be applied to enabl 107 in file: kernel/power/suspend.c 108 in function: int suspend_devices_and_e 109 remove call to "ftrace_stop();" 110 remove call to "ftrace_start();" 111 112 There is a patch which does this for k 113 (kernel/pre-3.11-rc2/enable_ftrace_in_ 114 115 116 117 ---------------------------------------------- 118 | USAGE 119 ---------------------------------------------- 120 121 Basic Usage 122 ___________ 123 124 1) First configure a kernel using the instruc 125 Then build, install, and boot with it. 126 2) Open up a terminal window and execute the 127 128 %> sudo ./sleepgraph.py -modes 129 ['freeze', 'mem', 'disk'] 130 131 Execute a test using one of the available pow 132 133 %> sudo ./sleepgraph.py -m mem -rtcwak 134 135 or with a config file 136 137 %> sudo ./sleepgraph.py -config config 138 139 When the system comes back you'll see the scr 140 creating the output files in the test subdir. 141 files in subdirectory: suspend-mmddyy-HHMMSS. 142 be used to regenerate the html timeline with 143 144 HTML output: <hostname 145 raw dmesg output: <hostname 146 raw ftrace output: <hostname 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 155 The tool sets kprobes on all delay and mutex 156 are waiting for something and when. It also s 157 subsystem dependent calls to better fill out 158 159 The tool will also expose kernel threads that 160 timeline. This is useful in discovering depen 161 idea of what each device is waiting for. For 162 a.k.a. scsi resume error handler, is what eac 163 before it can continue resume. 164 165 The timeline will be much larger if run with 166 to set the -mindev option to clip out any dev 167 to see easily. The following command will giv 168 169 %> sudo ./sleepgraph.py -m mem -rtcwake 15 -m 170 171 or with a config file 172 173 %> sudo ./sleepgraph.py -config config/suspen 174 175 176 Proc Mode Usage 177 _______________ 178 179 Proc mode adds user process info to the timel 180 similar to the bootchart utility, which graph 181 execution as the system boots. This tool opti 182 the period before and after suspend/resume. 183 184 In order to see any process info, there needs 185 after resume since processes are frozen in su 186 resume_complete. The predelay and postdelay a 187 can also be useful to run in x2 mode with an 188 see process activity before and after resume, 189 successive suspend/resumes. 190 191 The command can be run like this: 192 193 %> sudo ./sleepgraph.py -m mem -rtcwake 15 -x 194 195 or with a config file 196 197 %> sudo ./sleepgraph.py -config config/suspen 198 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 298 ---------------------------------------------- 299 | CONFIGURATION FILES 300 ---------------------------------------------- 301 302 Since 4.0 we've moved to using config files i 303 The config folder contains a collection of ty 304 There are corresponding configs for other pow 305 306 Simple suspend/resume with basic timel 307 config/suspend.cfg 308 config/freeze.cfg 309 config/standby.cfg 310 311 Dev mode suspend/resume with dev timel 312 config/suspend-dev.cfg 313 config/freeze-dev.cfg 314 config/standby-dev.cfg 315 316 Simple suspend/resume with timeline an 317 config/suspend-callgraph.cfg 318 config/freeze-callgraph.cfg 319 config/standby-callgraph.cfg 320 321 Sample proc mode x2 run using mem susp 322 config/suspend-x2-proc.cfg 323 324 Sample for editing timeline funcs (mov 325 config/custom-timeline-functio 326 327 Sample debug config for serio subsyste 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/suspen 336 337 Run a mem suspend with callgraph data: 338 %> sudo ./sleepgraph.py -config config/suspen 339 340 Run a mem suspend with dev mode detail: 341 %> sudo ./sleepgraph.py -config config/suspen 342 343 344 Config File Options 345 ___________________ 346 347 [Settings] 348 349 # Verbosity: print verbose messages (def: fal 350 verbose: false 351 352 # Suspend Mode: e.g. standby, mem, freeze, di 353 mode: mem 354 355 # Output Directory Format: {hostname}, {date} 356 output-dir: suspend-{hostname}-{date}-{time} 357 358 # Automatic Wakeup: use rtcwake to wakeup aft 359 rtcwake: 15 360 361 # Add Logs: add the dmesg and ftrace log to t 362 addlogs: false 363 364 # Sus/Res Gap: insert a gap between sus & res 365 srgap: false 366 367 # Custom Command: Command to execute in lieu 368 command: echo mem > /sys/power/state 369 370 # Proc mode: graph user processes and cpu usa 371 proc: false 372 373 # Dev mode: graph source functions in the tim 374 dev: false 375 376 # Suspend/Resume x2: run 2 suspend/resumes ba 377 x2: false 378 379 # x2 Suspend Delay: time delay between the tw 380 x2delay: 0 381 382 # Pre Suspend Delay: nclude an N ms delay bef 383 predelay: 0 384 385 # Post Resume Delay: include an N ms delay af 386 postdelay: 0 387 388 # Min Device Length: graph only dev callbacks 389 mindev: 0.001 390 391 # Callgraph: gather ftrace callgraph data on 392 callgraph: false 393 394 # Expand Callgraph: pre-expand the callgraph 395 expandcg: false 396 397 # Min Callgraph Length: show callgraphs only 398 mincg: 1 399 400 # Timestamp Precision: number of sig digits i 401 timeprec: 3 402 403 # Device Filter: show only devs whose name/dr 404 devicefilter: _cpu_up,_cpu_down,i915,usb 405 406 # Override default timeline entries: 407 # Do not use the internal default functions f 408 # Set this to true if you intend to only use 409 override-timeline-functions: true 410 411 # Override default dev timeline entries: 412 # Do not use the internal default functions f 413 # Set this to true if you intend to only use 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 les 418 callloop-maxgap: 0.0001 419 420 # Call Loop Max Length (dev mode only) 421 # merge loops of the same call if each is les 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 f 432 timeline where device callbacks don't appear. 433 the tool adds the sys_sync and freeze_process 434 in the timeline to show you where the time is 435 the timeline with contiguous data so that mos 436 437 It is possible to add new function calls to t 438 the config. It's also possible to copy the in 439 the config so that you can override and edit 440 timeline_functions_ARCH section with the name 441 i.e. for x86_64: [timeline_functions_x86_64] 442 443 Use the override-timeline-functions option if 444 custom calls, or leave it false to append the 445 446 This section includes a list of functions (se 447 symbol data and function arg data. The args a 448 stack using this architecture's registers and 449 can include up to four pieces of info: The fu 450 an argument list, and a color. But only a fun 451 452 For a full example config, see config/custom- 453 all the internal timeline functions into the 454 them. 455 456 Entry format: 457 458 function: format{fn_arg1}_{fn_arg2} fn_arg 459 460 Required Arguments: 461 462 function: The symbol name for the function 463 minimum required for an entry, i 464 name with no arguments. 465 466 example: _cpu_up: 467 468 Optional Arguments: 469 470 format: The format to display the data on 471 enclose the arg names. 472 473 example: CPU_ON[{cpu}] 474 475 color: The color of the entry block in the 476 transparent, so the entry shares th 477 html color string, either a word, o 478 479 example: [color=#CC00CC] 480 481 arglist: A list of arguments from register 482 https://www.kernel.org/doc/Docume 483 484 example: cpu=%di:s32 485 486 Here is a full example entry. It displays cpu 487 in orange. They will appear as CPU_ON[0], CPU 488 489 [timeline_functions_x86_64] 490 _cpu_up: CPU_ON[{cpu}] cpu=%di:s32 [color=or 491 492 493 Adding or Editing Dev Mode Timeline Source Fun 494 ______________________________________________ 495 496 In dev mode, the tool uses an array of functi 497 execution within the timeline entries. 498 499 The function calls are displayed inside the m 500 timeline. However, if a function call is not 501 it will spawn an entirely new event named aft 502 These asynchronous kernel threads will popula 503 beneath the main device/call section. 504 505 The tool has a set of hard coded calls which 506 cases: msleep, udelay, schedule_timeout, mute 507 the functions that add a hardcoded time delay 508 The tool also includes some common functions 509 subsystems: ata, i915, and ACPI, etc. 510 511 It is possible to add new function calls to t 512 to the config. It's also possible to copy the 513 functions into the config so that you can ove 514 in the dev_timeline_functions_ARCH section wi 515 appended. i.e. for x86_64: [dev_timeline_func 516 517 Use the override-dev-timeline-functions optio 518 custom calls, or leave it false to append the 519 520 The format is the same as the timeline_functi 521 list of functions (set using kprobes) which u 522 arg data. The args are pulled directly from t 523 architecture's registers and stack formatting 524 to four pieces of info: The function name, a 525 and a color. But only the function name is re 526 527 For a full example config, see config/custom- 528 all the internal dev timeline functions into 529 them. 530 531 Here is a full example entry. It displays the 532 ataN_port_reset in the timeline. This is wher 533 time goes, so it can be helpful to see the lo 534 535 [dev_timeline_functions_x86_64] 536 ata_eh_recover: ata{port}_port_reset port=+3 537 538 539 Verifying your custom functions 540 _______________________________ 541 542 Once you have a set of functions (kprobes) de 543 perform a quick check to see if you formatted 544 actually supports them. To do this, run the t 545 and the -status option. The tool will go thro 546 custom and internal if you haven't overridden 547 to set them in ftrace. It will then print out 548 549 Note that kprobes which don't actually exist 550 tool, they just wont show up. 551 552 For example: 553 554 sudo ./sleepgraph.py -config config/custom-ti 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 ev 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 OPERATIN 588 ---------------------------------------------- 589 590 Android 591 _______ 592 593 The easiest way to execute on an android devi 594 script on the device, then pull the ftrace lo 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.githubusercont 602 host%> adb connect 192.168.1.6 603 host%> adb root 604 # push the script to a writeable locat 605 host%> adb push android.sh /sdcard/ 606 607 [check whether the tool will run on your devi 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: fo 620 device_pm_callback_start: 621 } 622 # the above is what you see on a syste 623 624 [execute the suspend] 625 626 # NOTE: The suspend will only work if 627 # so you have to press some keys first 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/ftr 636 dmesg out : /mnt/shell/emulated/0/dme 637 log file : /mnt/shell/emulated/0/log 638 ------------------------------------ 639 INITIALIZING FTRACE........DONE 640 STARTING FTRACE 641 SUSPEND START @ 21:24:02 (rtcwake in 1 642 <adb connection will now terminate> 643 644 [retrieve the data from the device] 645 646 # I find that you have to actually kil 647 # reconnect sometimes in order for the 648 host%> adb connect 192.168.1.6 649 # (required) get the ftrace data, this 650 host%> adb pull /sdcard/ftrace.txt 651 # (optional) get the dmesg data, this 652 host%> adb pull /sdcard/dmesg.txt 653 # (optional) get the log, which just l 654 host%> adb pull /sdcard/log.txt 655 656 [create an output html file using sleepgraph. 657 658 host%> sleepgraph.py -ftrace ftrace.tx 659 660 You should now have an output.html with the a
Linux® is a registered trademark of Linus Torvalds in the United States and other countries.
TOMOYO® is a registered trademark of NTT DATA CORPORATION.