From 6ccfdb79c7779f9eedeea73a21df694551c9893e Mon Sep 17 00:00:00 2001
From: Maximilian Bosch <maximilian@mbosch.me>
Date: Tue, 21 Jul 2020 23:38:18 +0200
Subject: [PATCH] libutil/logging: extend `internal-json` logger to make it
 more machine-readable

The new error-format is pretty nice from a UX point-of-view, however
it's fairly hard to parse the output e.g. for editor plugins such as
vim-ale[1] that use `nix-instantiate --parse` to determine syntax errors in
Nix expression files.

This patch extends the `internal-json` logger by adding the fields
`line`, `column` and `file` to easily locate an error in a file and the
field `raw_msg` which contains the error-message itself without
code-lines and additional helpers.

An exemplary output may look like this:

```
[nix-shell]$ ./inst/bin/nix-instantiate ~/test.nix --log-format minimal
{"action":"msg","column":1,"file":"/home/ma27/test.nix","level":0,"line":4,"raw_msg":"syntax error, unexpected IF, expecting $end","msg":"<full error-msg with code-lines etc>"}
```

[1] https://github.com/dense-analysis/ale
---
 doc/manual/command-ref/opt-common.xml |  9 ++++++++-
 src/libutil/logging.cc                | 27 +++++++++++++++++++++++++++
 src/libutil/tests/logging.cc          | 18 ++++++++++++++++++
 3 files changed, 53 insertions(+), 1 deletion(-)

diff --git a/doc/manual/command-ref/opt-common.xml b/doc/manual/command-ref/opt-common.xml
index a68eef1d0..093bc2526 100644
--- a/doc/manual/command-ref/opt-common.xml
+++ b/doc/manual/command-ref/opt-common.xml
@@ -106,7 +106,14 @@
     </varlistentry>
 
     <varlistentry><term>internal-json</term>
-    <listitem><para>Outputs the logs in a structured manner. NOTE: the json schema is not guarantees to be stable between releases.</para></listitem>
+     <listitem>
+      <para>Outputs the logs in a structured manner.</para>
+      <warning>
+       <para>
+        While the schema itself is relatively stable, the format of the error-messages (namely of the <literal>msg</literal>-field) can change between several releases.
+       </para>
+      </warning>
+     </listitem>
     </varlistentry>
 
     <varlistentry><term>bar</term>
diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc
index 832aee783..cbbf64395 100644
--- a/src/libutil/logging.cc
+++ b/src/libutil/logging.cc
@@ -184,6 +184,33 @@ struct JSONLogger : Logger {
         json["action"] = "msg";
         json["level"] = ei.level;
         json["msg"] = oss.str();
+        json["raw_msg"] = ei.hint->str();
+
+        if (ei.errPos.has_value() && (*ei.errPos)) {
+            json["line"] = ei.errPos->line;
+            json["column"] = ei.errPos->column;
+            json["file"] = ei.errPos->file;
+        } else {
+            json["line"] = nullptr;
+            json["column"] = nullptr;
+            json["file"] = nullptr;
+        }
+
+        if (loggerSettings.showTrace.get() && !ei.traces.empty()) {
+            nlohmann::json traces = nlohmann::json::array();
+            for (auto iter = ei.traces.rbegin(); iter != ei.traces.rend(); ++iter) {
+                nlohmann::json stackFrame;
+                stackFrame["raw_msg"] = iter->hint.str();
+                if (iter->pos.has_value() && (*iter->pos)) {
+                    stackFrame["line"] = iter->pos->line;
+                    stackFrame["column"] = iter->pos->column;
+                    stackFrame["file"] = iter->pos->file;
+                }
+                traces.push_back(stackFrame);
+            }
+
+            json["trace"] = traces;
+        }
 
         write(json);
     }
diff --git a/src/libutil/tests/logging.cc b/src/libutil/tests/logging.cc
index ad588055f..7e53f17c6 100644
--- a/src/libutil/tests/logging.cc
+++ b/src/libutil/tests/logging.cc
@@ -34,6 +34,24 @@ namespace nix {
         }
     }
 
+    TEST(logEI, jsonOutput) {
+        SymbolTable testTable;
+        auto problem_file = testTable.create("random.nix");
+        testing::internal::CaptureStderr();
+
+        makeJSONLogger(*logger)->logEI({
+                .name = "error name",
+                .description = "error without any code lines.",
+                .hint = hintfmt("this hint has %1% templated %2%!!",
+                    "yellow",
+                    "values"),
+                .errPos = Pos(foFile, problem_file, 02, 13)
+            });
+
+        auto str = testing::internal::GetCapturedStderr();
+        ASSERT_STREQ(str.c_str(), "\x1B[31;1merror:\x1B[0m\x1B[34;1m --- SysError --- error-unit-test\x1B[0m\nopening file '\x1B[33;1mrandom.nix\x1B[0m': \x1B[33;1mNo such file or directory\x1B[0m\n@nix {\"action\":\"msg\",\"column\":13,\"file\":\"random.nix\",\"level\":0,\"line\":2,\"msg\":\"\\u001b[31;1merror:\\u001b[0m\\u001b[34;1m --- error name --- error-unit-test\\u001b[0m\\n\\u001b[34;1mat: \\u001b[33;1m(2:13)\\u001b[34;1m in file: \\u001b[0mrandom.nix\\n\\nerror without any code lines.\\n\\nthis hint has \\u001b[33;1myellow\\u001b[0m templated \\u001b[33;1mvalues\\u001b[0m!!\",\"raw_msg\":\"this hint has \\u001b[33;1myellow\\u001b[0m templated \\u001b[33;1mvalues\\u001b[0m!!\"}\n");
+    }
+
     TEST(logEI, appendingHintsToPreviousError) {
 
         MakeError(TestError, Error);