shinys000114/linux
1
0
Fork 0
mirror of https://github.com/hardkernel/linux.git synced 2026-06-07 03:15:31 +09:00
Code Issues Packages Projects Releases Wiki Activity

UPSTREAM: scsi: ufs: core: Use local_clock() for debugging timestamps

Browse Source 
CLOCK_MONOTONIC is not advanced when the system is in suspend. This becomes
problematic when debugging issues related to suspend-resume: the timestamps
printed by ufshcd_print_trs can not be correlated with dmesg entries, which
are timestamped with local_clock().

Change the used clock to local_clock() for the informational timestamp
variables and adds mirroring *_local_clock instances for variables used in
subsequent derevations (to not change the semantics of those derevations).

Link: https://lore.kernel.org/r/20220804065019.v5.1.I699244ea7efbd326a34a6dfd9b5a31e78400cf68@changeid
Acked-by: Stanley Chu <stanley.chu@mediatek.com>
Acked-by: Avri Altman <avri.altman@wdc.com>
Change-Id: If97e2a159690adb247156f264879a706eefabb84
Signed-off-by: Daniil Lunev <dlunev@chromium.org>
Signed-off-by: Martin K. Petersen <martin.petersen@oracle.com>
Bug: 258234315
(cherry picked from commit 0f85e74756)
Signed-off-by: Bart Van Assche <bvanassche@google.com>
This commit is contained in:
Daniil Lunev
2022-08-04 06:50:34 +10:00
committed by Alistair Delva
parent d393a614b5
commit 66f0e62e45
2 changed files with 21 additions and 13 deletions
Download Patch File Download Diff File Expand all files Collapse all files

20
drivers/ufs/core/ufshcd.c
View File

@@ -21,6 +21,7 @@
#include <linux/interrupt.h>
#include <linux/module.h>
#include <linux/regulator/consumer.h>
#include <linux/sched/clock.h>
#include <scsi/scsi_cmnd.h>
#include <scsi/scsi_dbg.h>
#include <scsi/scsi_driver.h>
@@ -464,7 +465,7 @@ static void ufshcd_print_evt(struct ufs_hba *hba, u32 id,
if (e->tstamp[p] == 0)
continue;
dev_err(hba->dev, "%s[%d] = 0x%x at %lld us\n", err_name, p,
e->val[p], ktime_to_us(e->tstamp[p]));
e->val[p], div_u64(e->tstamp[p], 1000));
found = true;
}
@@ -509,9 +510,9 @@ void ufshcd_print_trs(struct ufs_hba *hba, unsigned long bitmap, bool pr_prdt)
lrbp = &hba->lrb[tag];
dev_err(hba->dev, "UPIU[%d] - issue time %lld us\n",
tag, ktime_to_us(lrbp->issue_time_stamp));
tag, div_u64(lrbp->issue_time_stamp_local_clock, 1000));
dev_err(hba->dev, "UPIU[%d] - complete time %lld us\n",
tag, ktime_to_us(lrbp->compl_time_stamp));
tag, div_u64(lrbp->compl_time_stamp_local_clock, 1000));
dev_err(hba->dev,
"UPIU[%d] - Transfer Request Descriptor phys@0x%llx\n",
tag, (u64)lrbp->utrd_dma_addr);
@@ -573,10 +574,10 @@ static void ufshcd_print_host_state(struct ufs_hba *hba)
dev_err(hba->dev, "Clk gate=%d\n", hba->clk_gating.state);
dev_err(hba->dev,
"last_hibern8_exit_tstamp at %lld us, hibern8_exit_cnt=%d\n",
ktime_to_us(hba->ufs_stats.last_hibern8_exit_tstamp),
div_u64(hba->ufs_stats.last_hibern8_exit_tstamp, 1000),
hba->ufs_stats.hibern8_exit_cnt);
dev_err(hba->dev, "last intr at %lld us, last intr status=0x%x\n",
ktime_to_us(hba->ufs_stats.last_intr_ts),
div_u64(hba->ufs_stats.last_intr_ts, 1000),
hba->ufs_stats.last_intr_status);
dev_err(hba->dev, "error handling flags=0x%x, req. abort count=%d\n",
hba->eh_flags, hba->req_abort_count);
@@ -2190,7 +2191,9 @@ void ufshcd_send_command(struct ufs_hba *hba, unsigned int task_tag)
unsigned long flags;
lrbp->issue_time_stamp = ktime_get();
lrbp->issue_time_stamp_local_clock = local_clock();
lrbp->compl_time_stamp = ktime_set(0, 0);
lrbp->compl_time_stamp_local_clock = 0;
trace_android_vh_ufs_send_command(hba, lrbp);
ufshcd_add_command_trace(hba, task_tag, UFS_CMD_SEND);
ufshcd_clk_scaling_start_busy(hba);
@@ -4291,7 +4294,7 @@ int ufshcd_uic_hibern8_exit(struct ufs_hba *hba)
} else {
ufshcd_vops_hibern8_notify(hba, UIC_CMD_DME_HIBER_EXIT,
POST_CHANGE);
hba->ufs_stats.last_hibern8_exit_tstamp = ktime_get();
hba->ufs_stats.last_hibern8_exit_tstamp = local_clock();
hba->ufs_stats.hibern8_exit_cnt++;
}
@@ -4793,7 +4796,7 @@ void ufshcd_update_evt_hist(struct ufs_hba *hba, u32 id, u32 val)
e = &hba->ufs_stats.event[id];
e->val[e->pos] = val;
e->tstamp[e->pos] = ktime_get();
e->tstamp[e->pos] = local_clock();
e->cnt += 1;
e->pos = (e->pos + 1) % UFS_EVENT_HIST_LENGTH;
@@ -5429,6 +5432,7 @@ static void __ufshcd_transfer_req_compl(struct ufs_hba *hba,
for_each_set_bit(index, &completed_reqs, hba->nutrs) {
lrbp = &hba->lrb[index];
lrbp->compl_time_stamp = ktime_get();
lrbp->compl_time_stamp_local_clock = local_clock();
cmd = lrbp->cmd;
if (cmd) {
trace_android_vh_ufs_compl_command(hba, lrbp);
@@ -6722,7 +6726,7 @@ static irqreturn_t ufshcd_intr(int irq, void *__hba)
intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS);
hba->ufs_stats.last_intr_status = intr_status;
hba->ufs_stats.last_intr_ts = ktime_get();
hba->ufs_stats.last_intr_ts = local_clock();
/*
* There could be max of hba->nutrs reqs in flight and in worst case

14
include/ufs/ufshcd.h
View File

@@ -161,8 +161,10 @@ struct ufs_pm_lvl_states {
* @task_tag: Task tag of the command
* @lun: LUN of the command
* @intr_cmd: Interrupt command (doesn't participate in interrupt aggregation)
* @issue_time_stamp: time stamp for debug purposes
* @compl_time_stamp: time stamp for statistics
* @issue_time_stamp: time stamp for debug purposes (CLOCK_MONOTONIC)
* @issue_time_stamp_local_clock: time stamp for debug purposes (local_clock)
* @compl_time_stamp: time stamp for statistics (CLOCK_MONOTONIC)
* @compl_time_stamp_local_clock: time stamp for debug purposes (local_clock)
* @crypto_key_slot: the key slot to use for inline crypto (-1 if none)
* @data_unit_num: the data unit number for the first block for inline crypto
* @req_abort_skip: skip request abort task flag
@@ -186,7 +188,9 @@ struct ufshcd_lrb {
u8 lun; /* UPIU LUN id field is only 8-bit wide */
bool intr_cmd;
ktime_t issue_time_stamp;
u64 issue_time_stamp_local_clock;
ktime_t compl_time_stamp;
u64 compl_time_stamp_local_clock;
#ifdef CONFIG_SCSI_UFS_CRYPTO
int crypto_key_slot;
u64 data_unit_num;
@@ -442,7 +446,7 @@ struct ufs_clk_scaling {
struct ufs_event_hist {
int pos;
u32 val[UFS_EVENT_HIST_LENGTH];
ktime_t tstamp[UFS_EVENT_HIST_LENGTH];
u64 tstamp[UFS_EVENT_HIST_LENGTH];
unsigned long long cnt;
};
@@ -458,10 +462,10 @@ struct ufs_event_hist {
*/
struct ufs_stats {
u32 last_intr_status;
ktime_t last_intr_ts;
u64 last_intr_ts;
u32 hibern8_exit_cnt;
ktime_t last_hibern8_exit_tstamp;
u64 last_hibern8_exit_tstamp;
struct ufs_event_hist event[UFS_EVT_CNT];
};