clusteridle: psci: Tracing and debuggingcpuidle_psci_v1_debug

Signed-off-by: Ulf Hansson <ulf.hansson@linaro.org>

4 files changed, 30 insertions, 10 deletions

diff --git a/drivers/base/power/domain.c b/drivers/base/power/domain.c
index cc85e87eaf05..c35af907ea82 100644
--- a/drivers/base/power/domain.c
+++ b/drivers/base/power/domain.c
@@ -536,8 +536,10 @@ static int genpd_power_off(struct generic_pm_domain *genpd, bool one_dev_on,
 		return -EBUSY;
 
 	if (genpd->gov && genpd->gov->power_down_ok) {
-		if (!genpd->gov->power_down_ok(&genpd->domain))
+		if (!genpd->gov->power_down_ok(&genpd->domain)) {
+			trace_printk("power off prevented for %s\n", genpd->name);
 			return -EAGAIN;
+		}
 	}
 
 	/* Default to shallowest state. */
@@ -766,8 +768,10 @@ static int genpd_runtime_suspend(struct device *dev)
 	 * validating/measuring the PM QoS latency.
 	 */
 	suspend_ok = genpd->gov ? genpd->gov->suspend_ok : NULL;
-	if (runtime_pm && suspend_ok && !suspend_ok(dev))
+	if (runtime_pm && suspend_ok && !suspend_ok(dev)) {
+		trace_printk("%s: suspend prevented for dev\n", dev_name(dev));
 		return -EBUSY;
+	}
 
 	/* Measure suspend latency. */
 	time_start = 0;
@@ -789,8 +793,8 @@ static int genpd_runtime_suspend(struct device *dev)
 		elapsed_ns = ktime_to_ns(ktime_sub(ktime_get(), time_start));
 		if (elapsed_ns > td->suspend_latency_ns) {
 			td->suspend_latency_ns = elapsed_ns;
-			dev_dbg(dev, "suspend latency exceeded, %lld ns\n",
-				elapsed_ns);
+			trace_printk("%s: suspend latency exceeded, %lld ns\n",
+				     dev_name(dev), elapsed_ns);
 			genpd->max_off_time_changed = true;
 			td->constraint_changed = true;
 		}
@@ -869,8 +873,8 @@ static int genpd_runtime_resume(struct device *dev)
 		elapsed_ns = ktime_to_ns(ktime_sub(ktime_get(), time_start));
 		if (elapsed_ns > td->resume_latency_ns) {
 			td->resume_latency_ns = elapsed_ns;
-			dev_dbg(dev, "resume latency exceeded, %lld ns\n",
-				elapsed_ns);
+			trace_printk("%s: resume latency exceeded, %lld ns\n",
+				     dev_name(dev), elapsed_ns);
 			genpd->max_off_time_changed = true;
 			td->constraint_changed = true;
 		}
diff --git a/drivers/base/power/domain_governor.c b/drivers/base/power/domain_governor.c
index daa8c7689f7e..beca4911f1e4 100644
--- a/drivers/base/power/domain_governor.c
+++ b/drivers/base/power/domain_governor.c
@@ -258,8 +258,10 @@ static bool cpu_power_down_ok(struct dev_pm_domain *pd)
 	int cpu, i;
 
 	/* Validate dev PM QoS constraints. */
-	if (!default_power_down_ok(pd))
+	if (!default_power_down_ok(pd)) {
+		trace_printk("prevented off becuase dev PM QoS %s\n", genpd->name);
 		return false;
+	}
 
 	if (!(genpd->flags & GENPD_FLAG_CPU_DOMAIN))
 		return true;
@@ -298,6 +300,9 @@ static bool cpu_power_down_ok(struct dev_pm_domain *pd)
 		}
 	} while (--i >= 0);
 
+	trace_printk("residency not satisfied: duration_ns=%lld name=%s\n",
+		idle_duration_ns, genpd->name);
+
 	return false;
 }
 
diff --git a/drivers/cpuidle/cpuidle-psci-domain.c b/drivers/cpuidle/cpuidle-psci-domain.c
index 7429fd7626a1..cb03439c2ee1 100644
--- a/drivers/cpuidle/cpuidle-psci-domain.c
+++ b/drivers/cpuidle/cpuidle-psci-domain.c
@@ -37,13 +37,17 @@ static int psci_pd_power_off(struct generic_pm_domain *pd)
 	if (!osi_mode_enabled)
 		return -EBUSY;
 
-	if (!state->data)
+	if (!state->data) {
+		trace_printk("cpu=%d nostate\n", smp_processor_id());
 		return 0;
+	}
 
 	/* OSI mode is enabled, set the corresponding domain state. */
 	pd_state = state->data;
 	psci_set_domain_state(*pd_state);
 
+	trace_printk("cpu=%d state=%#x\n", smp_processor_id(), *pd_state);
+
 	return 0;
 }
 
@@ -298,5 +302,6 @@ struct device *psci_dt_attach_cpu(int cpu)
 	if (cpu_online(cpu))
 		pm_runtime_get_sync(dev);
 
+	pr_info("Attached CPU%d to PM domain\n", cpu);
 	return dev;
 }
diff --git a/drivers/cpuidle/cpuidle-psci.c b/drivers/cpuidle/cpuidle-psci.c
index 0919b40c1a85..2433ae87611f 100644
--- a/drivers/cpuidle/cpuidle-psci.c
+++ b/drivers/cpuidle/cpuidle-psci.c
@@ -66,10 +66,14 @@ static int psci_enter_idle_state(struct cpuidle_device *dev,
 		pm_runtime_put_sync_suspend(pd_dev);
 
 	state = psci_get_domain_state();
-	if (!state && idx)
+	if (!state && idx) {
+		trace_printk("NO STATE !WFI cpu=%d\n", smp_processor_id());
 		state = states[idx - 1];
+	}
 
+	trace_printk("ENTER cpu=%d state=%#x\n", smp_processor_id(), state);
 	ret = __psci_enter_idle_state(idx, state);
+	trace_printk("EXIT cpu=%d state=%#x ret=%d\n", smp_processor_id(), state, ret);
 
 	if (runtime_pm)
 		pm_runtime_get_sync(pd_dev);
@@ -128,6 +132,8 @@ static int __init psci_dt_cpu_init_idle(struct device_node *cpu_node,
 	struct device_node *state_node;
 	struct psci_cpuidle_data *data = per_cpu_ptr(&psci_cpuidle_data, cpu);
 
+	pr_warn("%s: state_nodes=%u, cpu=%d\n", __func__, state_nodes, cpu);
+
 	psci_states = kcalloc(state_nodes, sizeof(*psci_states), GFP_KERNEL);
 	if (!psci_states)
 		return -ENOMEM;
@@ -143,7 +149,7 @@ static int __init psci_dt_cpu_init_idle(struct device_node *cpu_node,
 		if (ret)
 			goto free_mem;
 
-		pr_debug("psci-power-state %#x index %d\n", psci_states[i], i);
+		pr_warn("psci-power-state %#x index %d\n", psci_states[i], i);
 	}
 
 	if (i != state_nodes) {