GPUShader: Improve error/warning logging experience

Thanks to the new `ShaderCreateInfo` we now include source files without
any modification. This let us query which are the source files passed to the
`print_log` function. The log will now include a file with row and column
number which is interpreted as a link in most IDE.

DEBUG_CONTEXT_LINES will add more lines around the error lines for more
context. This is also useful if the error line is imprecise (because of
driver bugs) and the reported line is not sufficient to know the location
of the error.

The DEBUG_DEPENDENCIES option will display the list of included files in
the shader sources. Note that it will not print generated source.

This commit also fixes some issues with unhelpful logs, bogus row & column
numbers, other error format, and bug if row was 0.

3 files changed, 112 insertions, 6 deletions

diff --git a/source/blender/gpu/intern/gpu_shader_log.cc b/source/blender/gpu/intern/gpu_shader_log.cc
index 21973cf976a..d20e49d3085 100644
--- a/source/blender/gpu/intern/gpu_shader_log.cc
+++ b/source/blender/gpu/intern/gpu_shader_log.cc
@@ -26,7 +26,9 @@
 #include "BLI_dynstr.h"
 #include "BLI_string.h"
 #include "BLI_string_utils.h"
+#include "BLI_vector.hh"
 
+#include "gpu_shader_dependency_private.h"
 #include "gpu_shader_private.hh"
 
 #include "GPU_platform.h"
@@ -41,6 +43,14 @@ namespace blender::gpu {
 /** \name Debug functions
  * \{ */
 
+/* Number of lines before and after the error line to print for compilation errors. */
+#define DEBUG_CONTEXT_LINES 0
+/**
+ * Print dependencies sources list before the shader report.
+ * Useful to debug include order or missing dependencies.
+ */
+#define DEBUG_DEPENDENCIES 0
+
 void Shader::print_log(Span<const char *> sources,
                        char *log,
                        const char *stage,
@@ -61,6 +71,30 @@ void Shader::print_log(Span<const char *> sources,
 
   BLI_dynstr_appendf(dynstr, "\n");
 
+#if DEBUG_DEPENDENCIES
+  BLI_dynstr_appendf(
+      dynstr, "%s%sIncluded files (in order):%s\n", info_col, line_prefix, reset_col);
+#endif
+
+  Vector<int64_t> sources_end_line;
+  for (StringRefNull src : sources) {
+    int64_t cursor = 0, line_count = 0;
+    while ((cursor = src.find('\n', cursor) + 1)) {
+      line_count++;
+    }
+    if (sources_end_line.is_empty() == false) {
+      line_count += sources_end_line.last();
+    }
+    sources_end_line.append(line_count);
+#if DEBUG_DEPENDENCIES
+    StringRefNull filename = shader::gpu_shader_dependency_get_filename_from_source_string(src);
+    if (!filename.is_empty()) {
+      BLI_dynstr_appendf(
+          dynstr, "%s%s  %s%s\n", info_col, line_prefix, filename.c_str(), reset_col);
+    }
+#endif
+  }
+
   char *log_line = log, *line_end;
 
   LogCursor previous_location;
@@ -73,12 +107,32 @@ void Shader::print_log(Span<const char *> sources,
       continue;
     }
 
+    /* Silence not useful lines. */
+    StringRef logref = StringRefNull(log_line).substr(0, (size_t)line_end - (size_t)log_line);
+    if (logref.endswith(" shader failed to compile with the following errors:") ||
+        logref.endswith(" No code generated")) {
+      log_line += (size_t)line_end - (size_t)log_line;
+      continue;
+    }
+
     GPULogItem log_item;
     log_line = parser->parse_line(log_line, log_item);
 
+    /* Sanitize output. Really bad values can happen when the error line is buggy. */
+    if (log_item.cursor.source >= sources.size()) {
+      log_item.cursor.source = -1;
+    }
+    if (log_item.cursor.row >= sources_end_line.last()) {
+      log_item.cursor.source = -1;
+      log_item.cursor.row = -1;
+    }
+
     if (log_item.cursor.row == -1) {
       found_line_id = false;
     }
+    else if (log_item.source_base_row && log_item.cursor.source > 0) {
+      log_item.cursor.row += sources_end_line[log_item.cursor.source - 1];
+    }
 
     const char *src_line = sources_combined;
 
@@ -98,15 +152,14 @@ void Shader::print_log(Span<const char *> sources,
       /* error_line is 1 based in this case. */
       int src_line_index = 1;
       while ((src_line_end = strchr(src_line, '\n'))) {
-        if (src_line_index == log_item.cursor.row) {
+        if (src_line_index >= log_item.cursor.row) {
           found_line_id = true;
           break;
         }
-/* TODO(@fclem): Make this an option to display N lines before error. */
-#if 0 /* Uncomment to print shader file up to the error line to have more context. */
-        BLI_dynstr_appendf(dynstr, "%5d | ", src_line_index);
-        BLI_dynstr_nappend(dynstr, src_line, (src_line_end + 1) - src_line);
-#endif
+        if (src_line_index >= log_item.cursor.row - DEBUG_CONTEXT_LINES) {
+          BLI_dynstr_appendf(dynstr, "%5d | ", src_line_index);
+          BLI_dynstr_nappend(dynstr, src_line, (src_line_end + 1) - src_line);
+        }
         /* Continue to next line. */
         src_line = src_line_end + 1;
         src_line_index++;
@@ -129,10 +182,53 @@ void Shader::print_log(Span<const char *> sources,
           BLI_dynstr_appendf(dynstr, "^");
         }
         BLI_dynstr_appendf(dynstr, "\n");
+
+        /* Skip the error line. */
+        src_line = src_line_end + 1;
+        src_line_index++;
+        while ((src_line_end = strchr(src_line, '\n'))) {
+          if (src_line_index > log_item.cursor.row + DEBUG_CONTEXT_LINES) {
+            break;
+          }
+          BLI_dynstr_appendf(dynstr, "%5d | ", src_line_index);
+          BLI_dynstr_nappend(dynstr, src_line, (src_line_end + 1) - src_line);
+          /* Continue to next line. */
+          src_line = src_line_end + 1;
+          src_line_index++;
+        }
       }
     }
     BLI_dynstr_appendf(dynstr, line_prefix);
 
+    /* Search the correct source index. */
+    int row_in_file = log_item.cursor.row;
+    int source_index = log_item.cursor.source;
+    if (source_index <= 0) {
+      for (auto i : sources_end_line.index_range()) {
+        if (log_item.cursor.row <= sources_end_line[i]) {
+          source_index = i;
+          break;
+        }
+      }
+    }
+    if (source_index > 0) {
+      row_in_file -= sources_end_line[source_index - 1];
+    }
+    /* Print the filename the error line is comming from. */
+    if (source_index > 0) {
+      StringRefNull filename = shader::gpu_shader_dependency_get_filename_from_source_string(
+          sources[source_index]);
+      if (!filename.is_empty()) {
+        BLI_dynstr_appendf(dynstr,
+                           "%s%s:%d:%d: %s",
+                           info_col,
+                           filename.c_str(),
+                           row_in_file,
+                           log_item.cursor.column + 1,
+                           reset_col);
+      }
+    }
+
     if (log_item.severity == Severity::Error) {
       BLI_dynstr_appendf(dynstr, "%s%s%s: ", err_col, "Error", info_col);
     }
diff --git a/source/blender/gpu/intern/gpu_shader_private.hh b/source/blender/gpu/intern/gpu_shader_private.hh
index 3bfecdefba7..93c33811ee0 100644
--- a/source/blender/gpu/intern/gpu_shader_private.hh
+++ b/source/blender/gpu/intern/gpu_shader_private.hh
@@ -120,6 +120,7 @@ struct LogCursor {
 
 struct GPULogItem {
   LogCursor cursor;
+  bool source_base_row = false;
   Severity severity = Severity::Unknown;
 };
 
diff --git a/source/blender/gpu/opengl/gl_shader_log.cc b/source/blender/gpu/opengl/gl_shader_log.cc
index 174cc63ad81..0ee70b54f52 100644
--- a/source/blender/gpu/opengl/gl_shader_log.cc
+++ b/source/blender/gpu/opengl/gl_shader_log.cc
@@ -60,6 +60,15 @@ char *GLLogParser::parse_line(char *log_line, GPULogItem &log_item)
       log_item.cursor.row = log_item.cursor.column;
       log_item.cursor.column = -1;
     }
+    else if (GPU_type_matches(GPU_DEVICE_ATI, GPU_OS_UNIX, GPU_DRIVER_OFFICIAL) &&
+             /* WORKAROUND(@fclem): Both Mesa and amdgpu-pro are reported as official. */
+             StringRefNull(GPU_platform_version()).find(" Mesa ") == -1) {
+      /* source:row */
+      log_item.cursor.source = log_item.cursor.row;
+      log_item.cursor.row = log_item.cursor.column;
+      log_item.cursor.column = -1;
+      log_item.source_base_row = true;
+    }
     else {
       /* line:char */
     }