power: add trace events suspend-resume path

Adds trace events in in suspend resume paths

This is copied from
https://github.com/01org/suspendresume/tree/master/config/3.10

Bug 200071658

Change-Id: I460b3ad6fb12808b949ff15aab3af3d376b52882
Signed-off-by: Shridhar Rasal <srasal@nvidia.com>
Reviewed-on: http://git-master/r/658784
Reviewed-by: Bharat Nihalani <bnihalani@nvidia.com>
Tested-by: Alankrita G <alankritag@nvidia.com>

diff --git a/drivers/acpi/sleep.c b/drivers/acpi/sleep.c
index 035920f2ab4d95a950e666a5cd69a9d8701eea76..73e45c83b8fc354b5873371b32acdfddd2fe2d64 100644 (file)
--- a/drivers/acpi/sleep.c
+++ b/drivers/acpi/sleep.c
@@ -20,6 +20,7 @@
 #include <linux/module.h>
 
 #include <asm/io.h>
+#include <trace/events/power.h>
 
 #include <acpi/acpi_bus.h>
 #include <acpi/acpi_drivers.h>
@@ -498,6 +499,7 @@ static int acpi_suspend_enter(suspend_state_t pm_state)
 
        ACPI_FLUSH_CPU_CACHE();
 
+       trace_suspend_resume(TPS("acpi_suspend"), acpi_state, true);
        switch (acpi_state) {
        case ACPI_STATE_S1:
                barrier();
@@ -511,6 +513,7 @@ static int acpi_suspend_enter(suspend_state_t pm_state)
                pr_info(PREFIX "Low-level resume complete\n");
                break;
        }
+       trace_suspend_resume(TPS("acpi_suspend"), acpi_state, false);
 
        /* This violates the spec but is required for bug compatibility. */
        acpi_write_bit_register(ACPI_BITREG_SCI_ENABLE, 1);

diff --git a/drivers/base/power/main.c b/drivers/base/power/main.c
index 5fc9e0fe47507c1c3e07ce8ac38c8996dd9a9d2f..a239f620974ca944216792e873399ee3789f73c2 100644 (file)
--- a/drivers/base/power/main.c
+++ b/drivers/base/power/main.c
@@ -34,6 +34,7 @@
 
 #include "../base.h"
 #include "power.h"
+#include <trace/events/power.h>
 
 typedef int (*pm_callback_t)(struct device *);
 
@@ -619,6 +620,7 @@ static void dpm_resume_noirq(pm_message_t state)
 {
        ktime_t starttime = ktime_get();
 
+       trace_suspend_resume(TPS("dpm_resume_noirq"), state.event, true);
        mutex_lock(&dpm_list_mtx);
        while (!list_empty(&dpm_noirq_list)) {
                struct device *dev = to_device(dpm_noirq_list.next);
@@ -643,6 +645,7 @@ static void dpm_resume_noirq(pm_message_t state)
        dpm_show_time(starttime, state, "noirq");
        resume_device_irqs();
        cpuidle_resume();
+       trace_suspend_resume(TPS("dpm_resume_noirq"), state.event, false);
 }
 
 /**
@@ -700,6 +703,7 @@ static void dpm_resume_early(pm_message_t state)
 {
        ktime_t starttime = ktime_get();
 
+       trace_suspend_resume(TPS("dpm_resume_early"), state.event, true);
        mutex_lock(&dpm_list_mtx);
        while (!list_empty(&dpm_late_early_list)) {
                struct device *dev = to_device(dpm_late_early_list.next);
@@ -722,6 +726,7 @@ static void dpm_resume_early(pm_message_t state)
        }
        mutex_unlock(&dpm_list_mtx);
        dpm_show_time(starttime, state, "early");
+       trace_suspend_resume(TPS("dpm_resume_early"), state.event, false);
 }
 
 /**
@@ -854,6 +859,7 @@ void dpm_resume(pm_message_t state)
        struct device *dev;
        ktime_t starttime = ktime_get();
 
+       trace_suspend_resume(TPS("dpm_resume"), state.event, true);
        might_sleep();
 
        mutex_lock(&dpm_list_mtx);
@@ -893,6 +899,7 @@ void dpm_resume(pm_message_t state)
        mutex_unlock(&dpm_list_mtx);
        async_synchronize_full();
        dpm_show_time(starttime, state, NULL);
+       trace_suspend_resume(TPS("dpm_resume"), state.event, false);
 }
 
 /**
@@ -950,6 +957,7 @@ void dpm_complete(pm_message_t state)
 {
        struct list_head list;
 
+       trace_suspend_resume(TPS("dpm_complete"), state.event, true);
        might_sleep();
 
        INIT_LIST_HEAD(&list);
@@ -969,6 +977,7 @@ void dpm_complete(pm_message_t state)
        }
        list_splice(&list, &dpm_list);
        mutex_unlock(&dpm_list_mtx);
+       trace_suspend_resume(TPS("dpm_complete"), state.event, false);
 }
 
 /**
@@ -1148,6 +1157,7 @@ static int dpm_suspend_noirq(pm_message_t state)
        char suspend_abort[MAX_SUSPEND_ABORT_LEN];
        int error = 0;
 
+       trace_suspend_resume(TPS("dpm_suspend_noirq"), state.event, true);
        cpuidle_pause();
        suspend_device_irqs();
        mutex_lock(&dpm_list_mtx);
@@ -1185,6 +1195,7 @@ static int dpm_suspend_noirq(pm_message_t state)
                dpm_resume_noirq(resume_event(state));
        else
                dpm_show_time(starttime, state, "noirq");
+       trace_suspend_resume(TPS("dpm_suspend_noirq"), state.event, false);
        return error;
 }
 
@@ -1237,6 +1248,7 @@ static int dpm_suspend_late(pm_message_t state)
        char suspend_abort[MAX_SUSPEND_ABORT_LEN];
        int error = 0;
 
+       trace_suspend_resume(TPS("dpm_suspend_late"), state.event, true);
        mutex_lock(&dpm_list_mtx);
        while (!list_empty(&dpm_suspended_list)) {
                struct device *dev = to_device(dpm_suspended_list.prev);
@@ -1272,7 +1284,7 @@ static int dpm_suspend_late(pm_message_t state)
                dpm_resume_early(resume_event(state));
        else
                dpm_show_time(starttime, state, "late");
-
+       trace_suspend_resume(TPS("dpm_suspend_late"), state.event, false);
        return error;
 }
 
@@ -1467,6 +1479,7 @@ int dpm_suspend(pm_message_t state)
        ktime_t starttime = ktime_get();
        int error = 0;
 
+       trace_suspend_resume(TPS("dpm_suspend"), state.event, true);
        might_sleep();
 
        mutex_lock(&dpm_list_mtx);
@@ -1502,6 +1515,7 @@ int dpm_suspend(pm_message_t state)
                dpm_save_failed_step(SUSPEND_SUSPEND);
        } else
                dpm_show_time(starttime, state, NULL);
+       trace_suspend_resume(TPS("dpm_suspend"), state.event, false);
        return error;
 }
 
@@ -1576,6 +1590,7 @@ int dpm_prepare(pm_message_t state)
 {
        int error = 0;
 
+       trace_suspend_resume(TPS("dpm_prepare"), state.event, true);
        might_sleep();
 
        mutex_lock(&dpm_list_mtx);
@@ -1606,6 +1621,7 @@ int dpm_prepare(pm_message_t state)
                put_device(dev);
        }
        mutex_unlock(&dpm_list_mtx);
+       trace_suspend_resume(TPS("dpm_prepare"), state.event, false);
        return error;
 }
 

diff --git a/drivers/base/syscore.c b/drivers/base/syscore.c
index 82ee97e78722e791b72248f4bf8c4000cbf108e6..e6cfc5d1981062d7ae3e79091e0884586c8a1902 100644 (file)
--- a/drivers/base/syscore.c
+++ b/drivers/base/syscore.c
@@ -11,6 +11,7 @@
 #include <linux/module.h>
 #include <linux/interrupt.h>
 #include <linux/wakeup_reason.h>
+#include <trace/events/power.h>
 
 static LIST_HEAD(syscore_ops_list);
 static DEFINE_MUTEX(syscore_ops_lock);
@@ -50,6 +51,7 @@ int syscore_suspend(void)
        struct syscore_ops *ops;
        int ret = 0;
 
+       trace_suspend_resume(TPS("syscore_suspend"), 0, true);
        pr_debug("Checking wakeup interrupts\n");
 
        /* Return error code if there are any wakeup interrupts pending. */
@@ -71,6 +73,7 @@ int syscore_suspend(void)
                                "Interrupts enabled after %pF\n", ops->suspend);
                }
 
+       trace_suspend_resume(TPS("syscore_suspend"), 0, false);
        return 0;
 
  err_out:
@@ -95,6 +98,7 @@ void syscore_resume(void)
 {
        struct syscore_ops *ops;
 
+       trace_suspend_resume(TPS("syscore_resume"), 0, true);
        WARN_ONCE(!irqs_disabled(),
                "Interrupts enabled before system core resume.\n");
 
@@ -110,6 +114,7 @@ void syscore_resume(void)
                                pr_info("PM: Called %pF\n", ops->resume);
                        }
        }
+        trace_suspend_resume(TPS("syscore_resume"), 0, false);
 }
 EXPORT_SYMBOL_GPL(syscore_resume);
 

diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index b5e36017acd7030c2bc2af0fb68c8eeacb1b4cfb..20aebdbab9a4222ef89ecebe9f9a26d9ea23f477 100644 (file)
--- a/include/linux/ftrace_event.h
+++ b/include/linux/ftrace_event.h
@@ -355,6 +355,40 @@ do {                                                                       \
                __trace_printk(ip, fmt, ##args);                        \
 } while (0)
 
+/**
+ * tracepoint_string - register constant persistent string to trace system
+ * @str - a constant persistent string that will be referenced in tracepoints
+ *
+ * If constant strings are being used in tracepoints, it is faster and
+ * more efficient to just save the pointer to the string and reference
+ * that with a printf "%s" instead of saving the string in the ring buffer
+ * and wasting space and time.
+ *
+ * The problem with the above approach is that userspace tools that read
+ * the binary output of the trace buffers do not have access to the string.
+ * Instead they just show the address of the string which is not very
+ * useful to users.
+ *
+ * With tracepoint_string(), the string will be registered to the tracing
+ * system and exported to userspace via the debugfs/tracing/printk_formats
+ * file that maps the string address to the string text. This way userspace
+ * tools that read the binary buffers have a way to map the pointers to
+ * the ASCII strings they represent.
+ *
+ * The @str used must be a constant string and persistent as it would not
+ * make sense to show a string that no longer exists. But it is still fine
+ * to be used with modules, because when modules are unloaded, if they
+ * had tracepoints, the ring buffers are cleared too. As long as the string
+ * does not change during the life of the module, it is fine to use
+ * tracepoint_string() within a module.
+ */
+#define tracepoint_string(str)                                         \
+       ({                                                              \
+               static const char *___tp_str __tracepoint_string = str; \
+               ___tp_str;                                              \
+       })
+#define __tracepoint_string    __attribute__((section("__tracepoint_str")))
+
 #ifdef CONFIG_PERF_EVENTS
 struct perf_event;
 

diff --git a/include/trace/events/power.h b/include/trace/events/power.h
index 52ec6e12e916cf48e887406c97f1df49d31f0eb8..743a0236b1ae0a314f8a989800c550650bdcdda3 100644 (file)
--- a/include/trace/events/power.h
+++ b/include/trace/events/power.h
@@ -6,6 +6,9 @@
 
 #include <linux/ktime.h>
 #include <linux/tracepoint.h>
+#include <linux/ftrace_event.h>
+
+#define TPS(x)  tracepoint_string(x)
 
 DECLARE_EVENT_CLASS(cpu,
 
@@ -157,21 +160,26 @@ DEFINE_EVENT(cpu, cpu_frequency,
        TP_ARGS(frequency, cpu_id)
 );
 
-TRACE_EVENT(machine_suspend,
+TRACE_EVENT(suspend_resume,
 
-       TP_PROTO(unsigned int state),
+       TP_PROTO(const char *action, int val, bool start),
 
-       TP_ARGS(state),
+       TP_ARGS(action, val, start),
 
        TP_STRUCT__entry(
-               __field(        u32,            state           )
+               __field(const char *, action)
+               __field(int, val)
+               __field(bool, start)
        ),
 
        TP_fast_assign(
-               __entry->state = state;
+               __entry->action = action;
+               __entry->val = val;
+               __entry->start = start;
        ),
 
-       TP_printk("state=%lu", (unsigned long)__entry->state)
+       TP_printk("%s[%u] %s", __entry->action, (unsigned int)__entry->val,
+               (__entry->start)?"begin":"end")
 );
 
 DECLARE_EVENT_CLASS(wakeup_source,

diff --git a/kernel/cpu.c b/kernel/cpu.c
index f12c92fec54135fbc77e4fa28ce61655de750acc..cf6035cdd9af711a2191e24a86b9aee8c6315850 100644 (file)
--- a/kernel/cpu.c
+++ b/kernel/cpu.c
@@ -501,7 +501,9 @@ int disable_nonboot_cpus(void)
        for_each_online_cpu(cpu) {
                if (cpu == first_cpu)
                        continue;
+               trace_suspend_resume(TPS("CPU_OFF"), cpu, true);
                error = _cpu_down(cpu, 1);
+               trace_suspend_resume(TPS("CPU_OFF"), cpu, false);
                if (!error)
                        cpumask_set_cpu(cpu, frozen_cpus);
                else {
@@ -545,7 +547,9 @@ void __ref enable_nonboot_cpus(void)
        arch_enable_nonboot_cpus_begin();
 
        for_each_cpu(cpu, frozen_cpus) {
+               trace_suspend_resume(TPS("CPU_ON"), cpu, true);
                error = _cpu_up(cpu, 1);
+               trace_suspend_resume(TPS("CPU_ON"), cpu, false);
                if (!error) {
                        printk(KERN_INFO "CPU%d is up\n", cpu);
                        continue;

diff --git a/kernel/power/hibernate.c b/kernel/power/hibernate.c
index 1634dc6e2fe7db3e5f77fa513d10d26a406be634..58f345604ff460b23b1555210d519693c7f88c0c 100644 (file)
--- a/kernel/power/hibernate.c
+++ b/kernel/power/hibernate.c
@@ -28,6 +28,7 @@
 #include <linux/syscore_ops.h>
 #include <linux/ctype.h>
 #include <linux/genhd.h>
+#include <trace/events/power.h>
 
 #include "power.h"
 
@@ -287,7 +288,9 @@ static int create_image(int platform_mode)
 
        in_suspend = 1;
        save_processor_state();
+       trace_suspend_resume(TPS("machine_suspend"), PM_EVENT_HIBERNATE, true);
        error = swsusp_arch_suspend();
+       trace_suspend_resume(TPS("machine_suspend"), PM_EVENT_HIBERNATE, false);
        if (error)
                printk(KERN_ERR "PM: Error %d creating hibernation image\n",
                        error);

diff --git a/kernel/power/process.c b/kernel/power/process.c
index 4c83e52dd77bc3019dcca5d734ce553313807fe0..cb98eccdf0a6c9e9825a563d20b3e6f3f98363d0 100644 (file)
--- a/kernel/power/process.c
+++ b/kernel/power/process.c
@@ -18,6 +18,8 @@
 #include <linux/workqueue.h>
 #include <linux/kmod.h>
 #include <linux/wakeup_reason.h>
+#include <trace/events/power.h>
+
 /* 
  * Timeout for stopping processes
  */
@@ -218,6 +220,7 @@ void thaw_processes(void)
        struct task_struct *g, *p;
        struct task_struct *curr = current;
 
+       trace_suspend_resume(TPS("thaw_processes"), 0, true);
        if (pm_freezing)
                atomic_dec(&system_freezing_cnt);
        pm_freezing = false;
@@ -245,6 +248,7 @@ void thaw_processes(void)
 
        schedule();
        printk("done.\n");
+       trace_suspend_resume(TPS("thaw_processes"), 0, false);
 }
 
 void thaw_kernel_threads(void)

diff --git a/kernel/power/suspend.c b/kernel/power/suspend.c
index 101f7ad6315a37258b642538a1813e98df43d317..6d4f0a3f658c8dd587f555dcb87f1ffce2659ec1 100644 (file)
--- a/kernel/power/suspend.c
+++ b/kernel/power/suspend.c
@@ -137,7 +137,9 @@ static int suspend_prepare(suspend_state_t state)
        if (error)
                goto Finish;
 
+       trace_suspend_resume(TPS("freeze_processes"), 0, true);
        error = suspend_freeze_processes();
+       trace_suspend_resume(TPS("freeze_processes"), 0, false);
        if (!error)
                return 0;
        log_suspend_abort_reason("One or more tasks refusing to freeze");
@@ -205,7 +207,9 @@ static int suspend_enter(suspend_state_t state, bool *wakeup)
         * all the devices are suspended.
         */
        if (state == PM_SUSPEND_FREEZE) {
+               trace_suspend_resume(TPS("machine_suspend"), state, true);
                freeze_enter();
+               trace_suspend_resume(TPS("machine_suspend"), state, false);
                goto Platform_wake;
        }
 
@@ -223,7 +227,11 @@ static int suspend_enter(suspend_state_t state, bool *wakeup)
        if (!error) {
                *wakeup = pm_wakeup_pending();
                if (!(suspend_test(TEST_CORE) || *wakeup)) {
+                       trace_suspend_resume(TPS("machine_suspend"),
+                               state, true);
                        error = suspend_ops->enter(state);
+                       trace_suspend_resume(TPS("machine_suspend"),
+                               state, false);
                        events_check_enabled = false;
                } else {
                        pm_get_active_wakeup_sources(suspend_abort,
@@ -265,7 +273,6 @@ int suspend_devices_and_enter(suspend_state_t state)
        if (need_suspend_ops(state) && !suspend_ops)
                return -ENOSYS;
 
-       trace_machine_suspend(state);
        if (need_suspend_ops(state) && suspend_ops->begin) {
                error = suspend_ops->begin(state);
                if (error)
@@ -296,7 +303,6 @@ int suspend_devices_and_enter(suspend_state_t state)
  Close:
        if (need_suspend_ops(state) && suspend_ops->end)
                suspend_ops->end();
-       trace_machine_suspend(PWR_EVENT_EXIT);
        return error;
 
  Recover_platform:
@@ -330,6 +336,7 @@ static int enter_state(suspend_state_t state)
 {
        int error;
 
+       trace_suspend_resume(TPS("suspend_enter"), state, true);
        if (state == PM_SUSPEND_FREEZE) {
 #ifdef CONFIG_PM_DEBUG
                if (pm_test_level != TEST_NONE && pm_test_level <= TEST_CPUS) {
@@ -347,9 +354,11 @@ static int enter_state(suspend_state_t state)
        if (state == PM_SUSPEND_FREEZE)
                freeze_begin();
 
+       trace_suspend_resume(TPS("sync_filesystems"), 0, true);
        printk(KERN_INFO "PM: Syncing filesystems ... ");
        sys_sync();
        printk("done.\n");
+       trace_suspend_resume(TPS("sync_filesystems"), 0, false);
 
        pr_debug("PM: Preparing system for %s sleep\n", pm_states[state].label);
        error = suspend_prepare(state);
@@ -359,6 +368,7 @@ static int enter_state(suspend_state_t state)
        if (suspend_test(TEST_FREEZER))
                goto Finish;
 
+       trace_suspend_resume(TPS("suspend_enter"), state, false);
        pr_debug("PM: Entering %s sleep\n", pm_states[state].label);
        pm_restrict_gfp_mask();
        error = suspend_devices_and_enter(state);