qcacmn: Record caller and timestamp for pm_runtime_mark_last_busy

pm_runtime_mark_last_busy will extend the timer for runtime suspend.
Recording caller and timestamp can help to debug who may prevent
runtime PM suspend.

Change-Id: I4848a2558197e0fc9b7300421a5a1993817333e4
CRs-fixed: 2457803
This commit is contained in:
Yue Ma
2019-05-08 17:17:12 -07:00
committed by nshrivas
parent 2bdc2baea6
commit ac6b275768
5 changed files with 47 additions and 31 deletions

View File

@@ -1580,8 +1580,8 @@ uint32_t dp_rx_process(struct dp_intr *int_ctx, void *hal_ring,
hal_soc = soc->hal_soc; hal_soc = soc->hal_soc;
qdf_assert_always(hal_soc); qdf_assert_always(hal_soc);
hif_pm_runtime_mark_last_busy(soc->osdev->dev);
scn = soc->hif_handle; scn = soc->hif_handle;
hif_pm_runtime_mark_last_busy(scn);
intr_id = int_ctx->dp_intr_id; intr_id = int_ctx->dp_intr_id;
more_data: more_data:

View File

@@ -748,6 +748,7 @@ int hif_pm_runtime_request_resume(struct hif_opaque_softc *hif_ctx);
int hif_pm_runtime_get(struct hif_opaque_softc *hif_ctx); int hif_pm_runtime_get(struct hif_opaque_softc *hif_ctx);
void hif_pm_runtime_get_noresume(struct hif_opaque_softc *hif_ctx); void hif_pm_runtime_get_noresume(struct hif_opaque_softc *hif_ctx);
int hif_pm_runtime_put(struct hif_opaque_softc *hif_ctx); int hif_pm_runtime_put(struct hif_opaque_softc *hif_ctx);
void hif_pm_runtime_mark_last_busy(struct hif_opaque_softc *hif_ctx);
int hif_runtime_lock_init(qdf_runtime_lock_t *lock, const char *name); int hif_runtime_lock_init(qdf_runtime_lock_t *lock, const char *name);
void hif_runtime_lock_deinit(struct hif_opaque_softc *hif_ctx, void hif_runtime_lock_deinit(struct hif_opaque_softc *hif_ctx,
struct hif_pm_runtime_lock *lock); struct hif_pm_runtime_lock *lock);
@@ -772,6 +773,8 @@ static inline int hif_pm_runtime_get(struct hif_opaque_softc *hif_ctx)
{ return 0; } { return 0; }
static inline int hif_pm_runtime_put(struct hif_opaque_softc *hif_ctx) static inline int hif_pm_runtime_put(struct hif_opaque_softc *hif_ctx)
{ return 0; } { return 0; }
static inline void
hif_pm_runtime_mark_last_busy(struct hif_opaque_softc *hif_ctx) {};
static inline int hif_runtime_lock_init(qdf_runtime_lock_t *lock, static inline int hif_runtime_lock_init(qdf_runtime_lock_t *lock,
const char *name) const char *name)
{ return 0; } { return 0; }

View File

@@ -2144,16 +2144,12 @@ hif_pci_ce_recv_data(struct CE_handle *copyeng, void *ce_context,
struct HIF_CE_state *hif_state = pipe_info->HIF_CE_state; struct HIF_CE_state *hif_state = pipe_info->HIF_CE_state;
struct CE_state *ce_state = (struct CE_state *) copyeng; struct CE_state *ce_state = (struct CE_state *) copyeng;
struct hif_softc *scn = HIF_GET_SOFTC(hif_state); struct hif_softc *scn = HIF_GET_SOFTC(hif_state);
#ifdef HIF_PCI struct hif_opaque_softc *hif_ctx = GET_HIF_OPAQUE_HDL(scn);
struct hif_pci_softc *hif_pci_sc = HIF_GET_PCI_SOFTC(hif_state);
#endif
struct hif_msg_callbacks *msg_callbacks = struct hif_msg_callbacks *msg_callbacks =
&pipe_info->pipe_callbacks; &pipe_info->pipe_callbacks;
do { do {
#ifdef HIF_PCI hif_pm_runtime_mark_last_busy(hif_ctx);
hif_pm_runtime_mark_last_busy(hif_pci_sc->dev);
#endif
qdf_nbuf_unmap_single(scn->qdf_dev, qdf_nbuf_unmap_single(scn->qdf_dev,
(qdf_nbuf_t) transfer_context, (qdf_nbuf_t) transfer_context,
QDF_DMA_FROM_DEVICE); QDF_DMA_FROM_DEVICE);

View File

@@ -978,27 +978,38 @@ static int hif_pci_pm_runtime_debugfs_show(struct seq_file *s, void *data)
static const char * const autopm_state[] = {"NONE", "ON", "INPROGRESS", static const char * const autopm_state[] = {"NONE", "ON", "INPROGRESS",
"SUSPENDED"}; "SUSPENDED"};
unsigned int msecs_age; unsigned int msecs_age;
qdf_time_t usecs_age;
int pm_state = atomic_read(&sc->pm_state); int pm_state = atomic_read(&sc->pm_state);
unsigned long timer_expires; unsigned long timer_expires;
struct hif_pm_runtime_lock *ctx; struct hif_pm_runtime_lock *ctx;
seq_printf(s, "%30s: %s\n", "Runtime PM state", seq_printf(s, "%30s: %s\n", "Runtime PM state",
autopm_state[pm_state]); autopm_state[pm_state]);
seq_printf(s, "%30s: %pf\n", "Last Resume Caller", seq_printf(s, "%30s: %pf\n", "Last Resume Caller",
sc->pm_stats.last_resume_caller); sc->pm_stats.last_resume_caller);
seq_printf(s, "%30s: %pf\n", "Last Busy Marker",
sc->pm_stats.last_busy_marker);
usecs_age = qdf_get_log_timestamp_usecs() -
sc->pm_stats.last_busy_timestamp;
seq_printf(s, "%30s: %lu.%06lus\n", "Last Busy Timestamp",
sc->pm_stats.last_busy_timestamp / 1000000,
sc->pm_stats.last_busy_timestamp % 1000000);
seq_printf(s, "%30s: %lu.%06lus\n", "Last Busy Since",
usecs_age / 1000000, usecs_age % 1000000);
if (pm_state == HIF_PM_RUNTIME_STATE_SUSPENDED) { if (pm_state == HIF_PM_RUNTIME_STATE_SUSPENDED) {
msecs_age = jiffies_to_msecs( msecs_age = jiffies_to_msecs(jiffies -
jiffies - sc->pm_stats.suspend_jiffies); sc->pm_stats.suspend_jiffies);
seq_printf(s, "%30s: %d.%03ds\n", "Suspended Since", seq_printf(s, "%30s: %d.%03ds\n", "Suspended Since",
msecs_age / 1000, msecs_age % 1000); msecs_age / 1000, msecs_age % 1000);
} }
seq_printf(s, "%30s: %d\n", "PM Usage count", seq_printf(s, "%30s: %d\n", "PM Usage count",
atomic_read(&sc->dev->power.usage_count)); atomic_read(&sc->dev->power.usage_count));
seq_printf(s, "%30s: %u\n", "prevent_suspend_cnt", seq_printf(s, "%30s: %u\n", "prevent_suspend_cnt",
sc->prevent_suspend_cnt); sc->prevent_suspend_cnt);
HIF_PCI_RUNTIME_PM_STATS(s, sc, suspended); HIF_PCI_RUNTIME_PM_STATS(s, sc, suspended);
HIF_PCI_RUNTIME_PM_STATS(s, sc, suspend_err); HIF_PCI_RUNTIME_PM_STATS(s, sc, suspend_err);
@@ -1016,7 +1027,7 @@ static int hif_pci_pm_runtime_debugfs_show(struct seq_file *s, void *data)
if (timer_expires > 0) { if (timer_expires > 0) {
msecs_age = jiffies_to_msecs(timer_expires - jiffies); msecs_age = jiffies_to_msecs(timer_expires - jiffies);
seq_printf(s, "%30s: %d.%03ds\n", "Prevent suspend timeout", seq_printf(s, "%30s: %d.%03ds\n", "Prevent suspend timeout",
msecs_age / 1000, msecs_age % 1000); msecs_age / 1000, msecs_age % 1000);
} }
spin_lock_bh(&sc->runtime_lock); spin_lock_bh(&sc->runtime_lock);
@@ -2746,12 +2757,10 @@ static void hif_log_runtime_resume_success(void *hif_ctx)
*/ */
void hif_process_runtime_suspend_failure(struct hif_opaque_softc *hif_ctx) void hif_process_runtime_suspend_failure(struct hif_opaque_softc *hif_ctx)
{ {
struct hif_pci_softc *hif_pci_sc = HIF_GET_PCI_SOFTC(hif_ctx);
struct hif_softc *scn = HIF_GET_SOFTC(hif_ctx); struct hif_softc *scn = HIF_GET_SOFTC(hif_ctx);
hif_log_runtime_suspend_failure(hif_ctx); hif_log_runtime_suspend_failure(hif_ctx);
if (hif_pci_sc) hif_pm_runtime_mark_last_busy(hif_ctx);
hif_pm_runtime_mark_last_busy(hif_pci_sc->dev);
hif_runtime_pm_set_state_on(scn); hif_runtime_pm_set_state_on(scn);
} }
@@ -2813,12 +2822,10 @@ void hif_pre_runtime_resume(struct hif_opaque_softc *hif_ctx)
*/ */
void hif_process_runtime_resume_success(struct hif_opaque_softc *hif_ctx) void hif_process_runtime_resume_success(struct hif_opaque_softc *hif_ctx)
{ {
struct hif_pci_softc *hif_pci_sc = HIF_GET_PCI_SOFTC(hif_ctx);
struct hif_softc *scn = HIF_GET_SOFTC(hif_ctx); struct hif_softc *scn = HIF_GET_SOFTC(hif_ctx);
hif_log_runtime_resume_success(hif_ctx); hif_log_runtime_resume_success(hif_ctx);
if (hif_pci_sc) hif_pm_runtime_mark_last_busy(hif_ctx);
hif_pm_runtime_mark_last_busy(hif_pci_sc->dev);
hif_runtime_pm_set_state_on(scn); hif_runtime_pm_set_state_on(scn);
} }
@@ -3868,6 +3875,19 @@ int hif_pm_runtime_request_resume(struct hif_opaque_softc *hif_ctx)
return hif_pm_request_resume(sc->dev); return hif_pm_request_resume(sc->dev);
} }
void hif_pm_runtime_mark_last_busy(struct hif_opaque_softc *hif_ctx)
{
struct hif_pci_softc *sc = HIF_GET_PCI_SOFTC(hif_ctx);
if (!sc)
return;
sc->pm_stats.last_busy_marker = (void *)_RET_IP_;
sc->pm_stats.last_busy_timestamp = qdf_get_log_timestamp_usecs();
return pm_runtime_mark_last_busy(sc->dev);
}
void hif_pm_runtime_get_noresume(struct hif_opaque_softc *hif_ctx) void hif_pm_runtime_get_noresume(struct hif_opaque_softc *hif_ctx)
{ {
struct hif_pci_softc *sc = HIF_GET_PCI_SOFTC(hif_ctx); struct hif_pci_softc *sc = HIF_GET_PCI_SOFTC(hif_ctx);
@@ -3979,7 +3999,7 @@ int hif_pm_runtime_put(struct hif_opaque_softc *hif_ctx)
sc->pm_stats.runtime_put++; sc->pm_stats.runtime_put++;
hif_pm_runtime_mark_last_busy(sc->dev); hif_pm_runtime_mark_last_busy(hif_ctx);
hif_pm_runtime_put_auto(sc->dev); hif_pm_runtime_put_auto(sc->dev);
return 0; return 0;
@@ -4046,6 +4066,7 @@ static int __hif_pm_runtime_prevent_suspend(struct hif_pci_softc
static int __hif_pm_runtime_allow_suspend(struct hif_pci_softc *hif_sc, static int __hif_pm_runtime_allow_suspend(struct hif_pci_softc *hif_sc,
struct hif_pm_runtime_lock *lock) struct hif_pm_runtime_lock *lock)
{ {
struct hif_opaque_softc *hif_ctx = GET_HIF_OPAQUE_HDL(hif_sc);
int ret = 0; int ret = 0;
int usage_count; int usage_count;
@@ -4079,7 +4100,7 @@ static int __hif_pm_runtime_allow_suspend(struct hif_pci_softc *hif_sc,
lock->active = false; lock->active = false;
lock->timeout = 0; lock->timeout = 0;
hif_pm_runtime_mark_last_busy(hif_sc->dev); hif_pm_runtime_mark_last_busy(hif_ctx);
ret = hif_pm_runtime_put_auto(hif_sc->dev); ret = hif_pm_runtime_put_auto(hif_sc->dev);
HIF_ERROR("%s: in pm_state:%s ret: %d", __func__, HIF_ERROR("%s: in pm_state:%s ret: %d", __func__,
@@ -4250,7 +4271,7 @@ int hif_pm_runtime_prevent_suspend_timeout(struct hif_opaque_softc *ol_sc,
*/ */
if (delay <= hif_sc->dev->power.autosuspend_delay) { if (delay <= hif_sc->dev->power.autosuspend_delay) {
hif_pm_request_resume(hif_sc->dev); hif_pm_request_resume(hif_sc->dev);
hif_pm_runtime_mark_last_busy(hif_sc->dev); hif_pm_runtime_mark_last_busy(ol_sc);
return ret; return ret;
} }

View File

@@ -84,6 +84,8 @@ struct hif_pci_pm_stats {
u32 allow_suspend_timeout; u32 allow_suspend_timeout;
u32 runtime_get_err; u32 runtime_get_err;
void *last_resume_caller; void *last_resume_caller;
void *last_busy_marker;
qdf_time_t last_busy_timestamp;
unsigned long suspend_jiffies; unsigned long suspend_jiffies;
}; };
#endif #endif
@@ -196,6 +198,7 @@ static inline int hif_pm_request_resume(struct device *dev)
{ {
return pm_request_resume(dev); return pm_request_resume(dev);
} }
static inline int __hif_pm_runtime_get(struct device *dev) static inline int __hif_pm_runtime_get(struct device *dev)
{ {
return pm_runtime_get(dev); return pm_runtime_get(dev);
@@ -206,16 +209,9 @@ static inline int hif_pm_runtime_put_auto(struct device *dev)
return pm_runtime_put_autosuspend(dev); return pm_runtime_put_autosuspend(dev);
} }
static inline void hif_pm_runtime_mark_last_busy(struct device *dev)
{
pm_runtime_mark_last_busy(dev);
}
static inline int hif_pm_runtime_resume(struct device *dev) static inline int hif_pm_runtime_resume(struct device *dev)
{ {
return pm_runtime_resume(dev); return pm_runtime_resume(dev);
} }
#else
static inline void hif_pm_runtime_mark_last_busy(struct device *dev) { }
#endif /* FEATURE_RUNTIME_PM */ #endif /* FEATURE_RUNTIME_PM */
#endif /* __ATH_PCI_H__ */ #endif /* __ATH_PCI_H__ */