[Mesa-dev] [PATCH 8/8] i965: Add perf debug for stalls during shader compiles.

[Kenneth Graunke]

On 08/07/2012 11:04 AM, Eric Anholt wrote:
> ---
>  src/mesa/drivers/dri/i965/brw_fs.cpp        |   13 +++++++++++++
>  src/mesa/drivers/dri/i965/brw_vec4_emit.cpp |   20 ++++++++++++++++++--
>  src/mesa/drivers/dri/intel/intel_screen.c   |   13 +++++++++++++
>  src/mesa/drivers/dri/intel/intel_screen.h   |    1 +
>  4 files changed, 45 insertions(+), 2 deletions(-)
> 
> diff --git a/src/mesa/drivers/dri/i965/brw_fs.cpp b/src/mesa/drivers/dri/i965/brw_fs.cpp
> index 90a1d92..dfd101f 100644
> --- a/src/mesa/drivers/dri/i965/brw_fs.cpp
> +++ b/src/mesa/drivers/dri/i965/brw_fs.cpp
> @@ -2044,10 +2044,18 @@ brw_wm_fs_emit(struct brw_context *brw, struct brw_wm_compile *c,
>  	       struct gl_shader_program *prog)
>  {
>     struct intel_context *intel = &brw->intel;
> +   bool start_busy = false;
> +   float start_time = 0;
>  
>     if (!prog)
>        return false;
>  
> +   if (unlikely(INTEL_DEBUG & DEBUG_PERF)) {
> +      start_busy = (intel->batch.last_bo &&
> +                    drm_intel_bo_busy(intel->batch.last_bo));
> +      start_time = get_time();
> +   }
> +
>     struct brw_shader *shader =
>       (brw_shader *) prog->_LinkedShaders[MESA_SHADER_FRAGMENT];
>     if (!shader)
> @@ -2090,6 +2098,11 @@ brw_wm_fs_emit(struct brw_context *brw, struct brw_wm_compile *c,
>        if (shader->compiled_once)
>           brw_wm_debug_recompile(brw, prog, &c->key);
>        shader->compiled_once = true;
> +
> +      if (start_busy && !drm_intel_bo_busy(intel->batch.last_bo)) {
> +         perf_debug("FS compile took %.03f ms and stalled the GPU\n",
> +                    (get_time() - start_time) / 1000);
> +      }
>     }
>  
>     return true;
> diff --git a/src/mesa/drivers/dri/i965/brw_vec4_emit.cpp b/src/mesa/drivers/dri/i965/brw_vec4_emit.cpp
> index 788d7b5..0db435b 100644
> --- a/src/mesa/drivers/dri/i965/brw_vec4_emit.cpp
> +++ b/src/mesa/drivers/dri/i965/brw_vec4_emit.cpp
> @@ -1017,9 +1017,19 @@ extern "C" {
>  bool
>  brw_vs_emit(struct gl_shader_program *prog, struct brw_vs_compile *c)
>  {
> +   struct intel_context *intel = &c->func.brw->intel;
> +   bool start_busy = false;
> +   float start_time = 0;
> +
>     if (!prog)
>        return false;
>  
> +   if (unlikely(INTEL_DEBUG & DEBUG_PERF)) {
> +      start_busy = (intel->batch.last_bo &&
> +                    drm_intel_bo_busy(intel->batch.last_bo));
> +      start_time = get_time();
> +   }
> +
>     struct brw_shader *shader =
>       (brw_shader *) prog->_LinkedShaders[MESA_SHADER_VERTEX];
>     if (!shader)
> @@ -1031,8 +1041,14 @@ brw_vs_emit(struct gl_shader_program *prog, struct brw_vs_compile *c)
>        printf("\n\n");
>     }
>  
> -   if (shader->compiled_once) {
> -      perf_debug("Recompiling vertex shader for program %d\n", prog->Name);
> +   if (unlikely(INTEL_DEBUG & DEBUG_PERF)) {
> +      if (shader->compiled_once) {
> +         perf_debug("Recompiling vertex shader for program %d\n", prog->Name);
> +      }
> +      if (start_busy && !drm_intel_bo_busy(intel->batch.last_bo)) {
> +         perf_debug("VS compile took %.03f ms and stalled the GPU\n",
> +                    (get_time() - start_time) / 1000);
> +      }
>     }
>  
>     vec4_visitor v(c, prog, shader);
> diff --git a/src/mesa/drivers/dri/intel/intel_screen.c b/src/mesa/drivers/dri/intel/intel_screen.c
> index 5c38c8d..56abc12 100644
> --- a/src/mesa/drivers/dri/intel/intel_screen.c
> +++ b/src/mesa/drivers/dri/intel/intel_screen.c
> @@ -109,6 +109,19 @@ const GLuint __driNConfigOptions = 15;
>  static PFNGLXCREATECONTEXTMODES create_context_modes = NULL;
>  #endif /*USE_NEW_INTERFACE */
>  
> +/**
> + * For debugging, this returns a time in seconds since the first call.
> + */

Doesn't seem to be "since the first call".

Otherwise, this series looks great!  It'll be extremely useful.
Reviewed-by: Kenneth Graunke <kenneth at whitecape.org>

> +double
> +get_time(void)
> +{
> +   struct timespec tp;
> +
> +   clock_gettime(CLOCK_MONOTONIC, &tp);
> +
> +   return tp.tv_sec + tp.tv_nsec / 1000000000.0;
> +}
> +
>  void
>  aub_dump_bmp(struct gl_context *ctx)
>  {
> diff --git a/src/mesa/drivers/dri/intel/intel_screen.h b/src/mesa/drivers/dri/intel/intel_screen.h
> index c0cc284..f5a374d 100644
> --- a/src/mesa/drivers/dri/intel/intel_screen.h
> +++ b/src/mesa/drivers/dri/intel/intel_screen.h
> @@ -81,6 +81,7 @@ intelMakeCurrent(__DRIcontext * driContextPriv,
>                   __DRIdrawable * driDrawPriv,
>                   __DRIdrawable * driReadPriv);
>  
> +double get_time(void);
>  void aub_dump_bmp(struct gl_context *ctx);
>  
>  #endif
>