R0dn3yS/android_kernel_xiaomi_sm7250
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

mm: mm_event: show MM/FS/IO/UFS latencies in fault flow

Browse Source 
Tracing points are:
                        mm_event types
MM:    Page fault              -
F2FS:  read metadata in F2FS   |
F2FS:  alloc_bio in F2FS       |  -  -  -  -
F2FS:  merge bios in F2FS      |   |  |  |  |
BLOCK: submit_bio              |   |  |  | - blk_read_submit_bio
BLOCK: IO scheduler/SCSI       |   |  |  |
UFS:   ufshcd_queuecommand     |   |  | - ufs_read_queue_cmd
UFS:   resume/ungating         |   |  |
UFS:   IO completion           |   | - ufs_read_compl_cmd
BLOCK: softirq                 |   |
F2FS:  read_end_io in F2FS     |  - f2fs_read_data
MM:    end of page fauilt     -  maj_flt

For example,

> cat /d/tracing/instances/pixel-trace/trace_pipe

<...>-8364  [000] ....  5858.525417: mm_event_record: blk_read_submit_bio count=1 avg_lat=5 max_lat=5
<...>-8364  [000] ....  5858.525418: mm_event_record: ufs_read_queue_cmd count=1 avg_lat=96 max_lat=96
<...>-8364  [000] ....  5858.525418: mm_event_record: ufs_read_send_cmd count=1 avg_lat=143 max_lat=143
...
sitor-13079 [007] ....  5858.827375: mm_event_record: ufs_read_compl_cmd count=1 avg_lat=12545 max_lat=12545
sitor-13079 [007] ....  5858.827433: mm_event_record: f2fs_read_data count=1 avg_lat=12587 max_lat=12587
...
<...>-13174 [001] ....  5859.187505: mm_event_record: maj_flt count=1 avg_lat=12677 max_lat=12677

Signed-off-by: Jaegeuk Kim <jaegeuk@google.com>
Change-Id: I0712f543212a14ab2b1d6f092a9a2a7e3ed9f0a0
Signed-off-by: UtsavBalar1231 <utsavbalar1231@gmail.com>
This commit is contained in:
Jaegeuk Kim 2020-04-07 16:16:36 -07:00 committed by spakkkk
parent 7fde96ee31
commit 1e0161d75b
9 changed files with 53 additions and 3 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
block/bio.c
View File

@ -612,6 +612,7 @@ void __bio_clone_fast(struct bio *bio, struct bio *bio_src)
bio->bi_write_hint = bio_src->bi_write_hint;
bio->bi_iter = bio_src->bi_iter;
bio->bi_io_vec = bio_src->bi_io_vec;
bio->bi_alloc_ts = bio_src->bi_alloc_ts;
bio_clone_blkcg_association(bio, bio_src);
}

3
block/blk-core.c
View File

@ -2596,6 +2596,9 @@ blk_qc_t submit_bio(struct bio *bio)
if (workingset_read)
psi_memstall_enter(&pflags);
if (bio->bi_alloc_ts)
mm_event_end(BLK_READ_SUBMIT_BIO, bio->bi_alloc_ts);
ret = generic_make_request(bio);
if (workingset_read)

24
drivers/scsi/ufs/ufshcd.c
View File

@ -59,8 +59,27 @@ static int ufshcd_wb_buf_flush_disable(struct ufs_hba *hba);
static bool ufshcd_wb_is_buf_flush_needed(struct ufs_hba *hba);
static int ufshcd_wb_toggle_flush_during_h8(struct ufs_hba *hba, bool set);
#ifdef CONFIG_DEBUG_FS
static void ufshcd_event_record(struct scsi_cmnd *cmd, enum mm_event_type event)
{
struct bio *bio;
if (!cmd || !cmd->request || !cmd->request->bio)
return;
if (likely(!is_read_opcode(*cmd->cmnd)))
return;
bio = cmd->request->bio;
while (bio) {
if (bio->bi_alloc_ts)
mm_event_end(event, bio->bi_alloc_ts);
bio = bio->bi_next;
if (bio == cmd->request->bio)
break;
}
}
#ifdef CONFIG_DEBUG_FS
static int ufshcd_tag_req_type(struct request *rq)
{
int rq_type = TS_WRITE;
@ -3090,6 +3109,7 @@ int ufshcd_send_command(struct ufs_hba *hba, unsigned int task_tag)
/* Make sure that doorbell is committed immediately */
wmb();
ufshcd_update_tag_stats(hba, task_tag);
ufshcd_event_record(hba->lrb[task_tag].cmd, UFS_READ_SEND_CMD);
return 0;
}
@ -3765,6 +3785,7 @@ static int ufshcd_queuecommand(struct Scsi_Host *host, struct scsi_cmnd *cmd)
spin_unlock_irqrestore(hba->host->host_lock, flags);
hba->req_abort_count = 0;
ufshcd_event_record(cmd, UFS_READ_QUEUE_CMD);
/* acquire the tag to make sure device cmds don't use it */
if (test_and_set_bit_lock(tag, &hba->lrb_in_use)) {
@ -6531,6 +6552,7 @@ static void __ufshcd_transfer_req_compl(struct ufs_hba *hba,
cmd->result = result;
lrbp->compl_time_stamp = ktime_get();
update_req_stats(hba, lrbp);
ufshcd_event_record(cmd, UFS_READ_COMPL_CMD);
ufshcd_complete_lrbp_crypto(hba, cmd, lrbp);
/* Mark completed command as NULL in LRB */
lrbp->cmd = NULL;

5
drivers/scsi/ufs/ufshcd.h
View File

@ -711,6 +711,11 @@ struct ufs_stats {
u32 dme_err_cnt;
};
static inline bool is_read_opcode(u8 opcode)
{
return opcode == READ_10 || opcode == READ_16;
}
/* UFS Host Controller debug print bitmask */
#define UFSHCD_DBG_PRINT_CLK_FREQ_EN UFS_BIT(0)
#define UFSHCD_DBG_PRINT_UIC_ERR_HIST_EN UFS_BIT(1)

6
fs/f2fs/data.c
View File

@ -151,6 +151,9 @@ static void f2fs_finish_read_bio(struct bio *bio, bool in_task)
unlock_page(page);
}
if (bio->bi_alloc_ts)
mm_event_end(F2FS_READ_DATA, bio->bi_alloc_ts);
if (bio->bi_private)
mempool_free(bio->bi_private, bio_post_read_ctx_pool);
bio_put(bio);
@ -2241,6 +2244,7 @@ submit_and_realloc:
bio = NULL;
goto out;
}
mm_event_start(&bio->bi_alloc_ts);
}
/*
@ -2397,6 +2401,8 @@ submit_and_realloc:
*bio_ret = NULL;
return ret;
}
if (!for_write)
mm_event_start(&bio->bi_alloc_ts);
}
if (bio_add_page(bio, page, blocksize, 0) < blocksize)

2
include/linux/blk_types.h
View File

@ -212,6 +212,8 @@ struct bio {
struct bio_set *bi_pool;
ktime_t bi_alloc_ts;
ANDROID_KABI_RESERVE(1);
ANDROID_KABI_RESERVE(2);

7
include/linux/mm_event.h
View File

@ -14,7 +14,12 @@ enum mm_event_type {
MM_RECLAIM = 4,
MM_SWP_FAULT = 5,
MM_KERN_ALLOC = 6,
MM_TYPE_NUM = 7,
BLK_READ_SUBMIT_BIO = 7,
UFS_READ_QUEUE_CMD = 8,
UFS_READ_SEND_CMD = 9,
UFS_READ_COMPL_CMD = 10,
F2FS_READ_DATA = 11,
MM_TYPE_NUM = 12,
};
struct mm_event_task {

7
include/trace/events/mm_event.h
View File

@ -20,7 +20,12 @@ struct mm_event_vmstat;
{ MM_COMPACTION, "compaction" }, \
{ MM_RECLAIM, "reclaim" }, \
{ MM_SWP_FAULT, "swp_flt" }, \
{ MM_KERN_ALLOC, "kern_alloc" })
{ MM_KERN_ALLOC, "kern_alloc" }, \
{ BLK_READ_SUBMIT_BIO, "blk_read_submit_bio" }, \
{ UFS_READ_QUEUE_CMD, "ufs_read_queue_cmd" }, \
{ UFS_READ_SEND_CMD, "ufs_read_send_cmd" }, \
{ UFS_READ_COMPL_CMD, "ufs_read_compl_cmd" }, \
{ F2FS_READ_DATA, "f2fs_read_data" })
TRACE_EVENT(mm_event_record,

1
mm/mm_event.c
View File

@ -108,6 +108,7 @@ void mm_event_end(enum mm_event_type event, ktime_t start)
current->mm_event[event].max_lat = elapsed;
record_stat();
}
EXPORT_SYMBOL_GPL(mm_event_end);
void mm_event_count(enum mm_event_type event, int count)
{