intel/compiler: Add id parameter to shader_perf_log callback

There are two problems with the current architecture.

In OpenGL, the id is supposed to be a unique identifier for a particular
log source.  This is done so that applications can (theoretically)
filter particular log messages.  The debug callback infrastructure in
Mesa assigns a uniqe value when a value of 0 is passed in.  This causes
the id to get set once to a unique value for each message.

By passing a stack variable that is initialized to 0 on every call,
every time the same message is logged, it will have a different id.
This isn't great, but it's also not catastrophic.

When threaded shader compiles are used, the id *pointer* is saved and
dereferenced at a possibly much later time on a possibly different
thread.  This causes one thread to access the stack from a different
thread... and that stack frame might not be valid any more. :(

I have not observed any crashes related to this particular issue.

Reviewed-by: Matt Turner <mattst88@gmail.com>
Reviewed-by: Anuj Phogat <anuj.phogat@gmail.com>
Part-of: <https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/12136>

src/gallium/drivers/crocus/crocus_program.c

@@ -1074,10 +1074,10 @@ crocus_debug_recompile(struct crocus_context *ice,
    if (!info)
       return;
 
-   c->shader_perf_log(&ice->dbg, "Recompiling %s shader for program %s: %s\n",
+   brw_shader_perf_log(c, &ice->dbg, "Recompiling %s shader for program %s: %s\n",
-                      _mesa_shader_stage_to_string(info->stage),
+                       _mesa_shader_stage_to_string(info->stage),
-                      info->name ? info->name : "(no identifier)",
+                       info->name ? info->name : "(no identifier)",
-                      info->label ? info->label : "");
+                       info->label ? info->label : "");
 
    const void *old_key =
       crocus_find_previous_compile(ice, info->stage, key->program_string_id);

src/gallium/drivers/crocus/crocus_screen.c

@@ -688,10 +688,9 @@ crocus_shader_debug_log(void *data, unsigned *id, const char *fmt, ...)
 }
 
 static void
-crocus_shader_perf_log(void *data, const char *fmt, ...)
+crocus_shader_perf_log(void *data, unsigned *id, const char *fmt, ...)
 {
    struct pipe_debug_callback *dbg = data;
-   unsigned id = 0;
    va_list args;
    va_start(args, fmt);
 
@@ -703,7 +702,7 @@ crocus_shader_perf_log(void *data, const char *fmt, ...)
    }
 
    if (dbg->debug_message) {
-      dbg->debug_message(dbg->data, &id, PIPE_DEBUG_TYPE_PERF_INFO, fmt, args);
+      dbg->debug_message(dbg->data, id, PIPE_DEBUG_TYPE_PERF_INFO, fmt, args);
    }
 
    va_end(args);

src/gallium/drivers/iris/iris_program.c

@@ -1069,10 +1069,10 @@ iris_debug_recompile(struct iris_screen *screen,
    const struct brw_compiler *c = screen->compiler;
    const struct shader_info *info = &ish->nir->info;
 
-   c->shader_perf_log(dbg, "Recompiling %s shader for program %s: %s\n",
+   brw_shader_perf_log(c, dbg, "Recompiling %s shader for program %s: %s\n",
-                      _mesa_shader_stage_to_string(info->stage),
+                       _mesa_shader_stage_to_string(info->stage),
-                      info->name ? info->name : "(no identifier)",
+                       info->name ? info->name : "(no identifier)",
-                      info->label ? info->label : "");
+                       info->label ? info->label : "");
 
    struct iris_compiled_shader *shader =
       list_first_entry(&ish->variants, struct iris_compiled_shader, link);

src/gallium/drivers/iris/iris_screen.c

@@ -731,10 +731,9 @@ iris_shader_debug_log(void *data, unsigned *id, const char *fmt, ...)
 }
 
 static void
-iris_shader_perf_log(void *data, const char *fmt, ...)
+iris_shader_perf_log(void *data, unsigned *id, const char *fmt, ...)
 {
    struct pipe_debug_callback *dbg = data;
-   unsigned id = 0;
    va_list args;
    va_start(args, fmt);
 
@@ -746,7 +745,7 @@ iris_shader_perf_log(void *data, const char *fmt, ...)
    }
 
    if (dbg->debug_message) {
-      dbg->debug_message(dbg->data, &id, PIPE_DEBUG_TYPE_PERF_INFO, fmt, args);
+      dbg->debug_message(dbg->data, id, PIPE_DEBUG_TYPE_PERF_INFO, fmt, args);
    }
 
    va_end(args);

src/intel/compiler/brw_compiler.h

@@ -70,7 +70,7 @@ struct brw_compiler {
    } fs_reg_sets[3];
 
    void (*shader_debug_log)(void *, unsigned *id, const char *str, ...) PRINTFLIKE(3, 4);
-   void (*shader_perf_log)(void *, const char *str, ...) PRINTFLIKE(2, 3);
+   void (*shader_perf_log)(void *, unsigned *id, const char *str, ...) PRINTFLIKE(3, 4);
 
    bool scalar_stage[MESA_ALL_SHADER_STAGES];
    bool use_tcs_8_patch;
@@ -126,6 +126,11 @@ struct brw_compiler {
    compiler->shader_debug_log(data, &id, fmt, ##__VA_ARGS__);   \
 } while (0)
 
+#define brw_shader_perf_log(compiler, data, fmt, ... ) do {     \
+   static unsigned id = 0;                                      \
+   compiler->shader_perf_log(data, &id, fmt, ##__VA_ARGS__);    \
+} while (0)
+
 /**
  * We use a constant subgroup size of 32.  It really only needs to be a
  * maximum and, since we do SIMD32 for compute shaders in some cases, it

src/intel/compiler/brw_debug_recompile.c

@@ -33,7 +33,7 @@ key_debug(const struct brw_compiler *c, void *log,
           const char *name, int a, int b)
 {
    if (a != b) {
-      c->shader_perf_log(log, "  %s %d->%d\n", name, a, b);
+      brw_shader_perf_log(c, log, "  %s %d->%d\n", name, a, b);
       return true;
    }
    return false;
@@ -44,7 +44,7 @@ key_debug_float(const struct brw_compiler *c, void *log,
                 const char *name, float a, float b)
 {
    if (a != b) {
-      c->shader_perf_log(log, "  %s %f->%f\n", name, a, b);
+      brw_shader_perf_log(c, log, "  %s %f->%f\n", name, a, b);
       return true;
    }
    return false;
@@ -111,7 +111,7 @@ debug_vs_recompile(const struct brw_compiler *c, void *log,
    found |= check("vertex color clamping", clamp_vertex_color);
 
    if (!found) {
-      c->shader_perf_log(log, "  something else\n");
+      brw_shader_perf_log(c, log, "  something else\n");
    }
 }
 
@@ -129,7 +129,7 @@ debug_tcs_recompile(const struct brw_compiler *c, void *log,
    found |= check("quads and equal_spacing workaround", quads_workaround);
 
    if (!found) {
-      c->shader_perf_log(log, "  something else\n");
+      brw_shader_perf_log(c, log, "  something else\n");
    }
 }
 
@@ -144,7 +144,7 @@ debug_tes_recompile(const struct brw_compiler *c, void *log,
    found |= check("patch inputs read", patch_inputs_read);
 
    if (!found) {
-      c->shader_perf_log(log, "  something else\n");
+      brw_shader_perf_log(c, log, "  something else\n");
    }
 }
 
@@ -156,7 +156,7 @@ debug_gs_recompile(const struct brw_compiler *c, void *log,
    bool found = debug_base_recompile(c, log, &old_key->base, &key->base);
 
    if (!found) {
-      c->shader_perf_log(log, "  something else\n");
+      brw_shader_perf_log(c, log, "  something else\n");
    }
 }
 
@@ -190,7 +190,7 @@ debug_fs_recompile(const struct brw_compiler *c, void *log,
    found |= debug_base_recompile(c, log, &old_key->base, &key->base);
 
    if (!found) {
-      c->shader_perf_log(log, "  something else\n");
+      brw_shader_perf_log(c, log, "  something else\n");
    }
 }
 
@@ -202,7 +202,7 @@ debug_cs_recompile(const struct brw_compiler *c, void *log,
    bool found = debug_base_recompile(c, log, &old_key->base, &key->base);
 
    if (!found) {
-      c->shader_perf_log(log, "  something else\n");
+      brw_shader_perf_log(c, log, "  something else\n");
    }
 }
 
@@ -213,7 +213,7 @@ brw_debug_key_recompile(const struct brw_compiler *c, void *log,
                         const struct brw_base_prog_key *key)
 {
    if (!old_key) {
-      c->shader_perf_log(log, "  No previous compile found...\n");
+      brw_shader_perf_log(c, log, "  No previous compile found...\n");
       return;
    }
 

src/intel/compiler/brw_fs.cpp

@@ -715,9 +715,9 @@ fs_visitor::limit_dispatch_width(unsigned n, const char *msg)
       fail("%s", msg);
    } else {
       max_dispatch_width = MIN2(max_dispatch_width, n);
-      compiler->shader_perf_log(log_data,
+      brw_shader_perf_log(compiler, log_data,
-                                "Shader dispatch width limited to SIMD%d: %s",
+                          "Shader dispatch width limited to SIMD%d: %s",
-                                n, msg);
+                          n, msg);
    }
 }
 
@@ -8884,11 +8884,11 @@ fs_visitor::allocate_registers(bool allow_spilling)
       fail("Failure to register allocate.  Reduce number of "
            "live scalar values to avoid this.");
    } else if (spilled_any_registers) {
-      compiler->shader_perf_log(log_data,
+      brw_shader_perf_log(compiler, log_data,
-                                "%s shader triggered register spilling.  "
+                          "%s shader triggered register spilling.  "
-                                "Try reducing the number of live scalar "
+                          "Try reducing the number of live scalar "
-                                "values to improve performance.\n",
+                          "values to improve performance.\n",
-                                stage_name);
+                          stage_name);
    }
 
    /* This must come after all optimization and register allocation, since
@@ -9783,9 +9783,9 @@ brw_compile_fs(const struct brw_compiler *compiler,
                            debug_enabled);
       v16->import_uniforms(v8);
       if (!v16->run_fs(allow_spilling, params->use_rep_send)) {
-         compiler->shader_perf_log(params->log_data,
+         brw_shader_perf_log(compiler, params->log_data,
-                                   "SIMD16 shader failed to compile: %s",
+                             "SIMD16 shader failed to compile: %s",
-                                   v16->fail_msg);
+                             v16->fail_msg);
       } else {
          simd16_cfg = v16->cfg;
          prog_data->dispatch_grf_start_reg_16 = v16->payload.num_regs;
@@ -9811,14 +9811,15 @@ brw_compile_fs(const struct brw_compiler *compiler,
                            debug_enabled);
       v32->import_uniforms(v8);
       if (!v32->run_fs(allow_spilling, false)) {
-         compiler->shader_perf_log(params->log_data,
+         brw_shader_perf_log(compiler, params->log_data,
-                                   "SIMD32 shader failed to compile: %s",
+                             "SIMD32 shader failed to compile: %s",
-                                   v32->fail_msg);
+                             v32->fail_msg);
       } else {
          const performance &perf = v32->performance_analysis.require();
 
          if (!(INTEL_DEBUG & DEBUG_DO32) && throughput >= perf.throughput) {
-            compiler->shader_perf_log(params->log_data, "SIMD32 shader inefficient\n");
+            brw_shader_perf_log(compiler, params->log_data,
+                                "SIMD32 shader inefficient\n");
          } else {
             simd32_cfg = v32->cfg;
             prog_data->dispatch_grf_start_reg_32 = v32->payload.num_regs;
@@ -10174,9 +10175,9 @@ brw_compile_cs(const struct brw_compiler *compiler,
 
       const bool allow_spilling = generate_all || v == NULL;
       if (!v16->run_cs(allow_spilling)) {
-         compiler->shader_perf_log(params->log_data,
+         brw_shader_perf_log(compiler, params->log_data,
-                                   "SIMD16 shader failed to compile: %s",
+                             "SIMD16 shader failed to compile: %s",
-                                   v16->fail_msg);
+                             v16->fail_msg);
          if (!v) {
             assert(v8 == NULL);
             params->error_str = ralloc_asprintf(
@@ -10222,9 +10223,9 @@ brw_compile_cs(const struct brw_compiler *compiler,
 
       const bool allow_spilling = generate_all || v == NULL;
       if (!v32->run_cs(allow_spilling)) {
-         compiler->shader_perf_log(params->log_data,
+         brw_shader_perf_log(compiler, params->log_data,
-                                   "SIMD32 shader failed to compile: %s",
+                             "SIMD32 shader failed to compile: %s",
-                                   v32->fail_msg);
+                             v32->fail_msg);
          if (!v) {
             assert(v8 == NULL);
             assert(v16 == NULL);
@@ -10418,9 +10419,9 @@ compile_single_bs(const struct brw_compiler *compiler, void *log_data,
                            16, -1 /* shader time */, debug_enabled);
       const bool allow_spilling = (v == NULL);
       if (!v16->run_bs(allow_spilling)) {
-         compiler->shader_perf_log(log_data,
+         brw_shader_perf_log(compiler, log_data,
-                                   "SIMD16 shader failed to compile: %s",
+                             "SIMD16 shader failed to compile: %s",
-                                   v16->fail_msg);
+                             v16->fail_msg);
          if (v == NULL) {
             assert(v8 == NULL);
             if (error_str) {

src/intel/compiler/brw_vec4.cpp

@@ -2848,11 +2848,11 @@ vec4_visitor::run()
    bool allocated_without_spills = reg_allocate();
 
    if (!allocated_without_spills) {
-      compiler->shader_perf_log(log_data,
+      brw_shader_perf_log(compiler, log_data,
-                                "%s shader triggered register spilling.  "
+                          "%s shader triggered register spilling.  "
-                                "Try reducing the number of live vec4 values "
+                          "Try reducing the number of live vec4 values "
-                                "to improve performance.\n",
+                          "to improve performance.\n",
-                                stage_name);
+                          stage_name);
 
       while (!reg_allocate()) {
          if (failed)

src/intel/vulkan/anv_device.c

@@ -105,7 +105,7 @@ compiler_debug_log(void *data, UNUSED unsigned *id, const char *fmt, ...)
 }
 
 static void
-compiler_perf_log(void *data, const char *fmt, ...)
+compiler_perf_log(UNUSED void *data, UNUSED unsigned *id, const char *fmt, ...)
 {
    va_list args;
    va_start(args, fmt);

src/mesa/drivers/dri/i965/brw_program.c

@@ -964,8 +964,8 @@ brw_debug_recompile(struct brw_context *brw,
    const struct brw_compiler *compiler = brw->screen->compiler;
    enum brw_cache_id cache_id = brw_stage_cache_id(stage);
 
-   compiler->shader_perf_log(brw, "Recompiling %s shader for program %d\n",
+   brw_shader_perf_log(compiler, brw, "Recompiling %s shader for program %d\n",
-                             _mesa_shader_stage_to_string(stage), api_id);
+                       _mesa_shader_stage_to_string(stage), api_id);
 
    const void *old_key =
       brw_find_previous_compile(&brw->cache, cache_id, key->program_string_id);

src/mesa/drivers/dri/i965/brw_screen.c

@@ -2486,7 +2486,7 @@ shader_debug_log_mesa(void *data, unsigned *msg_id, const char *fmt, ...)
 }
 
 static void
-shader_perf_log_mesa(void *data, const char *fmt, ...)
+shader_perf_log_mesa(void *data, unsigned *msg_id, const char *fmt, ...)
 {
    struct brw_context *brw = (struct brw_context *)data;
 
@@ -2501,8 +2501,7 @@ shader_perf_log_mesa(void *data, const char *fmt, ...)
    }
 
    if (brw->perf_debug) {
-      GLuint msg_id = 0;
+      _mesa_gl_vdebugf(&brw->ctx, msg_id,
-      _mesa_gl_vdebugf(&brw->ctx, &msg_id,
                        MESA_DEBUG_SOURCE_SHADER_COMPILER,
                        MESA_DEBUG_TYPE_PERFORMANCE,
                        MESA_DEBUG_SEVERITY_MEDIUM, fmt, args);