Commit f2511774863487e61b56a97da07ebf8dd61d7836
Committed by
Rafael J. Wysocki
Rafael J. Wysocki
1 parent
1d531c14d2
Exists in
master
and in
7 other branches
PM: Add initcall_debug style timing for suspend/resume
In order to diagnose overall suspend/resume times, we need basic instrumentation to break down the total time into per device timing, similar to initcall_debug. This patch adds the basic timing instrumentation, needed for a scritps/bootgraph.pl equivalent or humans. The bootgraph.pl program is still a work in progress, but is far enough along to know that this patch is sufficient. Signed-off-by: Arjan van de Ven <arjan@linux.intel.com> Signed-off-by: Rafael J. Wysocki <rjw@sisk.pl>
Showing 2 changed files with 33 additions and 0 deletions Side-by-side Diff
drivers/base/power/main.c
| ... | ... | @@ -25,6 +25,7 @@ |
| 25 | 25 | #include <linux/resume-trace.h> |
| 26 | 26 | #include <linux/rwsem.h> |
| 27 | 27 | #include <linux/interrupt.h> |
| 28 | +#include <linux/sched.h> | |
| 28 | 29 | |
| 29 | 30 | #include "../base.h" |
| 30 | 31 | #include "power.h" |
| 31 | 32 | |
| ... | ... | @@ -172,7 +173,14 @@ |
| 172 | 173 | pm_message_t state) |
| 173 | 174 | { |
| 174 | 175 | int error = 0; |
| 176 | + ktime_t calltime, delta, rettime; | |
| 175 | 177 | |
| 178 | + if (initcall_debug) { | |
| 179 | + pr_info("calling %s+ @ %i\n", | |
| 180 | + dev_name(dev), task_pid_nr(current)); | |
| 181 | + calltime = ktime_get(); | |
| 182 | + } | |
| 183 | + | |
| 176 | 184 | switch (state.event) { |
| 177 | 185 | #ifdef CONFIG_SUSPEND |
| 178 | 186 | case PM_EVENT_SUSPEND: |
| ... | ... | @@ -219,6 +227,14 @@ |
| 219 | 227 | default: |
| 220 | 228 | error = -EINVAL; |
| 221 | 229 | } |
| 230 | + | |
| 231 | + if (initcall_debug) { | |
| 232 | + rettime = ktime_get(); | |
| 233 | + delta = ktime_sub(rettime, calltime); | |
| 234 | + pr_info("call %s+ returned %d after %Ld usecs\n", dev_name(dev), | |
| 235 | + error, (unsigned long long)ktime_to_ns(delta) >> 10); | |
| 236 | + } | |
| 237 | + | |
| 222 | 238 | return error; |
| 223 | 239 | } |
| 224 | 240 | |
| 225 | 241 | |
| ... | ... | @@ -236,7 +252,14 @@ |
| 236 | 252 | pm_message_t state) |
| 237 | 253 | { |
| 238 | 254 | int error = 0; |
| 255 | + ktime_t calltime, delta, rettime; | |
| 239 | 256 | |
| 257 | + if (initcall_debug) { | |
| 258 | + pr_info("calling %s_i+ @ %i\n", | |
| 259 | + dev_name(dev), task_pid_nr(current)); | |
| 260 | + calltime = ktime_get(); | |
| 261 | + } | |
| 262 | + | |
| 240 | 263 | switch (state.event) { |
| 241 | 264 | #ifdef CONFIG_SUSPEND |
| 242 | 265 | case PM_EVENT_SUSPEND: |
| ... | ... | @@ -283,6 +306,14 @@ |
| 283 | 306 | default: |
| 284 | 307 | error = -EINVAL; |
| 285 | 308 | } |
| 309 | + | |
| 310 | + if (initcall_debug) { | |
| 311 | + rettime = ktime_get(); | |
| 312 | + delta = ktime_sub(rettime, calltime); | |
| 313 | + printk("initcall %s_i+ returned %d after %Ld usecs\n", dev_name(dev), | |
| 314 | + error, (unsigned long long)ktime_to_ns(delta) >> 10); | |
| 315 | + } | |
| 316 | + | |
| 286 | 317 | return error; |
| 287 | 318 | } |
| 288 | 319 |