This patch converts all DPU_EVTs in dpu_crtc with either a DRM_* log message or a linux tracepoint.
Signed-off-by: Sean Paul <seanp...@chromium.org> --- drivers/gpu/drm/msm/disp/dpu1/dpu_crtc.c | 122 ++++++---------- drivers/gpu/drm/msm/disp/dpu1/dpu_trace.h | 166 ++++++++++++++++++++++ 2 files changed, 210 insertions(+), 78 deletions(-) diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_crtc.c b/drivers/gpu/drm/msm/disp/dpu1/dpu_crtc.c index 9ca8325877a1..eefc1892ad47 100644 --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_crtc.c +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_crtc.c @@ -431,18 +431,12 @@ static void *_dpu_crtc_rp_get(struct dpu_crtc_respool *rp, u32 type, u64 tag) list_for_each_entry(res, &old_rp->res_list, list) { if (res->type != type) continue; - DPU_DEBUG( - "crtc%d.%u found res:0x%x//%pK/ in crtc%d.%d\n", - crtc->base.id, - rp->sequence_id, - res->type, res->val, - crtc->base.id, - old_rp->sequence_id); - DPU_EVT32_VERBOSE(crtc->base.id, - rp->sequence_id, - res->type, res->val, - crtc->base.id, - old_rp->sequence_id); + DRM_DEBUG_KMS("crtc%d.%u found res:0x%x//%pK/ " + "in crtc%d.%d\n", + crtc->base.id, rp->sequence_id, + res->type, res->val, + crtc->base.id, + old_rp->sequence_id); if (res->ops.get) res->ops.get(res->val, 0, -1); val = res->val; @@ -688,23 +682,17 @@ static void _dpu_crtc_blend_setup_mixer(struct drm_crtc *crtc, if (pstate->stage == DPU_STAGE_BASE && format->alpha_enable) bg_alpha_enable = true; - DPU_EVT32(DRMID(crtc), DRMID(plane), - state->fb ? state->fb->base.id : -1, - state->src_x >> 16, state->src_y >> 16, - state->src_w >> 16, state->src_h >> 16, - state->crtc_x, state->crtc_y, - state->crtc_w, state->crtc_h); - stage_idx = zpos_cnt[pstate->stage]++; stage_cfg->stage[pstate->stage][stage_idx] = dpu_plane_pipe(plane); stage_cfg->multirect_index[pstate->stage][stage_idx] = pstate->multirect_index; - DPU_EVT32(DRMID(crtc), DRMID(plane), stage_idx, - dpu_plane_pipe(plane) - SSPP_VIG0, pstate->stage, - pstate->multirect_index, pstate->multirect_mode, - format->base.pixel_format, fb ? fb->modifier : 0); + trace_dpu_crtc_setup_mixer(DRMID(crtc), DRMID(plane), + state, pstate, stage_idx, + dpu_plane_pipe(plane) - SSPP_VIG0, + format->base.pixel_format, + fb ? fb->modifier : 0); /* blend config update */ for (lm_idx = 0; lm_idx < dpu_crtc->num_mixers; lm_idx++) { @@ -821,7 +809,7 @@ static void _dpu_crtc_complete_flip(struct drm_crtc *crtc, dpu_crtc->event = NULL; DRM_DEBUG_VBL("%s: send event: %pK\n", dpu_crtc->name, event); - DPU_EVT32_VERBOSE(DRMID(crtc)); + trace_dpu_crtc_complete_flip(DRMID(crtc)); drm_crtc_send_vblank_event(crtc, event); } } @@ -856,8 +844,7 @@ static void dpu_crtc_vblank_cb(void *data) dpu_crtc->vblank_cb_count++; _dpu_crtc_complete_flip(crtc, NULL); drm_crtc_handle_vblank(crtc); - DRM_DEBUG_VBL("crtc%d\n", crtc->base.id); - DPU_EVT32_VERBOSE(DRMID(crtc)); + trace_dpu_crtc_vblank_cb(DRMID(crtc)); } /* _dpu_crtc_idle_notify - signal idle timeout to client */ @@ -933,34 +920,28 @@ static void dpu_crtc_frame_event_work(struct kthread_work *work) priv = dpu_kms->dev->dev_private; DPU_ATRACE_BEGIN("crtc_frame_event"); - DPU_DEBUG("crtc%d event:%u ts:%lld\n", crtc->base.id, fevent->event, + DRM_DEBUG_KMS("crtc%d event:%u ts:%lld\n", crtc->base.id, fevent->event, ktime_to_ns(fevent->ts)); - DPU_EVT32_VERBOSE(DRMID(crtc), fevent->event, DPU_EVTLOG_FUNC_ENTRY); - if (fevent->event & (DPU_ENCODER_FRAME_EVENT_DONE | DPU_ENCODER_FRAME_EVENT_ERROR | DPU_ENCODER_FRAME_EVENT_PANEL_DEAD)) { if (atomic_read(&dpu_crtc->frame_pending) < 1) { /* this should not happen */ - DPU_ERROR("crtc%d ts:%lld invalid frame_pending:%d\n", + DRM_ERROR("crtc%d ev:%u ts:%lld frame_pending:%d\n", crtc->base.id, + fevent->event, ktime_to_ns(fevent->ts), atomic_read(&dpu_crtc->frame_pending)); - DPU_EVT32(DRMID(crtc), fevent->event, - DPU_EVTLOG_FUNC_CASE1); } else if (atomic_dec_return(&dpu_crtc->frame_pending) == 0) { /* release bandwidth and other resources */ - DPU_DEBUG("crtc%d ts:%lld last pending\n", - crtc->base.id, - ktime_to_ns(fevent->ts)); - DPU_EVT32(DRMID(crtc), fevent->event, - DPU_EVTLOG_FUNC_CASE2); + trace_dpu_crtc_frame_event_done(DRMID(crtc), + fevent->event); dpu_core_perf_crtc_release_bw(crtc); } else { - DPU_EVT32_VERBOSE(DRMID(crtc), fevent->event, - DPU_EVTLOG_FUNC_CASE3); + trace_dpu_crtc_frame_event_more_pending(DRMID(crtc), + fevent->event); } if (fevent->event & DPU_ENCODER_FRAME_EVENT_DONE) @@ -1011,8 +992,7 @@ static void dpu_crtc_frame_event_cb(void *data, u32 event) priv = crtc->dev->dev_private; crtc_id = drm_crtc_index(crtc); - DPU_DEBUG("crtc%d\n", crtc->base.id); - DPU_EVT32_VERBOSE(DRMID(crtc), event); + trace_dpu_crtc_frame_event_cb(DRMID(crtc), event); /* try to process the event in caller context */ event_processed = _dpu_crtc_handle_event(dpu_crtc, event); @@ -1027,9 +1007,7 @@ static void dpu_crtc_frame_event_cb(void *data, u32 event) spin_unlock_irqrestore(&dpu_crtc->spin_lock, flags); if (!fevent) { - DPU_ERROR("crtc%d event %d overflow\n", - crtc->base.id, event); - DPU_EVT32(DRMID(crtc), event); + DRM_ERROR("crtc%d event %d overflow\n", crtc->base.id, event); return; } @@ -1046,7 +1024,7 @@ void dpu_crtc_complete_commit(struct drm_crtc *crtc, DPU_ERROR("invalid crtc\n"); return; } - DPU_EVT32_VERBOSE(DRMID(crtc)); + trace_dpu_crtc_complete_commit(DRMID(crtc)); } static void _dpu_crtc_setup_mixer_for_encoder( @@ -1146,9 +1124,8 @@ static void _dpu_crtc_setup_lm_bounds(struct drm_crtc *crtc, cstate->lm_bounds[i].w = crtc_split_width; cstate->lm_bounds[i].h = dpu_crtc_get_mixer_height(dpu_crtc, cstate, adj_mode); - DPU_EVT32_VERBOSE(DRMID(crtc), i, - cstate->lm_bounds[i].x, cstate->lm_bounds[i].y, - cstate->lm_bounds[i].w, cstate->lm_bounds[i].h); + trace_dpu_crtc_setup_lm_bounds(DRMID(crtc), i, + &cstate->lm_bounds[i]); } drm_mode_debug_printmodeline(adj_mode); @@ -1345,16 +1322,14 @@ static int _dpu_crtc_wait_for_frame_done(struct drm_crtc *crtc) return 0; } - DPU_EVT32_VERBOSE(DRMID(crtc), DPU_EVTLOG_FUNC_ENTRY); + DPU_ATRACE_BEGIN("frame done completion wait"); ret = wait_for_completion_timeout(&dpu_crtc->frame_done_comp, msecs_to_jiffies(DPU_FRAME_DONE_TIMEOUT)); if (!ret) { - DPU_ERROR("frame done completion wait timed out, ret:%d\n", - ret); - DPU_EVT32(DRMID(crtc), DPU_EVTLOG_FATAL); + DRM_ERROR("frame done wait timed out, ret:%d\n", ret); rc = -ETIMEDOUT; } - DPU_EVT32_VERBOSE(DRMID(crtc), DPU_EVTLOG_FUNC_EXIT); + DPU_ATRACE_END("frame done completion wait"); return rc; } @@ -1477,10 +1452,9 @@ static int _dpu_crtc_vblank_enable_no_lock( if (enc->crtc != crtc) continue; - DPU_EVT32(DRMID(&dpu_crtc->base), DRMID(enc), enable, - dpu_crtc->enabled, - dpu_crtc->suspend, - dpu_crtc->vblank_requested); + trace_dpu_crtc_vblank_enable(DRMID(&dpu_crtc->base), + DRMID(enc), enable, + dpu_crtc); dpu_encoder_register_vblank_callback(enc, dpu_crtc_vblank_cb, (void *)crtc); @@ -1490,10 +1464,9 @@ static int _dpu_crtc_vblank_enable_no_lock( if (enc->crtc != crtc) continue; - DPU_EVT32(DRMID(&dpu_crtc->base), DRMID(enc), enable, - dpu_crtc->enabled, - dpu_crtc->suspend, - dpu_crtc->vblank_requested); + trace_dpu_crtc_vblank_enable(DRMID(&dpu_crtc->base), + DRMID(enc), enable, + dpu_crtc); dpu_encoder_register_vblank_callback(enc, NULL, NULL); } @@ -1532,8 +1505,7 @@ static void _dpu_crtc_set_suspend(struct drm_crtc *crtc, bool enable) } dpu_kms = to_dpu_kms(priv->kms); - DPU_DEBUG("crtc%d suspend = %d\n", crtc->base.id, enable); - DPU_EVT32_VERBOSE(DRMID(crtc), enable); + DRM_DEBUG_KMS("crtc%d suspend = %d\n", crtc->base.id, enable); mutex_lock(&dpu_crtc->crtc_lock); @@ -1541,8 +1513,7 @@ static void _dpu_crtc_set_suspend(struct drm_crtc *crtc, bool enable) * If the vblank is enabled, release a power reference on suspend * and take it back during resume (if it is still enabled). */ - DPU_EVT32(DRMID(&dpu_crtc->base), enable, dpu_crtc->enabled, - dpu_crtc->suspend, dpu_crtc->vblank_requested); + trace_dpu_crtc_set_suspend(DRMID(&dpu_crtc->base), enable, dpu_crtc); if (dpu_crtc->suspend == enable) DPU_DEBUG("crtc%d suspend already set to %d, ignoring update\n", crtc->base.id, enable); @@ -1644,7 +1615,7 @@ static void dpu_crtc_handle_power_event(u32 event_type, void *arg) mutex_lock(&dpu_crtc->crtc_lock); - DPU_EVT32(DRMID(crtc), event_type); + trace_dpu_crtc_handle_power_event(DRMID(crtc), event_type); switch (event_type) { case DPU_POWER_EVENT_POST_ENABLE: @@ -1712,13 +1683,12 @@ static void dpu_crtc_disable(struct drm_crtc *crtc) mode = &cstate->base.adjusted_mode; priv = crtc->dev->dev_private; - DPU_DEBUG("crtc%d\n", crtc->base.id); + DRM_DEBUG_KMS("crtc%d\n", crtc->base.id); if (dpu_kms_is_suspend_state(crtc->dev)) _dpu_crtc_set_suspend(crtc, true); mutex_lock(&dpu_crtc->crtc_lock); - DPU_EVT32_VERBOSE(DRMID(crtc)); /* update color processing on suspend */ event.type = DRM_EVENT_CRTC_POWER; @@ -1733,8 +1703,7 @@ static void dpu_crtc_disable(struct drm_crtc *crtc) crtc->base.id, atomic_read(&dpu_crtc->frame_pending)); - DPU_EVT32(DRMID(crtc), dpu_crtc->enabled, dpu_crtc->suspend, - dpu_crtc->vblank_requested); + trace_dpu_crtc_disable(DRMID(crtc), false, dpu_crtc); if (dpu_crtc->enabled && !dpu_crtc->suspend && dpu_crtc->vblank_requested) { ret = _dpu_crtc_vblank_enable_no_lock(dpu_crtc, false); @@ -1745,8 +1714,8 @@ static void dpu_crtc_disable(struct drm_crtc *crtc) dpu_crtc->enabled = false; if (atomic_read(&dpu_crtc->frame_pending)) { - DPU_EVT32(DRMID(crtc), atomic_read(&dpu_crtc->frame_pending), - DPU_EVTLOG_FUNC_CASE2); + trace_dpu_crtc_disable_frame_pending(DRMID(crtc), + atomic_read(&dpu_crtc->frame_pending)); dpu_core_perf_crtc_release_bw(crtc); atomic_set(&dpu_crtc->frame_pending, 0); } @@ -1791,8 +1760,7 @@ static void dpu_crtc_enable(struct drm_crtc *crtc, } priv = crtc->dev->dev_private; - DPU_DEBUG("crtc%d\n", crtc->base.id); - DPU_EVT32_VERBOSE(DRMID(crtc)); + DRM_DEBUG_KMS("crtc%d\n", crtc->base.id); dpu_crtc = to_dpu_crtc(crtc); drm_for_each_encoder(encoder, crtc->dev) { @@ -1803,8 +1771,7 @@ static void dpu_crtc_enable(struct drm_crtc *crtc, } mutex_lock(&dpu_crtc->crtc_lock); - DPU_EVT32(DRMID(crtc), dpu_crtc->enabled, dpu_crtc->suspend, - dpu_crtc->vblank_requested); + trace_dpu_crtc_enable(DRMID(crtc), true, dpu_crtc); if (!dpu_crtc->enabled && !dpu_crtc->suspend && dpu_crtc->vblank_requested) { ret = _dpu_crtc_vblank_enable_no_lock(dpu_crtc, true); @@ -2078,8 +2045,7 @@ int dpu_crtc_vblank(struct drm_crtc *crtc, bool en) dpu_crtc = to_dpu_crtc(crtc); mutex_lock(&dpu_crtc->crtc_lock); - DPU_EVT32(DRMID(&dpu_crtc->base), en, dpu_crtc->enabled, - dpu_crtc->suspend, dpu_crtc->vblank_requested); + trace_dpu_crtc_vblank(DRMID(&dpu_crtc->base), en, dpu_crtc); if (dpu_crtc->enabled && !dpu_crtc->suspend) { ret = _dpu_crtc_vblank_enable_no_lock(dpu_crtc, en); if (ret) diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_trace.h b/drivers/gpu/drm/msm/disp/dpu1/dpu_trace.h index b00bdcd0f4e8..877621184782 100644 --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_trace.h +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_trace.h @@ -17,8 +17,10 @@ #include <linux/types.h> #include <linux/tracepoint.h> +#include "dpu_crtc.h" #include "dpu_encoder_phys.h" #include "dpu_hw_mdss.h" +#include "dpu_plane.h" #undef TRACE_SYSTEM #define TRACE_SYSTEM dpu @@ -324,6 +326,18 @@ DEFINE_EVENT(dpu_drm_obj_template, dpu_enc_prepare_kickoff_reset, TP_PROTO(uint32_t drm_id), TP_ARGS(drm_id) ); +DEFINE_EVENT(dpu_drm_obj_template, dpu_crtc_complete_flip, + TP_PROTO(uint32_t drm_id), + TP_ARGS(drm_id) +); +DEFINE_EVENT(dpu_drm_obj_template, dpu_crtc_vblank_cb, + TP_PROTO(uint32_t drm_id), + TP_ARGS(drm_id) +); +DEFINE_EVENT(dpu_drm_obj_template, dpu_crtc_complete_commit, + TP_PROTO(uint32_t drm_id), + TP_ARGS(drm_id) +); TRACE_EVENT(dpu_enc_enable, TP_PROTO(uint32_t drm_id, int hdisplay, int vdisplay), @@ -532,6 +546,22 @@ DEFINE_EVENT(dpu_id_event_template, dpu_enc_frame_done_timeout, TP_PROTO(uint32_t drm_id, u32 event), TP_ARGS(drm_id, event) ); +DEFINE_EVENT(dpu_id_event_template, dpu_crtc_frame_event_cb, + TP_PROTO(uint32_t drm_id, u32 event), + TP_ARGS(drm_id, event) +); +DEFINE_EVENT(dpu_id_event_template, dpu_crtc_handle_power_event, + TP_PROTO(uint32_t drm_id, u32 event), + TP_ARGS(drm_id, event) +); +DEFINE_EVENT(dpu_id_event_template, dpu_crtc_frame_event_done, + TP_PROTO(uint32_t drm_id, u32 event), + TP_ARGS(drm_id, event) +); +DEFINE_EVENT(dpu_id_event_template, dpu_crtc_frame_event_more_pending, + TP_PROTO(uint32_t drm_id, u32 event), + TP_ARGS(drm_id, event) +); TRACE_EVENT(dpu_enc_wait_event_timeout, TP_PROTO(uint32_t drm_id, int32_t hw_id, int rc, s64 time, @@ -558,6 +588,142 @@ TRACE_EVENT(dpu_enc_wait_event_timeout, __entry->expected_time, __entry->atomic_cnt) ); +TRACE_EVENT(dpu_crtc_setup_mixer, + TP_PROTO(uint32_t crtc_id, uint32_t plane_id, + struct drm_plane_state *state, struct dpu_plane_state *pstate, + uint32_t stage_idx, enum dpu_sspp sspp, uint32_t pixel_format, + uint64_t modifier), + TP_ARGS(crtc_id, plane_id, state, pstate, stage_idx, sspp, + pixel_format, modifier), + TP_STRUCT__entry( + __field( uint32_t, crtc_id ) + __field( uint32_t, plane_id ) + __field( struct drm_plane_state*,state ) + __field( struct dpu_plane_state*,pstate ) + __field( uint32_t, stage_idx ) + __field( enum dpu_sspp, sspp ) + __field( uint32_t, pixel_format ) + __field( uint64_t, modifier ) + ), + TP_fast_assign( + __entry->crtc_id = crtc_id; + __entry->plane_id = plane_id; + __entry->state = state; + __entry->pstate = pstate; + __entry->stage_idx = stage_idx; + __entry->sspp = sspp; + __entry->pixel_format = pixel_format; + __entry->modifier = modifier; + ), + TP_printk("crtc_id:%u plane_id:%u fb_id:%u src:{%ux%u+%ux%u} " + "dst:{%ux%u+%ux%u} stage_idx:%u stage:%d, sspp:%d " + "multirect_index:%d multirect_mode:%u pix_format:%u " + "modifier:%llu", + __entry->crtc_id, __entry->plane_id, + __entry->state->fb ? __entry->state->fb->base.id : -1, + __entry->state->src_w >> 16, __entry->state->src_h >> 16, + __entry->state->src_x >> 16, __entry->state->src_y >> 16, + __entry->state->crtc_w, __entry->state->crtc_h, + __entry->state->crtc_x, __entry->state->crtc_y, + __entry->stage_idx, __entry->pstate->stage, __entry->sspp, + __entry->pstate->multirect_index, + __entry->pstate->multirect_mode, __entry->pixel_format, + __entry->modifier) +); + +TRACE_EVENT(dpu_crtc_setup_lm_bounds, + TP_PROTO(uint32_t drm_id, int mixer, struct dpu_rect *bounds), + TP_ARGS(drm_id, mixer, bounds), + TP_STRUCT__entry( + __field( uint32_t, drm_id ) + __field( int, mixer ) + __field( struct dpu_rect *, bounds ) + ), + TP_fast_assign( + __entry->drm_id = drm_id; + __entry->mixer = mixer; + __entry->bounds = bounds; + ), + TP_printk("id:%u mixer:%d bounds:{%ux%u/%ux%u}", __entry->drm_id, + __entry->mixer, __entry->bounds->x, __entry->bounds->y, + __entry->bounds->w, __entry->bounds->h) +); + +TRACE_EVENT(dpu_crtc_vblank_enable, + TP_PROTO(uint32_t drm_id, uint32_t enc_id, bool enable, + struct dpu_crtc *crtc), + TP_ARGS(drm_id, enc_id, enable, crtc), + TP_STRUCT__entry( + __field( uint32_t, drm_id ) + __field( uint32_t, enc_id ) + __field( bool, enable ) + __field( struct dpu_crtc *, crtc ) + ), + TP_fast_assign( + __entry->drm_id = drm_id; + __entry->enc_id = enc_id; + __entry->enable = enable; + __entry->crtc = crtc; + ), + TP_printk("id:%u encoder:%u enable:%s state{enabled:%s suspend:%s " + "vblank_req:%s}", + __entry->drm_id, __entry->enc_id, + __entry->enable ? "true" : "false", + __entry->crtc->enabled ? "true" : "false", + __entry->crtc->suspend ? "true" : "false", + __entry->crtc->vblank_requested ? "true" : "false") +); + +DECLARE_EVENT_CLASS(dpu_crtc_enable_template, + TP_PROTO(uint32_t drm_id, bool enable, struct dpu_crtc *crtc), + TP_ARGS(drm_id, enable, crtc), + TP_STRUCT__entry( + __field( uint32_t, drm_id ) + __field( bool, enable ) + __field( struct dpu_crtc *, crtc ) + ), + TP_fast_assign( + __entry->drm_id = drm_id; + __entry->enable = enable; + __entry->crtc = crtc; + ), + TP_printk("id:%u enable:%s state{enabled:%s suspend:%s vblank_req:%s}", + __entry->drm_id, __entry->enable ? "true" : "false", + __entry->crtc->enabled ? "true" : "false", + __entry->crtc->suspend ? "true" : "false", + __entry->crtc->vblank_requested ? "true" : "false") +); +DEFINE_EVENT(dpu_crtc_enable_template, dpu_crtc_set_suspend, + TP_PROTO(uint32_t drm_id, bool enable, struct dpu_crtc *crtc), + TP_ARGS(drm_id, enable, crtc) +); +DEFINE_EVENT(dpu_crtc_enable_template, dpu_crtc_enable, + TP_PROTO(uint32_t drm_id, bool enable, struct dpu_crtc *crtc), + TP_ARGS(drm_id, enable, crtc) +); +DEFINE_EVENT(dpu_crtc_enable_template, dpu_crtc_disable, + TP_PROTO(uint32_t drm_id, bool enable, struct dpu_crtc *crtc), + TP_ARGS(drm_id, enable, crtc) +); +DEFINE_EVENT(dpu_crtc_enable_template, dpu_crtc_vblank, + TP_PROTO(uint32_t drm_id, bool enable, struct dpu_crtc *crtc), + TP_ARGS(drm_id, enable, crtc) +); + +TRACE_EVENT(dpu_crtc_disable_frame_pending, + TP_PROTO(uint32_t drm_id, int frame_pending), + TP_ARGS(drm_id, frame_pending), + TP_STRUCT__entry( + __field( uint32_t, drm_id ) + __field( int, frame_pending ) + ), + TP_fast_assign( + __entry->drm_id = drm_id; + __entry->frame_pending = frame_pending; + ), + TP_printk("id:%u frame_pending:%d", __entry->drm_id, + __entry->frame_pending) +); #define DPU_ATRACE_END(name) trace_tracing_mark_write(current->tgid, name, 0) #define DPU_ATRACE_BEGIN(name) trace_tracing_mark_write(current->tgid, name, 1) -- Sean Paul, Software Engineer, Google / Chromium OS _______________________________________________ Freedreno mailing list Freedreno@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/freedreno