i965: make shader_time output a CSV report at the end

2 files changed, 28 insertions, 31 deletions

diff --git a/src/mesa/drivers/dri/i965/brw_context.h b/src/mesa/drivers/dri/i965/brw_context.h
index df7b6ebb1d..a16037fb84 100644
--- a/src/mesa/drivers/dri/i965/brw_context.h
+++ b/src/mesa/drivers/dri/i965/brw_context.h
@@ -1260,6 +1260,7 @@ struct brw_context
    } l3;
 
    struct {
+      FILE *f;
       struct brw_bo *bo;
       const char **names;
       int *ids;
diff --git a/src/mesa/drivers/dri/i965/brw_shader_time.c b/src/mesa/drivers/dri/i965/brw_shader_time.c
index cdc8472dba..97ca25ecf3 100644
--- a/src/mesa/drivers/dri/i965/brw_shader_time.c
+++ b/src/mesa/drivers/dri/i965/brw_shader_time.c
@@ -38,6 +38,15 @@ void
 brw_init_shader_time(struct brw_context *brw)
 {
    const int max_entries = 2048;
+
+   static int index = 0;
+
+   char *name = getenv("SHADER_TIME_OUTPUT");
+   if (!name)
+      name = "shader-time";
+   asprintf(&name, "%s-%d.csv", name, index++);
+
+   brw->shader_time.f = fopen(name, "w");
    brw->shader_time.bo =
       brw_bo_alloc(brw->bufmgr, "shader time",
                    max_entries * BRW_SHADER_TIME_STRIDE * 3, 4096);
@@ -48,6 +57,7 @@ brw_init_shader_time(struct brw_context *brw)
    brw->shader_time.cumulative = rzalloc_array(brw, struct shader_times,
                                                max_entries);
    brw->shader_time.max_entries = max_entries;
+   free(name);
 }
 
 static int
@@ -66,20 +76,10 @@ compare_time(const void *a, const void *b)
 }
 
 static void
-print_shader_time_line(const char *stage, const char *name,
-                       int shader_num, uint64_t time, uint64_t total)
+print_shader_time_line(FILE *f, const char *stage, const char *name,
+                       int shader_num, uint64_t time)
 {
-   fprintf(stderr, "%-6s%-18s", stage, name);
-
-   if (shader_num != 0)
-      fprintf(stderr, "%4d: ", shader_num);
-   else
-      fprintf(stderr, "    : ");
-
-   fprintf(stderr, "%16lld (%7.2f Gcycles)      %4.1f%%\n",
-           (long long)time,
-           (double)time / 1000000000.0,
-           (double)time / total * 100.0);
+   fprintf(f, "%s,%s,%d,%lld\n", stage, name, shader_num, (long long) time);
 }
 
 static void
@@ -88,6 +88,7 @@ brw_report_shader_time(struct brw_context *brw)
    if (!brw->shader_time.bo || !brw->shader_time.num_entries)
       return;
 
+   FILE *f = brw->shader_time.f;
    uint64_t scaled[brw->shader_time.num_entries];
    uint64_t *sorted[brw->shader_time.num_entries];
    uint64_t total_by_type[ST_CS + 1];
@@ -151,8 +152,8 @@ brw_report_shader_time(struct brw_context *brw)
 
    qsort(sorted, brw->shader_time.num_entries, sizeof(sorted[0]), compare_time);
 
-   fprintf(stderr, "\n");
-   fprintf(stderr, "type          ID                  cycles spent                   %% of total\n");
+
+   fprintf(f, "stage,name,id,cycles\n");
    for (int s = 0; s < brw->shader_time.num_entries; s++) {
       const char *stage;
       /* Work back from the sorted pointers times to a time to print. */
@@ -191,18 +192,17 @@ brw_report_shader_time(struct brw_context *brw)
          break;
       }
 
-      print_shader_time_line(stage, shader_name, shader_num,
-                             scaled[i], total);
+      print_shader_time_line(f, stage, shader_name, shader_num,
+                             scaled[i]);
    }
 
-   fprintf(stderr, "\n");
-   print_shader_time_line("total", "vs", 0, total_by_type[ST_VS], total);
-   print_shader_time_line("total", "tcs", 0, total_by_type[ST_TCS], total);
-   print_shader_time_line("total", "tes", 0, total_by_type[ST_TES], total);
-   print_shader_time_line("total", "gs", 0, total_by_type[ST_GS], total);
-   print_shader_time_line("total", "fs8", 0, total_by_type[ST_FS8], total);
-   print_shader_time_line("total", "fs16", 0, total_by_type[ST_FS16], total);
-   print_shader_time_line("total", "cs", 0, total_by_type[ST_CS], total);
+   print_shader_time_line(f, "total", "vs", 0, total_by_type[ST_VS]);
+   print_shader_time_line(f, "total", "tcs", 0, total_by_type[ST_TCS]);
+   print_shader_time_line(f, "total", "tes", 0, total_by_type[ST_TES]);
+   print_shader_time_line(f, "total", "gs", 0, total_by_type[ST_GS]);
+   print_shader_time_line(f, "total", "fs8", 0, total_by_type[ST_FS8]);
+   print_shader_time_line(f, "total", "fs16", 0, total_by_type[ST_FS16]);
+   print_shader_time_line(f, "total", "cs", 0, total_by_type[ST_CS]);
 }
 
 static void
@@ -236,12 +236,6 @@ void
 brw_collect_and_report_shader_time(struct brw_context *brw)
 {
    brw_collect_shader_time(brw);
-
-   if (brw->shader_time.report_time == 0 ||
-       get_time() - brw->shader_time.report_time >= 1.0) {
-      brw_report_shader_time(brw);
-      brw->shader_time.report_time = get_time();
-   }
 }
 
 /**
@@ -278,6 +272,8 @@ brw_get_shader_time_index(struct brw_context *brw, struct gl_program *prog,
 void
 brw_destroy_shader_time(struct brw_context *brw)
 {
+   brw_report_shader_time(brw);
+   fclose(brw->shader_time.f);
    brw_bo_unreference(brw->shader_time.bo);
    brw->shader_time.bo = NULL;
 }