On Wed, Dec 02, 2020 at 09:28:09PM +0000, Chris Wilson wrote: > Since we try and estimate how long we require to update the registers to > perform a plane update, it is of vital importance that we measure the > distribution of plane updates to better guide our estimate. If we > underestimate how long it takes to perform the plane update, we may > slip into the next scanout frame causing a tear. If we overestimate, we > may unnecessarily delay the update to the next frame, causing visible > jitter. > > Replace the warning that we exceed some arbitrary threshold for the > vblank update with a histogram for debugfs. > > v2: Add a per-crtc debugfs entry so that the information is easier to > extract when testing individual CRTC, and so that it can be reset before > a test. > > v3: Flip the graph on its side; creates space to label the time axis. > > Updates: 4684 > | > 1us | > | > 4us |******** > |********** > 16us |*********** > |***** > 66us | > | > 262us | > | > 1ms | > | > 4ms | > | > 17ms | > | Going that high feels a bit overkill to me. I'd be satisified with an upper limit of <1ms or something. Anyways, this orientation seems more readable. Reviewed-by: Ville Syrjälä <ville.syrjala@xxxxxxxxxxxxxxx> > Min update: 5918ns > Max update: 54781ns > Average update: 16628ns > Overruns > 250us: 0 > > Closes: https://gitlab.freedesktop.org/drm/intel/-/issues/1982 > Signed-off-by: Chris Wilson <chris@xxxxxxxxxxxxxxxxxx> > Cc: Jani Nikula <jani.nikula@xxxxxxxxxxxxxxx> > Cc: Ville Syrjälä <ville.syrjala@xxxxxxxxxxxxxxx> > --- > drivers/gpu/drm/i915/display/intel_display.c | 10 +- > .../drm/i915/display/intel_display_debugfs.c | 124 ++++++++++++++++++ > .../drm/i915/display/intel_display_debugfs.h | 3 + > .../drm/i915/display/intel_display_types.h | 9 ++ > drivers/gpu/drm/i915/display/intel_sprite.c | 49 ++++--- > drivers/gpu/drm/i915/display/intel_sprite.h | 10 ++ > 6 files changed, 187 insertions(+), 18 deletions(-) > > diff --git a/drivers/gpu/drm/i915/display/intel_display.c b/drivers/gpu/drm/i915/display/intel_display.c > index ba26545392bc..9187a20a8aca 100644 > --- a/drivers/gpu/drm/i915/display/intel_display.c > +++ b/drivers/gpu/drm/i915/display/intel_display.c > @@ -45,6 +45,7 @@ > > #include "display/intel_crt.h" > #include "display/intel_ddi.h" > +#include "display/intel_display_debugfs.h" > #include "display/intel_dp.h" > #include "display/intel_dp_mst.h" > #include "display/intel_dpll_mgr.h" > @@ -17266,6 +17267,12 @@ intel_cursor_plane_create(struct drm_i915_private *dev_priv, > return ERR_PTR(ret); > } > > +static int intel_crtc_late_register(struct drm_crtc *crtc) > +{ > + intel_crtc_debugfs_add(crtc); > + return 0; > +} > + > #define INTEL_CRTC_FUNCS \ > .gamma_set = drm_atomic_helper_legacy_gamma_set, \ > .set_config = drm_atomic_helper_set_config, \ > @@ -17275,7 +17282,8 @@ intel_cursor_plane_create(struct drm_i915_private *dev_priv, > .atomic_destroy_state = intel_crtc_destroy_state, \ > .set_crc_source = intel_crtc_set_crc_source, \ > .verify_crc_source = intel_crtc_verify_crc_source, \ > - .get_crc_sources = intel_crtc_get_crc_sources > + .get_crc_sources = intel_crtc_get_crc_sources, \ > + .late_register = intel_crtc_late_register > > static const struct drm_crtc_funcs bdw_crtc_funcs = { > INTEL_CRTC_FUNCS, > diff --git a/drivers/gpu/drm/i915/display/intel_display_debugfs.c b/drivers/gpu/drm/i915/display/intel_display_debugfs.c > index ca41e8c00ad7..cd7e5519ee7d 100644 > --- a/drivers/gpu/drm/i915/display/intel_display_debugfs.c > +++ b/drivers/gpu/drm/i915/display/intel_display_debugfs.c > @@ -18,6 +18,7 @@ > #include "intel_pm.h" > #include "intel_psr.h" > #include "intel_sideband.h" > +#include "intel_sprite.h" > > static inline struct drm_i915_private *node_to_i915(struct drm_info_node *node) > { > @@ -865,6 +866,110 @@ static void intel_scaler_info(struct seq_file *m, struct intel_crtc *crtc) > } > } > > +#if IS_ENABLED(CONFIG_DRM_I915_DEBUG_VBLANK_EVADE) > +static void crtc_updates_info(struct seq_file *m, > + struct intel_crtc *crtc, > + const char *hdr) > +{ > + u64 count; > + int row; > + > + count = 0; > + for (row = 0; row < ARRAY_SIZE(crtc->debug.vbl.times); row++) > + count += crtc->debug.vbl.times[row]; > + seq_printf(m, "%sUpdates: %llu\n", hdr, count); > + if (!count) > + return; > + > + for (row = 0; row < ARRAY_SIZE(crtc->debug.vbl.times); row++) { > + char columns[80] = " |"; > + unsigned int x; > + > + if (row & 1) { > + const char *units; > + > + if (row > 10) { > + x = 1000000; > + units = "ms"; > + } else { > + x = 1000; > + units = "us"; > + } > + > + snprintf(columns, sizeof(columns), "%4ld%s |", > + DIV_ROUND_CLOSEST(BIT(row + 9), x), units); > + } > + > + if (crtc->debug.vbl.times[row]) { > + x = ilog2(crtc->debug.vbl.times[row]); > + memset(columns + 8, '*', x); > + columns[8 + x] = '\0'; > + } > + > + seq_printf(m, "%s%s\n", hdr, columns); > + } > + > + seq_printf(m, "%sMin update: %lluns\n", > + hdr, crtc->debug.vbl.min); > + seq_printf(m, "%sMax update: %lluns\n", > + hdr, crtc->debug.vbl.max); > + seq_printf(m, "%sAverage update: %lluns\n", > + hdr, div64_u64(crtc->debug.vbl.sum, count)); > + seq_printf(m, "%sOverruns > %uus: %u\n", > + hdr, VBLANK_EVASION_TIME_US, crtc->debug.vbl.over); > +} > + > +static int crtc_updates_show(struct seq_file *m, void *data) > +{ > + crtc_updates_info(m, m->private, ""); > + return 0; > +} > + > +static int crtc_updates_open(struct inode *inode, struct file *file) > +{ > + return single_open(file, crtc_updates_show, inode->i_private); > +} > + > +static ssize_t crtc_updates_write(struct file *file, > + const char __user *ubuf, > + size_t len, loff_t *offp) > +{ > + struct seq_file *m = file->private_data; > + struct intel_crtc *crtc = m->private; > + > + /* May race with an update. Meh. */ > + memset(&crtc->debug.vbl, 0, sizeof(crtc->debug.vbl)); > + > + return len; > +} > + > +static const struct file_operations crtc_updates_fops = { > + .owner = THIS_MODULE, > + .open = crtc_updates_open, > + .read = seq_read, > + .llseek = seq_lseek, > + .release = single_release, > + .write = crtc_updates_write > +}; > + > +static void crtc_updates_add(struct drm_crtc *crtc) > +{ > + debugfs_create_file("i915_update_info", 0644, crtc->debugfs_entry, > + to_intel_crtc(crtc), &crtc_updates_fops); > +} > + > +#else > +static void crtc_updates_info(struct seq_file *m, > + struct intel_crtc *crtc, > + const char *hdr) > +{ > +} > + > +static void crtc_updates_add(struct drm_crtc *crtc) > +{ > +} > +#endif > + > static void intel_crtc_info(struct seq_file *m, struct intel_crtc *crtc) > { > struct drm_i915_private *dev_priv = node_to_i915(m->private); > @@ -907,6 +1012,8 @@ static void intel_crtc_info(struct seq_file *m, struct intel_crtc *crtc) > seq_printf(m, "\tunderrun reporting: cpu=%s pch=%s\n", > yesno(!crtc->cpu_fifo_underrun_disabled), > yesno(!crtc->pch_fifo_underrun_disabled)); > + > + crtc_updates_info(m, crtc, "\t"); > } > > static int i915_display_info(struct seq_file *m, void *unused) > @@ -2278,3 +2385,20 @@ int intel_connector_debugfs_add(struct drm_connector *connector) > > return 0; > } > + > +/** > + * intel_crtc_debugfs_add - add i915 specific crtc debugfs files > + * @crtc: pointer to a drm_crtc > + * > + * Returns 0 on success, negative error codes on error. > + * > + * Failure to add debugfs entries should generally be ignored. > + */ > +int intel_crtc_debugfs_add(struct drm_crtc *crtc) > +{ > + if (!crtc->debugfs_entry) > + return -ENODEV; > + > + crtc_updates_add(crtc); > + return 0; > +} > diff --git a/drivers/gpu/drm/i915/display/intel_display_debugfs.h b/drivers/gpu/drm/i915/display/intel_display_debugfs.h > index c922c1745bfe..557901f3eb90 100644 > --- a/drivers/gpu/drm/i915/display/intel_display_debugfs.h > +++ b/drivers/gpu/drm/i915/display/intel_display_debugfs.h > @@ -7,14 +7,17 @@ > #define __INTEL_DISPLAY_DEBUGFS_H__ > > struct drm_connector; > +struct drm_crtc; > struct drm_i915_private; > > #ifdef CONFIG_DEBUG_FS > void intel_display_debugfs_register(struct drm_i915_private *i915); > int intel_connector_debugfs_add(struct drm_connector *connector); > +int intel_crtc_debugfs_add(struct drm_crtc *crtc); > #else > static inline void intel_display_debugfs_register(struct drm_i915_private *i915) {} > static inline int intel_connector_debugfs_add(struct drm_connector *connector) { return 0; } > +static inline int intel_crtc_debugfs_add(struct drm_crtc *crtc) { return 0; } > #endif > > #endif /* __INTEL_DISPLAY_DEBUGFS_H__ */ > diff --git a/drivers/gpu/drm/i915/display/intel_display_types.h b/drivers/gpu/drm/i915/display/intel_display_types.h > index 491e3550174f..d426dd31479e 100644 > --- a/drivers/gpu/drm/i915/display/intel_display_types.h > +++ b/drivers/gpu/drm/i915/display/intel_display_types.h > @@ -1188,6 +1188,15 @@ struct intel_crtc { > ktime_t start_vbl_time; > int min_vbl, max_vbl; > int scanline_start; > +#ifdef CONFIG_DRM_I915_DEBUG_VBLANK_EVADE > + struct { > + u64 min; > + u64 max; > + u64 sum; > + unsigned int over; > + unsigned int times[17]; /* [1us, 16ms] */ > + } vbl; > +#endif > } debug; > > /* scalers available on this crtc */ > diff --git a/drivers/gpu/drm/i915/display/intel_sprite.c b/drivers/gpu/drm/i915/display/intel_sprite.c > index 019a2d6d807a..b7e208816074 100644 > --- a/drivers/gpu/drm/i915/display/intel_sprite.c > +++ b/drivers/gpu/drm/i915/display/intel_sprite.c > @@ -61,14 +61,6 @@ int intel_usecs_to_scanlines(const struct drm_display_mode *adjusted_mode, > 1000 * adjusted_mode->crtc_htotal); > } > > -/* FIXME: We should instead only take spinlocks once for the entire update > - * instead of once per mmio. */ > -#if IS_ENABLED(CONFIG_PROVE_LOCKING) > -#define VBLANK_EVASION_TIME_US 250 > -#else > -#define VBLANK_EVASION_TIME_US 100 > -#endif > - > /** > * intel_pipe_update_start() - start update of a set of display registers > * @new_crtc_state: the new crtc state > @@ -187,6 +179,36 @@ void intel_pipe_update_start(const struct intel_crtc_state *new_crtc_state) > local_irq_disable(); > } > > +#if IS_ENABLED(CONFIG_DRM_I915_DEBUG_VBLANK_EVADE) > +static void dbg_vblank_evade(struct intel_crtc *crtc, ktime_t end) > +{ > + u64 delta = ktime_to_ns(ktime_sub(end, crtc->debug.start_vbl_time)); > + unsigned int h; > + > + h = ilog2(delta >> 9); > + if (h >= ARRAY_SIZE(crtc->debug.vbl.times)) > + h = ARRAY_SIZE(crtc->debug.vbl.times) - 1; > + crtc->debug.vbl.times[h]++; > + > + crtc->debug.vbl.sum += delta; > + if (!crtc->debug.vbl.min || delta < crtc->debug.vbl.min) > + crtc->debug.vbl.min = delta; > + if (delta > crtc->debug.vbl.max) > + crtc->debug.vbl.max = delta; > + > + if (delta > 1000 * VBLANK_EVASION_TIME_US) { > + drm_dbg_kms(crtc->base.dev, > + "Atomic update on pipe (%c) took %lld us, max time under evasion is %u us\n", > + pipe_name(crtc->pipe), > + div_u64(delta, 1000), > + VBLANK_EVASION_TIME_US); > + crtc->debug.vbl.over++; > + } > +} > +#else > +static void dbg_vblank_evade(struct intel_crtc *crtc, ktime_t end) {} > +#endif > + > /** > * intel_pipe_update_end() - end update of a set of display registers > * @new_crtc_state: the new crtc state > @@ -249,15 +271,8 @@ void intel_pipe_update_end(struct intel_crtc_state *new_crtc_state) > crtc->debug.min_vbl, crtc->debug.max_vbl, > crtc->debug.scanline_start, scanline_end); > } > -#ifdef CONFIG_DRM_I915_DEBUG_VBLANK_EVADE > - else if (ktime_us_delta(end_vbl_time, crtc->debug.start_vbl_time) > > - VBLANK_EVASION_TIME_US) > - drm_warn(&dev_priv->drm, > - "Atomic update on pipe (%c) took %lld us, max time under evasion is %u us\n", > - pipe_name(pipe), > - ktime_us_delta(end_vbl_time, crtc->debug.start_vbl_time), > - VBLANK_EVASION_TIME_US); > -#endif > + > + dbg_vblank_evade(crtc, end_vbl_time); > } > > int intel_plane_check_stride(const struct intel_plane_state *plane_state) > diff --git a/drivers/gpu/drm/i915/display/intel_sprite.h b/drivers/gpu/drm/i915/display/intel_sprite.h > index cd2104ba1ca1..76126dd8d584 100644 > --- a/drivers/gpu/drm/i915/display/intel_sprite.h > +++ b/drivers/gpu/drm/i915/display/intel_sprite.h > @@ -17,6 +17,16 @@ struct drm_i915_private; > struct intel_crtc_state; > struct intel_plane_state; > > +/* > + * FIXME: We should instead only take spinlocks once for the entire update > + * instead of once per mmio. > + */ > +#if IS_ENABLED(CONFIG_PROVE_LOCKING) > +#define VBLANK_EVASION_TIME_US 250 > +#else > +#define VBLANK_EVASION_TIME_US 100 > +#endif > + > int intel_usecs_to_scanlines(const struct drm_display_mode *adjusted_mode, > int usecs); > struct intel_plane *intel_sprite_plane_create(struct drm_i915_private *dev_priv, > -- > 2.20.1 -- Ville Syrjälä Intel _______________________________________________ Intel-gfx mailing list Intel-gfx@xxxxxxxxxxxxxxxxxxxxx https://lists.freedesktop.org/mailman/listinfo/intel-gfx
