1
0

qcacmn: Track tasklet execution and total time (sched+exec)

Add support to track tasklet execution and total time in different
buckets for debugging purposes

Change-Id: Ide459c385b2a44c0f16d05b37879c8b462782d72
CRs-Fixed: 2589199
Este cometimento está contido em:
Surya Prakash Raajen
2020-01-02 20:02:52 +05:30
cometido por nshrivas
ascendente 0181445b71
cometimento b976076b3b
12 ficheiros modificados com 312 adições e 22 eliminações

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2013-2019 The Linux Foundation. All rights reserved.
* Copyright (c) 2013-2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -468,6 +468,8 @@ enum hif_ce_event_type {
HIF_RX_DESC_PRE_NBUF_ALLOC,
HIF_RX_DESC_PRE_NBUF_MAP,
HIF_RX_DESC_POST_NBUF_MAP,
HIF_EVENT_TYPE_MAX,
};
void ce_init_ce_desc_event_log(struct hif_softc *scn, int ce_id, int size);

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2015-2019 The Linux Foundation. All rights reserved.
* Copyright (c) 2015-2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -49,6 +49,7 @@
#define CE_USEFUL_SIZE 0x00000058
#define CE_ALL_BITMAP 0xFFFF
#define HIF_REQUESTED_EVENTS 20
/**
* enum ce_id_type
*
@@ -70,6 +71,30 @@ enum ce_id_type {
CE_ID_MAX
};
/**
* enum ce_buckets
*
* @ce_buckets: CE tasklet time buckets
* @CE_BUCKET_500_US: tasklet bucket to store 0-0.5ms
* @CE_BUCKET_1_MS: tasklet bucket to store 0.5-1ms
* @CE_BUCKET_2_MS: tasklet bucket to store 1-2ms
* @CE_BUCKET_5_MS: tasklet bucket to store 2-5ms
* @CE_BUCKET_10_MS: tasklet bucket to store 5-10ms
* @CE_BUCKET_BEYOND: tasklet bucket to store > 10ms
* @CE_BUCKET_MAX: enum max value
*/
#ifdef CE_TASKLET_DEBUG_ENABLE
enum ce_buckets {
CE_BUCKET_500_US,
CE_BUCKET_1_MS,
CE_BUCKET_2_MS,
CE_BUCKET_5_MS,
CE_BUCKET_10_MS,
CE_BUCKET_BEYOND,
CE_BUCKET_MAX,
};
#endif
enum ce_target_type {
CE_SVC_LEGACY,
CE_SVC_SRNG,
@@ -134,8 +159,33 @@ static inline bool hif_dummy_grp_done(struct hif_exec_context *grp_entry, int
extern struct hif_execution_ops tasklet_sched_ops;
extern struct hif_execution_ops napi_sched_ops;
/**
* struct ce_stats
*
* @ce_per_cpu: Stats of the CEs running per CPU
* @record_index: Current index to store in time record
* @tasklet_sched_entry_ts: Timestamp when tasklet is scheduled
* @tasklet_exec_entry_ts: Timestamp when tasklet is started execuiton
* @tasklet_exec_time_record: Last N number of tasklets execution time
* @tasklet_sched_time_record: Last N number of tasklets scheduled time
* @ce_tasklet_exec_bucket: Tasklet execution time buckets
* @ce_tasklet_sched_bucket: Tasklet time in queue buckets
* @ce_tasklet_exec_last_update: Latest timestamp when bucket is updated
* @ce_tasklet_sched_last_update: Latest timestamp when bucket is updated
*/
struct ce_stats {
uint32_t ce_per_cpu[CE_COUNT_MAX][QDF_MAX_AVAILABLE_CPU];
#ifdef CE_TASKLET_DEBUG_ENABLE
uint32_t record_index[CE_COUNT_MAX];
uint64_t tasklet_sched_entry_ts[CE_COUNT_MAX];
uint64_t tasklet_exec_entry_ts[CE_COUNT_MAX];
uint64_t tasklet_exec_time_record[CE_COUNT_MAX][HIF_REQUESTED_EVENTS];
uint64_t tasklet_sched_time_record[CE_COUNT_MAX][HIF_REQUESTED_EVENTS];
uint64_t ce_tasklet_exec_bucket[CE_COUNT_MAX][CE_BUCKET_MAX];
uint64_t ce_tasklet_sched_bucket[CE_COUNT_MAX][CE_BUCKET_MAX];
uint64_t ce_tasklet_exec_last_update[CE_COUNT_MAX][CE_BUCKET_MAX];
uint64_t ce_tasklet_sched_last_update[CE_COUNT_MAX][CE_BUCKET_MAX];
#endif
};
struct HIF_CE_state {

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2015-2019 The Linux Foundation. All rights reserved.
* Copyright (c) 2015-2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -35,7 +35,6 @@
#include "hif_debug.h"
#include "hif_napi.h"
/**
* struct tasklet_work
*
@@ -139,6 +138,199 @@ static inline void ce_schedule_tasklet(struct ce_tasklet_entry *tasklet_entry)
tasklet_schedule(&tasklet_entry->intr_tq);
}
#ifdef CE_TASKLET_DEBUG_ENABLE
/**
* hif_record_tasklet_exec_entry_ts() - Record ce tasklet execution
* entry time
* @scn: hif_softc
* @ce_id: ce_id
*
* Return: None
*/
static inline void
hif_record_tasklet_exec_entry_ts(struct hif_softc *scn, uint8_t ce_id)
{
struct HIF_CE_state *hif_ce_state = HIF_GET_CE_STATE(scn);
hif_ce_state->stats.tasklet_exec_entry_ts[ce_id] =
qdf_get_log_timestamp_usecs();
}
/**
* hif_record_tasklet_sched_entry_ts() - Record ce tasklet scheduled
* entry time
* @scn: hif_softc
* @ce_id: ce_id
*
* Return: None
*/
static inline void
hif_record_tasklet_sched_entry_ts(struct hif_softc *scn, uint8_t ce_id)
{
struct HIF_CE_state *hif_ce_state = HIF_GET_CE_STATE(scn);
hif_ce_state->stats.tasklet_sched_entry_ts[ce_id] =
qdf_get_log_timestamp_usecs();
}
/**
* hif_ce_latency_stats() - Display ce latency information
* @hif_ctx: hif_softc struct
*
* Return: None
*/
static void
hif_ce_latency_stats(struct hif_softc *hif_ctx)
{
uint8_t i, j;
uint32_t index, start_index;
static const char * const buck_str[] = {"0 - 0.5", "0.5 - 1", "1 - 2",
"2 - 5", "5 - 10", " > 10"};
struct HIF_CE_state *hif_ce_state = HIF_GET_CE_STATE(hif_ctx);
struct ce_stats *stats = &hif_ce_state->stats;
for (i = 0; i < CE_COUNT_MAX; i++) {
qdf_nofl_info("\n\t\tCE Ring %d Tasklet Execution Bucket", i);
for (j = 0; j < CE_BUCKET_MAX; j++) {
qdf_nofl_info("\t Bucket %sms :%llu\t last update:%llu",
buck_str[j],
stats->ce_tasklet_exec_bucket[i][j],
stats->ce_tasklet_exec_last_update[i][j]);
}
qdf_nofl_info("\n\t\tCE Ring %d Tasklet Scheduled Bucket", i);
for (j = 0; j < CE_BUCKET_MAX; j++) {
qdf_nofl_info("\t Bucket %sms :%llu\t last update :%lld",
buck_str[j],
stats->ce_tasklet_sched_bucket[i][j],
stats->
ce_tasklet_sched_last_update[i][j]);
}
qdf_nofl_info("\n\t\t CE RING %d Last %d time records",
i, HIF_REQUESTED_EVENTS);
index = stats->record_index[i];
start_index = stats->record_index[i];
for (j = 0; j < HIF_REQUESTED_EVENTS; j++) {
qdf_nofl_info("\t Execuiton time: %luus Total Scheduled time: %luus",
stats->tasklet_exec_time_record[i][index],
stats->
tasklet_sched_time_record[i][index]);
index = (index - 1) % HIF_REQUESTED_EVENTS;
if (index == start_index)
break;
}
}
}
/**
* ce_tasklet_update_bucket() - update ce execution and scehduled time latency
* in corresponding time buckets
* @stats: struct ce_stats
* @ce_id: ce_id_type
* @entry_us: timestamp when tasklet is started to execute
* @exit_us: timestamp when tasklet is completed execution
*
* Return: N/A
*/
static void ce_tasklet_update_bucket(struct HIF_CE_state *hif_ce_state,
uint8_t ce_id)
{
uint32_t index;
uint64_t exec_time, exec_ms;
uint64_t sched_time, sched_ms;
uint64_t curr_time = qdf_get_log_timestamp_usecs();
struct ce_stats *stats = &hif_ce_state->stats;
exec_time = curr_time - (stats->tasklet_exec_entry_ts[ce_id]);
sched_time = (stats->tasklet_exec_entry_ts[ce_id]) -
(stats->tasklet_sched_entry_ts[ce_id]);
index = stats->record_index[ce_id];
index = (index + 1) % HIF_REQUESTED_EVENTS;
stats->tasklet_exec_time_record[ce_id][index] = exec_time;
stats->tasklet_sched_time_record[ce_id][index] = sched_time;
stats->record_index[ce_id] = index;
exec_ms = (exec_time) / (1000);
sched_ms = (sched_time) / (1000);
if (exec_ms > 10) {
stats->ce_tasklet_exec_bucket[ce_id][CE_BUCKET_BEYOND]++;
stats->ce_tasklet_exec_last_update[ce_id][CE_BUCKET_BEYOND]
= curr_time;
} else if (exec_ms > 5) {
stats->ce_tasklet_exec_bucket[ce_id][CE_BUCKET_10_MS]++;
stats->ce_tasklet_exec_last_update[ce_id][CE_BUCKET_10_MS]
= curr_time;
} else if (exec_ms > 2) {
stats->ce_tasklet_exec_bucket[ce_id][CE_BUCKET_5_MS]++;
stats->ce_tasklet_exec_last_update[ce_id][CE_BUCKET_5_MS]
= curr_time;
} else if (exec_ms > 1) {
stats->ce_tasklet_exec_bucket[ce_id][CE_BUCKET_2_MS]++;
stats->ce_tasklet_exec_last_update[ce_id][CE_BUCKET_2_MS]
= curr_time;
} else if (exec_time > 500) {
stats->ce_tasklet_exec_bucket[ce_id][CE_BUCKET_1_MS]++;
stats->ce_tasklet_exec_last_update[ce_id][CE_BUCKET_1_MS]
= curr_time;
} else {
stats->ce_tasklet_exec_bucket[ce_id][CE_BUCKET_500_US]++;
stats->ce_tasklet_exec_last_update[ce_id][CE_BUCKET_500_US]
= curr_time;
}
if (sched_ms > 10) {
stats->ce_tasklet_sched_bucket[ce_id][CE_BUCKET_BEYOND]++;
stats->ce_tasklet_sched_last_update[ce_id][CE_BUCKET_BEYOND]
= curr_time;
} else if (sched_ms > 5) {
stats->ce_tasklet_sched_bucket[ce_id][CE_BUCKET_10_MS]++;
stats->ce_tasklet_sched_last_update[ce_id][CE_BUCKET_10_MS]
= curr_time;
} else if (sched_ms > 2) {
stats->ce_tasklet_sched_bucket[ce_id][CE_BUCKET_5_MS]++;
stats->ce_tasklet_sched_last_update[ce_id][CE_BUCKET_5_MS]
= curr_time;
} else if (sched_ms > 1) {
stats->ce_tasklet_sched_bucket[ce_id][CE_BUCKET_2_MS]++;
stats->ce_tasklet_sched_last_update[ce_id][CE_BUCKET_2_MS]
= curr_time;
} else if (sched_time > 500) {
stats->ce_tasklet_sched_bucket[ce_id][CE_BUCKET_1_MS]++;
stats->ce_tasklet_sched_last_update[ce_id][CE_BUCKET_1_MS]
= curr_time;
} else {
stats->ce_tasklet_sched_bucket[ce_id][CE_BUCKET_500_US]++;
stats->ce_tasklet_sched_last_update[ce_id][CE_BUCKET_500_US]
= curr_time;
}
}
#else
static inline void
hif_record_tasklet_exec_entry_ts(struct hif_softc *scn, uint8_t ce_id)
{
}
static void ce_tasklet_update_bucket(struct HIF_CE_state *hif_ce_state,
uint8_t ce_id)
{
}
static inline void
hif_record_tasklet_sched_entry_ts(struct hif_softc *scn, uint8_t ce_id)
{
}
static void
hif_ce_latency_stats(struct hif_softc *hif_ctx)
{
}
#endif /*CE_TASKLET_DEBUG_ENABLE*/
/**
* ce_tasklet() - ce_tasklet
* @data: data
@@ -153,8 +345,9 @@ static void ce_tasklet(unsigned long data)
struct hif_softc *scn = HIF_GET_SOFTC(hif_ce_state);
struct CE_state *CE_state = scn->ce_id_to_state[tasklet_entry->ce_id];
hif_record_tasklet_exec_entry_ts(scn, tasklet_entry->ce_id);
hif_record_ce_desc_event(scn, tasklet_entry->ce_id,
HIF_CE_TASKLET_ENTRY, NULL, NULL, -1, 0);
HIF_CE_TASKLET_ENTRY, NULL, NULL, -1, 0);
if (qdf_atomic_read(&scn->link_suspended)) {
HIF_ERROR("%s: ce %d tasklet fired after link suspend.",
@@ -182,7 +375,7 @@ static void ce_tasklet(unsigned long data)
hif_record_ce_desc_event(scn, tasklet_entry->ce_id, HIF_CE_TASKLET_EXIT,
NULL, NULL, -1, 0);
ce_tasklet_update_bucket(hif_ce_state, tasklet_entry->ce_id);
qdf_atomic_dec(&scn->active_tasklet_cnt);
}
@@ -339,12 +532,13 @@ hif_ce_increment_interrupt_count(struct HIF_CE_state *hif_ce_state, int ce_id)
*
* Return: none
*/
void hif_display_ce_stats(struct HIF_CE_state *hif_ce_state)
void hif_display_ce_stats(struct hif_softc *hif_ctx)
{
#define STR_SIZE 128
uint8_t i, j, pos;
char str_buffer[STR_SIZE];
int size, ret;
struct HIF_CE_state *hif_ce_state = HIF_GET_CE_STATE(hif_ctx);
qdf_debug("CE interrupt statistics:");
for (i = 0; i < CE_COUNT_MAX; i++) {
@@ -352,7 +546,7 @@ void hif_display_ce_stats(struct HIF_CE_state *hif_ce_state)
pos = 0;
for (j = 0; j < QDF_MAX_AVAILABLE_CPU; j++) {
ret = snprintf(str_buffer + pos, size, "[%d]:%d ",
j, hif_ce_state->stats.ce_per_cpu[i][j]);
j, hif_ce_state->stats.ce_per_cpu[i][j]);
if (ret <= 0 || ret >= size)
break;
size -= ret;
@@ -360,6 +554,8 @@ void hif_display_ce_stats(struct HIF_CE_state *hif_ce_state)
}
qdf_debug("CE id[%2d] - %s", i, str_buffer);
}
hif_ce_latency_stats(hif_ctx);
#undef STR_SIZE
}
@@ -393,6 +589,7 @@ static inline bool hif_tasklet_schedule(struct hif_opaque_softc *hif_ctx,
}
tasklet_schedule(&tasklet_entry->intr_tq);
hif_record_tasklet_sched_entry_ts(scn, tasklet_entry->ce_id);
return true;
}

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2015-2016,2018 The Linux Foundation. All rights reserved.
* Copyright (c) 2015-2016,2018,2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -28,6 +28,6 @@ QDF_STATUS ce_register_irq(struct HIF_CE_state *hif_ce_state, uint32_t mask);
QDF_STATUS ce_unregister_irq(struct HIF_CE_state *hif_ce_state, uint32_t mask);
irqreturn_t ce_dispatch_interrupt(int irq,
struct ce_tasklet_entry *tasklet_entry);
void hif_display_ce_stats(struct HIF_CE_state *hif_ce_state);
void hif_display_ce_stats(struct hif_softc *hif_ctx);
void hif_clear_ce_stats(struct HIF_CE_state *hif_ce_state);
#endif /* __CE_TASKLET_H__ */

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2013-2018 The Linux Foundation. All rights reserved.
* Copyright (c) 2013-2018,2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -50,4 +50,6 @@ int hif_ahb_configure_irq(struct hif_pci_softc *sc);
int hif_ahb_configure_grp_irq(struct hif_softc *scn,
struct hif_exec_context *hif_ext_grp);
bool hif_ahb_needs_bmi(struct hif_softc *scn);
void hif_ahb_display_stats(struct hif_softc *scn);
void hif_ahb_clear_stats(struct hif_softc *scn);
#endif

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2016-2018 The Linux Foundation. All rights reserved.
* Copyright (c) 2016-2018,2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -69,7 +69,8 @@ QDF_STATUS hif_initialize_ahb_ops(struct hif_bus_ops *bus_ops)
bus_ops->hif_grp_irq_configure = &hif_ahb_configure_grp_irq;
bus_ops->hif_addr_in_boundary = &hif_dummy_addr_in_boundary;
bus_ops->hif_needs_bmi = &hif_ahb_needs_bmi;
bus_ops->hif_display_stats = &hif_ahb_display_stats;
bus_ops->hif_clear_stats = &hif_ahb_clear_stats;
return QDF_STATUS_SUCCESS;
}

Ver ficheiro

@@ -1395,7 +1395,7 @@ void hif_pci_display_stats(struct hif_softc *hif_ctx)
HIF_ERROR("%s, hif_ctx null", __func__);
return;
}
hif_display_ce_stats(&pci_ctx->ce_sc);
hif_display_ce_stats(hif_ctx);
hif_print_pci_stats(pci_ctx);
}

Ver ficheiro

@@ -835,3 +835,23 @@ bool hif_ahb_needs_bmi(struct hif_softc *scn)
{
return !ce_srng_based(scn);
}
void hif_ahb_display_stats(struct hif_softc *scn)
{
if (!scn) {
HIF_ERROR("%s, hif_scn null", __func__);
return;
}
hif_display_ce_stats(scn);
}
void hif_ahb_clear_stats(struct hif_softc *scn)
{
struct HIF_CE_state *hif_state = HIF_GET_CE_STATE(scn);
if (!hif_state) {
HIF_ERROR("%s, hif_state null", __func__);
return;
}
hif_clear_ce_stats(hif_state);
}

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2015-2019 The Linux Foundation. All rights reserved.
* Copyright (c) 2015-2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -78,13 +78,11 @@ int hif_snoc_dump_registers(struct hif_softc *hif_ctx)
void hif_snoc_display_stats(struct hif_softc *hif_ctx)
{
struct HIF_CE_state *hif_state = HIF_GET_CE_STATE(hif_ctx);
if (!hif_state) {
if (!hif_ctx) {
HIF_ERROR("%s, hif_ctx null", __func__);
return;
}
hif_display_ce_stats(hif_state);
hif_display_ce_stats(hif_ctx);
}
void hif_snoc_clear_stats(struct hif_softc *hif_ctx)

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2013-2019 The Linux Foundation. All rights reserved.
* Copyright (c) 2013-2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -134,6 +134,16 @@ void htc_dump(HTC_HANDLE HTCHandle, uint8_t CmdId, bool start)
hif_dump(target->hif_dev, CmdId, start);
}
void htc_ce_tasklet_debug_dump(HTC_HANDLE htc_handle)
{
HTC_TARGET *target = GET_HTC_TARGET_FROM_HANDLE(htc_handle);
if (!target->hif_dev)
return;
hif_display_stats(target->hif_dev);
}
/* cleanup the HTC instance */
static void htc_cleanup(HTC_TARGET *target)
{

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2013-2014, 2016-2019 The Linux Foundation. All rights reserved.
* Copyright (c) 2013-2014, 2016-2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -481,6 +481,15 @@ QDF_STATUS htc_connect_service(HTC_HANDLE HTCHandle,
*/
void htc_dump(HTC_HANDLE HTCHandle, uint8_t CmdId, bool start);
/**
* htc_ce_taklet_debug_dump - Dump ce tasklet rings debug data
* @HTCHandle - HTC handle
*
* Debug logs will be printed.
* Return: None
*/
void htc_ce_tasklet_debug_dump(HTC_HANDLE htc_handle);
/**
* htc_send_pkt - Send an HTC packet
* @HTCHandle - HTC handle

Ver ficheiro

@@ -1,5 +1,5 @@
/*
* Copyright (c) 2015-2019 The Linux Foundation. All rights reserved.
* Copyright (c) 2015-2020 The Linux Foundation. All rights reserved.
*
* Permission to use, copy, modify, and/or distribute this software for
* any purpose with or without fee is hereby granted, provided that the
@@ -1808,6 +1808,7 @@ QDF_STATUS wmi_unified_cmd_send_fl(wmi_unified_t wmi_handle, wmi_buf_t buf,
wmi_nofl_err("%s:%d, MAX %d WMI Pending cmds reached",
func, line, wmi_handle->wmi_max_cmds);
wmi_unified_debug_dump(wmi_handle);
htc_ce_tasklet_debug_dump(wmi_handle->htc_handle);
qdf_trigger_self_recovery(QDF_WMI_EXCEED_MAX_PENDING_CMDS);
return QDF_STATUS_E_BUSY;
}