Metal: Improve shader logging

This adds some `#line` directive between the
source file injection so that the log parser knowns
which file the errors originated from.

This is then followed by a scan over the combined
source to find out the real row number.

This needed some changes in the `Shader::plint_log`
to skip lines to avoid outputing redundant information.

source/blender/gpu/intern/gpu_shader_log.cc

@@ -103,7 +103,12 @@ void Shader::print_log(Span<const char *> sources,
     }
 
     GPULogItem log_item;
-    log_line = parser->parse_line(log_line, log_item);
+    log_line = parser->parse_line(sources_combined, log_line, log_item);
+
+    /* Empty line, skip. */
+    if ((log_item.cursor.row == -1) && ELEM(log_line[0], '\n', '\0')) {
+      continue;
+    }
 
     /* Sanitize output. Really bad values can happen when the error line is buggy. */
     if (log_item.cursor.source >= sources.size()) {
@@ -204,7 +209,12 @@ void Shader::print_log(Span<const char *> sources,
       row_in_file -= sources_end_line[source_index - 1];
     }
     /* Print the filename the error line is coming from. */
-    if (source_index > 0) {
+    if (!log_item.cursor.file_name_and_error_line.is_empty()) {
+      char name_buf[128];
+      log_item.cursor.file_name_and_error_line.copy(name_buf);
+      BLI_dynstr_appendf(dynstr, "%s%s: %s", info_col, name_buf, reset_col);
+    }
+    else if (source_index > 0) {
       StringRefNull filename = shader::gpu_shader_dependency_get_filename_from_source_string(
           sources[source_index]);
       if (!filename.is_empty()) {

source/blender/gpu/intern/gpu_shader_private.hh

@@ -152,6 +152,7 @@ struct LogCursor {
   int source = -1;
   int row = -1;
   int column = -1;
+  StringRef file_name_and_error_line = {};
 };
 
 struct GPULogItem {
@@ -162,7 +163,9 @@ struct GPULogItem {
 
 class GPULogParser {
  public:
-  virtual const char *parse_line(const char *log_line, GPULogItem &log_item) = 0;
+  virtual const char *parse_line(const char *source_combined,
+                                 const char *log_line,
+                                 GPULogItem &log_item) = 0;
 
  protected:
   const char *skip_severity(const char *log_line,

source/blender/gpu/metal/mtl_shader.mm

@@ -25,6 +25,7 @@
 #include "GPU_platform.h"
 #include "GPU_vertex_format.h"
 
+#include "gpu_shader_dependency_private.h"
 #include "mtl_common.hh"
 #include "mtl_context.hh"
 #include "mtl_debug.hh"
@@ -206,9 +207,20 @@ void MTLShader::fragment_shader_from_glsl(MutableSpan<const char *> sources)
 
   /* Consolidate GLSL fragment sources. */
   std::stringstream ss;
-  for (int i = 0; i < sources.size(); i++) {
-    ss << sources[i] << std::endl;
+  int i;
+  for (i = 0; i < sources.size(); i++) {
+    /* Output preprocessor directive to improve shader log. */
+    StringRefNull name = shader::gpu_shader_dependency_get_filename_from_source_string(sources[i]);
+    if (name.is_empty()) {
+      ss << "#line 1 \"generated_code_" << i << "\"\n";
+    }
+    else {
+      ss << "#line 1 \"" << name << "\"\n";
+    }
+
+    ss << sources[i] << '\n';
   }
+  ss << "#line 1 \"msl_wrapper_code\"";
   shd_builder_->glsl_fragment_source_ = ss.str();
 }
 

source/blender/gpu/metal/mtl_shader_generator.mm

@@ -1061,6 +1061,8 @@ bool MTLShader::generate_msl_from_glsl(const shader::ShaderCreateInfo *info)
   /* Setup `stringstream` for populating generated MSL shader vertex/frag shaders. */
   std::stringstream ss_vertex;
   std::stringstream ss_fragment;
+  ss_vertex << "#line 1 \"msl_wrapper_code\"";
+  ss_fragment << "#line 1 \"msl_wrapper_code\"";
 
   if (bool(info->builtins_ & BuiltinBits::TEXTURE_ATOMIC) &&
       MTLBackend::get_capabilities().supports_texture_atomics)

source/blender/gpu/metal/mtl_shader_log.hh

@@ -8,11 +8,17 @@ namespace blender::gpu {
 
 class MTLLogParser : public GPULogParser {
  public:
-  const char *parse_line(const char *log_line, GPULogItem &log_item) override;
+  const char *parse_line(const char *source_combined,
+                         const char *log_line,
+                         GPULogItem &log_item) override;
 
  protected:
+  bool wrapper_error_ = false;
+  bool parsed_error_ = false;
+
   const char *skip_name(const char *log_line);
   const char *skip_severity_keyword(const char *log_line, GPULogItem &log_item);
+  const char *skip_line(const char *cursor) const;
 };
 
 }  // namespace blender::gpu

source/blender/gpu/metal/mtl_shader_log.mm

@@ -14,20 +14,73 @@
 
 namespace blender::gpu {
 
-const char *MTLLogParser::parse_line(const char *log_line, GPULogItem &log_item)
+const char *MTLLogParser::parse_line(const char *source_combined,
+                                     const char *log_line,
+                                     GPULogItem &log_item)
 {
+  const char *name_start = log_line;
   log_line = skip_name(log_line);
+  const char *name_end = log_line;
   log_line = skip_separators(log_line, ":");
 
   /* Parse error line & char numbers. */
   if (at_number(log_line)) {
+    /* Reset skip line if two errors follow. */
+    parsed_error_ = false;
+    wrapper_error_ = false;
+
     const char *error_line_number_end;
 
     log_item.cursor.row = parse_number(log_line, &error_line_number_end);
     log_line = error_line_number_end;
     log_line = skip_separators(log_line, ": ");
     log_item.cursor.column = parse_number(log_line, &error_line_number_end);
+    /* For some reason the column is off by one. */
+    log_item.cursor.column--;
     log_line = error_line_number_end;
+    /* Simply copy the start of the error line since it is already in the format we want. */
+    log_item.cursor.file_name_and_error_line = StringRef(name_start, error_line_number_end);
+
+    StringRef source_name(name_start, name_end);
+
+    if (source_name == "msl_wrapper_code") {
+      /* In this case the issue is in the wrapper. We cannot access it.
+       * So we still display the internal error lines for some more infos. */
+      log_item.cursor.row = -1;
+      wrapper_error_ = true;
+    }
+    else if (!source_name.is_empty()) {
+      std::string needle = std::string("#line 1 \"") + source_name + "\"";
+
+      StringRefNull src(source_combined);
+      int64_t file_start = src.find(needle);
+      if (file_start == -1) {
+        /* Can be generated code or wrapper code outside of the main sources.
+         * But should be already catched by the above case. */
+        log_item.cursor.row = -1;
+        wrapper_error_ = true;
+      }
+      else {
+        StringRef previous_sources(source_combined, file_start);
+        for (const char c : previous_sources) {
+          if (c == '\n') {
+            log_item.cursor.row++;
+          }
+        }
+        /* Count the needle end of line too. */
+        log_item.cursor.row++;
+        parsed_error_ = true;
+      }
+    }
+  }
+  else if (parsed_error_) {
+    /* Skip the redundant lines that we be outputed above the error. */
+    return skip_line(log_line);
+  }
+  else if (wrapper_error_) {
+    /* Display full lines of error in case of wrapper (non parsed) errors.
+     * Avoids weirdly aligned '^' and underlined suggestions. */
+    return name_start;
   }
   log_line = skip_separators(log_line, ": ");
 
@@ -48,4 +101,12 @@ const char *MTLLogParser::skip_severity_keyword(const char *log_line, GPULogItem
   return skip_severity(log_line, log_item, "error", "warning", "note");
 }
 
+const char *MTLLogParser::skip_line(const char *cursor) const
+{
+  while (!ELEM(cursor[0], '\n', '\0')) {
+    cursor++;
+  }
+  return cursor;
+}
+
 }  // namespace blender::gpu

source/blender/gpu/opengl/gl_shader.hh

@@ -106,7 +106,9 @@ class GLShader : public Shader {
 
 class GLLogParser : public GPULogParser {
  public:
-  const char *parse_line(const char *log_line, GPULogItem &log_item) override;
+  const char *parse_line(const char *source_combined,
+                         const char *log_line,
+                         GPULogItem &log_item) override;
 
  protected:
   const char *skip_severity_prefix(const char *log_line, GPULogItem &log_item);

source/blender/gpu/opengl/gl_shader_log.cc

@@ -12,7 +12,9 @@
 
 namespace blender::gpu {
 
-const char *GLLogParser::parse_line(const char *log_line, GPULogItem &log_item)
+const char *GLLogParser::parse_line(const char * /*source_combined*/,
+                                    const char *log_line,
+                                    GPULogItem &log_item)
 {
   /* Skip ERROR: or WARNING:. */
   log_line = skip_severity_prefix(log_line, log_item);

source/blender/gpu/vulkan/vk_shader_log.cc

@@ -12,7 +12,9 @@
 
 namespace blender::gpu {
 
-const char *VKLogParser::parse_line(const char *log_line, GPULogItem &log_item)
+const char *VKLogParser::parse_line(const char * /*source_combined*/,
+                                    const char *log_line,
+                                    GPULogItem &log_item)
 {
   log_line = skip_name(log_line);
   log_line = skip_separators(log_line, ":");

source/blender/gpu/vulkan/vk_shader_log.hh

@@ -8,7 +8,9 @@ namespace blender::gpu {
 
 class VKLogParser : public GPULogParser {
  public:
-  const char *parse_line(const char *log_line, GPULogItem &log_item) override;
+  const char *parse_line(const char *source_combined,
+                         const char *log_line,
+                         GPULogItem &log_item) override;
 
  protected:
   const char *skip_name(const char *log_line);