Merge pull request #4467 from edolstra/error-formatting

Improve error formatting

7 files changed, 97 insertions, 181 deletions

diff --git a/src/libutil/error.cc b/src/libutil/error.cc
index 2a67a730a..0eea3455d 100644
--- a/src/libutil/error.cc
+++ b/src/libutil/error.cc
@@ -43,9 +43,9 @@ string showErrPos(const ErrPos & errPos)
 {
     if (errPos.line > 0) {
         if (errPos.column > 0) {
-            return fmt("(%1%:%2%)", errPos.line, errPos.column);
+            return fmt("%d:%d", errPos.line, errPos.column);
         } else {
-            return fmt("(%1%)", errPos.line);
+            return fmt("%d", errPos.line);
         }
     }
     else {
@@ -180,24 +180,20 @@ void printCodeLines(std::ostream & out,
     }
 }
 
-void printAtPos(const string & prefix, const ErrPos & pos, std::ostream & out)
+void printAtPos(const ErrPos & pos, std::ostream & out)
 {
-    if (pos)
-    {
+    if (pos) {
         switch (pos.origin) {
             case foFile: {
-                out << prefix << ANSI_BLUE << "at: " << ANSI_YELLOW << showErrPos(pos) <<
-                    ANSI_BLUE << " in file: " << ANSI_NORMAL << pos.file;
+                out << fmt(ANSI_BLUE "at " ANSI_YELLOW "%s:%s" ANSI_NORMAL ":", pos.file, showErrPos(pos));
                 break;
             }
             case foString: {
-                out << prefix << ANSI_BLUE << "at: " << ANSI_YELLOW << showErrPos(pos) <<
-                    ANSI_BLUE << " from string" << ANSI_NORMAL;
+                out << fmt(ANSI_BLUE "at " ANSI_YELLOW "«string»:%s" ANSI_NORMAL ":", showErrPos(pos));
                 break;
             }
             case foStdin: {
-                out << prefix << ANSI_BLUE << "at: " << ANSI_YELLOW << showErrPos(pos) <<
-                    ANSI_BLUE << " from stdin" << ANSI_NORMAL;
+                out << fmt(ANSI_BLUE "at " ANSI_YELLOW "«stdin»:%s" ANSI_NORMAL ":", showErrPos(pos));
                 break;
             }
             default:
@@ -206,168 +202,108 @@ void printAtPos(const string & prefix, const ErrPos & pos, std::ostream & out)
     }
 }
 
-std::ostream & showErrorInfo(std::ostream & out, const ErrorInfo & einfo, bool showTrace)
+static std::string indent(std::string_view indentFirst, std::string_view indentRest, std::string_view s)
 {
-    auto errwidth = std::max<size_t>(getWindowSize().second, 20);
-    string prefix = "";
+    std::string res;
+    bool first = true;
+
+    while (!s.empty()) {
+        auto end = s.find('\n');
+        if (!first) res += "\n";
+        res += chomp(std::string(first ? indentFirst : indentRest) + std::string(s.substr(0, end)));
+        first = false;
+        if (end == s.npos) break;
+        s = s.substr(end + 1);
+    }
+
+    return res;
+}
 
-    string levelString;
+std::ostream & showErrorInfo(std::ostream & out, const ErrorInfo & einfo, bool showTrace)
+{
+    std::string prefix;
     switch (einfo.level) {
         case Verbosity::lvlError: {
-            levelString = ANSI_RED;
-            levelString += "error:";
-            levelString += ANSI_NORMAL;
+            prefix = ANSI_RED "error";
+            break;
+        }
+        case Verbosity::lvlNotice: {
+            prefix = ANSI_RED "note";
             break;
         }
         case Verbosity::lvlWarn: {
-            levelString = ANSI_YELLOW;
-            levelString += "warning:";
-            levelString += ANSI_NORMAL;
+            prefix = ANSI_YELLOW "warning";
             break;
         }
         case Verbosity::lvlInfo: {
-            levelString = ANSI_GREEN;
-            levelString += "info:";
-            levelString += ANSI_NORMAL;
+            prefix = ANSI_GREEN "info";
             break;
         }
         case Verbosity::lvlTalkative: {
-            levelString = ANSI_GREEN;
-            levelString += "talk:";
-            levelString += ANSI_NORMAL;
+            prefix = ANSI_GREEN "talk";
             break;
         }
         case Verbosity::lvlChatty: {
-            levelString = ANSI_GREEN;
-            levelString += "chat:";
-            levelString += ANSI_NORMAL;
+            prefix = ANSI_GREEN "chat";
             break;
         }
         case Verbosity::lvlVomit: {
-            levelString = ANSI_GREEN;
-            levelString += "vomit:";
-            levelString += ANSI_NORMAL;
+            prefix = ANSI_GREEN "vomit";
             break;
         }
         case Verbosity::lvlDebug: {
-            levelString = ANSI_YELLOW;
-            levelString += "debug:";
-            levelString += ANSI_NORMAL;
-            break;
-        }
-        default: {
-            levelString = fmt("invalid error level: %1%", einfo.level);
+            prefix = ANSI_YELLOW "debug";
             break;
         }
+        default:
+            assert(false);
     }
 
-    auto ndl = prefix.length()
-        + filterANSIEscapes(levelString, true).length()
-        + 7
-        + einfo.name.length()
-        + einfo.programName.value_or("").length();
-    auto dashwidth = std::max<int>(errwidth - ndl, 3);
-
-    std::string dashes(dashwidth, '-');
-
-    // divider.
-    if (einfo.name != "")
-        out << fmt("%1%%2%" ANSI_BLUE " --- %3% %4% %5%" ANSI_NORMAL,
-            prefix,
-            levelString,
-            einfo.name,
-            dashes,
-            einfo.programName.value_or(""));
+    // FIXME: show the program name as part of the trace?
+    if (einfo.programName && einfo.programName != ErrorInfo::programName)
+        prefix += fmt(" [%s]:" ANSI_NORMAL " ", einfo.programName.value_or(""));
     else
-        out << fmt("%1%%2%" ANSI_BLUE " -----%3% %4%" ANSI_NORMAL,
-            prefix,
-            levelString,
-            dashes,
-            einfo.programName.value_or(""));
-
-    bool nl = false;  // intersperse newline between sections.
-    if (einfo.errPos.has_value() && (*einfo.errPos)) {
-        out << prefix << std::endl;
-        printAtPos(prefix, *einfo.errPos, out);
-        nl = true;
-    }
+        prefix += ":" ANSI_NORMAL " ";
 
-    // description
-    if (einfo.description != "") {
-        if (nl)
-            out << std::endl << prefix;
-        out << std::endl << prefix << einfo.description;
-        nl = true;
-    }
+    std::ostringstream oss;
+    oss << einfo.msg << "\n";
+
+    if (einfo.errPos.has_value() && *einfo.errPos) {
+        oss << "\n";
+        printAtPos(*einfo.errPos, oss);
 
-    if (einfo.errPos.has_value() && (*einfo.errPos)) {
         auto loc = getCodeLines(*einfo.errPos);
 
         // lines of code.
         if (loc.has_value()) {
-            if (nl)
-                out << std::endl << prefix;
-            printCodeLines(out, prefix, *einfo.errPos, *loc);
-            nl = true;
+            oss << "\n";
+            printCodeLines(oss, "", *einfo.errPos, *loc);
+            oss << "\n";
         }
     }
 
-    // hint
-    if (einfo.hint.has_value()) {
-        if (nl)
-            out << std::endl << prefix;
-        out << std::endl << prefix << *einfo.hint;
-        nl = true;
-    }
-
     // traces
-    if (showTrace && !einfo.traces.empty())
-    {
-        const string tracetitle(" show-trace ");
-
-        int fill = errwidth - tracetitle.length();
-        int lw = 0;
-        int rw = 0;
-        const int min_dashes = 3;
-        if (fill > min_dashes * 2) {
-            if (fill % 2 != 0) {
-                lw = fill / 2;
-                rw = lw + 1;
-            }
-            else
-            {
-                lw = rw = fill / 2;
-            }
-        }
-        else
-            lw = rw = min_dashes;
-
-        if (nl)
-            out << std::endl << prefix;
-
-        out << ANSI_BLUE << std::string(lw, '-') << tracetitle << std::string(rw, '-') << ANSI_NORMAL;
-
-        for (auto iter = einfo.traces.rbegin(); iter != einfo.traces.rend(); ++iter)
-        {
-            out << std::endl << prefix;
-            out << ANSI_BLUE << "trace: " << ANSI_NORMAL << iter->hint.str();
+    if (showTrace && !einfo.traces.empty()) {
+        for (auto iter = einfo.traces.rbegin(); iter != einfo.traces.rend(); ++iter) {
+            oss << "\n" << "… " << iter->hint.str() << "\n";
 
             if (iter->pos.has_value() && (*iter->pos)) {
                 auto pos = iter->pos.value();
-                out << std::endl << prefix;
-                printAtPos(prefix, pos, out);
+                oss << "\n";
+                printAtPos(pos, oss);
 
                 auto loc = getCodeLines(pos);
-                if (loc.has_value())
-                {
-                    out << std::endl << prefix;
-                    printCodeLines(out, prefix, pos, *loc);
-                    out << std::endl << prefix;
+                if (loc.has_value()) {
+                    oss << "\n";
+                    printCodeLines(oss, "", pos, *loc);
+                    oss << "\n";
                 }
             }
         }
     }
 
+    out << indent(prefix, std::string(filterANSIEscapes(prefix, true).size(), ' '), chomp(oss.str()));
+
     return out;
 }
 }
diff --git a/src/libutil/error.hh b/src/libutil/error.hh
index 1e0bde7ea..ff58d3e00 100644
--- a/src/libutil/error.hh
+++ b/src/libutil/error.hh
@@ -107,9 +107,8 @@ struct Trace {
 
 struct ErrorInfo {
     Verbosity level;
-    string name;
-    string description; // FIXME: remove? it seems to be barely used
-    std::optional<hintformat> hint;
+    string name; // FIXME: rename
+    hintformat msg;
     std::optional<ErrPos> errPos;
     std::list<Trace> traces;
 
@@ -133,23 +132,17 @@ public:
 
     template<typename... Args>
     BaseError(unsigned int status, const Args & ... args)
-        : err {.level = lvlError,
-            .hint = hintfmt(args...)
-            }
+        : err { .level = lvlError, .msg = hintfmt(args...) }
         , status(status)
     { }
 
     template<typename... Args>
     BaseError(const std::string & fs, const Args & ... args)
-        : err {.level = lvlError,
-            .hint = hintfmt(fs, args...)
-            }
+        : err { .level = lvlError, .msg = hintfmt(fs, args...) }
     { }
 
     BaseError(hintformat hint)
-        : err {.level = lvlError,
-            .hint = hint
-            }
+        : err { .level = lvlError, .msg = hint }
     { }
 
     BaseError(ErrorInfo && e)
@@ -206,7 +199,7 @@ public:
     {
         errNo = errno;
         auto hf = hintfmt(args...);
-        err.hint = hintfmt("%1%: %2%", normaltxt(hf.str()), strerror(errNo));
+        err.msg = hintfmt("%1%: %2%", normaltxt(hf.str()), strerror(errNo));
     }
 
     virtual const char* sname() const override { return "SysError"; }
diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc
index 6fd0dacef..d2e801175 100644
--- a/src/libutil/logging.cc
+++ b/src/libutil/logging.cc
@@ -184,7 +184,7 @@ struct JSONLogger : Logger {
         json["action"] = "msg";
         json["level"] = ei.level;
         json["msg"] = oss.str();
-        json["raw_msg"] = ei.hint->str();
+        json["raw_msg"] = ei.msg.str();
 
         if (ei.errPos.has_value() && (*ei.errPos)) {
             json["line"] = ei.errPos->line;
@@ -305,10 +305,7 @@ bool handleJSONLogMessage(const std::string & msg,
         }
 
     } catch (std::exception & e) {
-        logError({
-            .name = "JSON log message",
-            .hint = hintfmt("bad log message from builder: %s", e.what())
-        });
+        printError("bad JSON log message from builder: %s", e.what());
     }
 
     return true;
diff --git a/src/libutil/serialise.cc b/src/libutil/serialise.cc
index 87c1099a1..d1a16b6ba 100644
--- a/src/libutil/serialise.cc
+++ b/src/libutil/serialise.cc
@@ -52,10 +52,7 @@ size_t threshold = 256 * 1024 * 1024;
 
 static void warnLargeDump()
 {
-    logWarning({
-        .name = "Large path",
-        .description = "dumping very large path (> 256 MiB); this may run out of memory"
-    });
+    warn("dumping very large path (> 256 MiB); this may run out of memory");
 }
 
 
@@ -306,8 +303,7 @@ Sink & operator << (Sink & sink, const Error & ex)
         << "Error"
         << info.level
         << info.name
-        << info.description
-        << (info.hint ? info.hint->str() : "")
+        << info.msg.str()
         << 0 // FIXME: info.errPos
         << info.traces.size();
     for (auto & trace : info.traces) {
@@ -374,12 +370,14 @@ Error readError(Source & source)
 {
     auto type = readString(source);
     assert(type == "Error");
-    ErrorInfo info;
-    info.level = (Verbosity) readInt(source);
-    info.name = readString(source);
-    info.description = readString(source);
-    auto hint = readString(source);
-    if (hint != "") info.hint = hintformat(std::move(format("%s") % hint));
+    auto level = (Verbosity) readInt(source);
+    auto name = readString(source);
+    auto msg = readString(source);
+    ErrorInfo info {
+        .level = level,
+        .name = name,
+        .msg = hintformat(std::move(format("%s") % msg)),
+    };
     auto havePos = readNum<size_t>(source);
     assert(havePos == 0);
     auto nrTraces = readNum<size_t>(source);
diff --git a/src/libutil/tests/logging.cc b/src/libutil/tests/logging.cc
index 5b32c84a4..d990e5499 100644
--- a/src/libutil/tests/logging.cc
+++ b/src/libutil/tests/logging.cc
@@ -1,3 +1,5 @@
+#if 0
+
 #include "logging.hh"
 #include "nixexpr.hh"
 #include "util.hh"
@@ -41,8 +43,7 @@ namespace nix {
 
         makeJSONLogger(*logger)->logEI({
                 .name = "error name",
-                .description = "error without any code lines.",
-                .hint = hintfmt("this hint has %1% templated %2%!!",
+                .msg = hintfmt("this hint has %1% templated %2%!!",
                     "yellow",
                     "values"),
                 .errPos = Pos(foFile, problem_file, 02, 13)
@@ -62,7 +63,7 @@ namespace nix {
             throw TestError(e.info());
         } catch (Error &e) {
             ErrorInfo ei = e.info();
-            ei.hint = hintfmt("%s; subsequent error message.", normaltxt(e.info().hint ? e.info().hint->str() : ""));
+            ei.msg = hintfmt("%s; subsequent error message.", normaltxt(e.info().msg.str()));
 
             testing::internal::CaptureStderr();
             logger->logEI(ei);
@@ -95,7 +96,6 @@ namespace nix {
 
         logger->logEI({ .level = lvlInfo,
                         .name = "Info name",
-                        .description = "Info description",
             });
 
         auto str = testing::internal::GetCapturedStderr();
@@ -109,7 +109,6 @@ namespace nix {
 
         logger->logEI({ .level = lvlTalkative,
                         .name = "Talkative name",
-                        .description = "Talkative description",
             });
 
         auto str = testing::internal::GetCapturedStderr();
@@ -123,7 +122,6 @@ namespace nix {
 
         logger->logEI({ .level = lvlChatty,
                         .name = "Chatty name",
-                        .description = "Talkative description",
             });
 
         auto str = testing::internal::GetCapturedStderr();
@@ -137,7 +135,6 @@ namespace nix {
 
         logger->logEI({ .level = lvlDebug,
                         .name = "Debug name",
-                        .description = "Debug description",
             });
 
         auto str = testing::internal::GetCapturedStderr();
@@ -151,7 +148,6 @@ namespace nix {
 
         logger->logEI({ .level = lvlVomit,
                         .name = "Vomit name",
-                        .description = "Vomit description",
             });
 
         auto str = testing::internal::GetCapturedStderr();
@@ -167,7 +163,6 @@ namespace nix {
 
         logError({
                 .name = "name",
-                .description = "error description",
             });
 
         auto str = testing::internal::GetCapturedStderr();
@@ -182,8 +177,7 @@ namespace nix {
 
         logError({
                 .name = "error name",
-                .description = "error with code lines",
-                .hint = hintfmt("this hint has %1% templated %2%!!",
+                .msg = hintfmt("this hint has %1% templated %2%!!",
                     "yellow",
                     "values"),
                 .errPos = Pos(foString, problem_file, 02, 13),
@@ -200,8 +194,7 @@ namespace nix {
 
         logError({
                 .name = "error name",
-                .description = "error without any code lines.",
-                .hint = hintfmt("this hint has %1% templated %2%!!",
+                .msg = hintfmt("this hint has %1% templated %2%!!",
                     "yellow",
                     "values"),
                 .errPos = Pos(foFile, problem_file, 02, 13)
@@ -216,7 +209,7 @@ namespace nix {
 
         logError({
                 .name = "error name",
-                .hint = hintfmt("hint %1%", "only"),
+                .msg = hintfmt("hint %1%", "only"),
             });
 
         auto str = testing::internal::GetCapturedStderr();
@@ -233,8 +226,7 @@ namespace nix {
 
         logWarning({
                 .name = "name",
-                .description = "warning description",
-                .hint = hintfmt("there was a %1%", "warning"),
+                .msg = hintfmt("there was a %1%", "warning"),
             });
 
         auto str = testing::internal::GetCapturedStderr();
@@ -250,8 +242,7 @@ namespace nix {
 
         logWarning({
                 .name = "warning name",
-                .description = "warning description",
-                .hint = hintfmt("this hint has %1% templated %2%!!",
+                .msg = hintfmt("this hint has %1% templated %2%!!",
                     "yellow",
                     "values"),
                 .errPos = Pos(foStdin, problem_file, 2, 13),
@@ -274,8 +265,7 @@ namespace nix {
 
         auto e = AssertionError(ErrorInfo {
                 .name = "wat",
-                .description = "show-traces",
-                .hint = hintfmt("it has been %1% days since our last error", "zero"),
+                .msg = hintfmt("it has been %1% days since our last error", "zero"),
                 .errPos = Pos(foString, problem_file, 2, 13),
             });
 
@@ -301,8 +291,7 @@ namespace nix {
 
         auto e = AssertionError(ErrorInfo {
                 .name = "wat",
-                .description = "hide traces",
-                .hint = hintfmt("it has been %1% days since our last error", "zero"),
+                .msg = hintfmt("it has been %1% days since our last error", "zero"),
                 .errPos = Pos(foString, problem_file, 2, 13),
             });
 
@@ -377,3 +366,5 @@ namespace nix {
     }
 
 }
+
+#endif
diff --git a/src/libutil/util.cc b/src/libutil/util.cc
index e6b6d287d..89f7b58f8 100644
--- a/src/libutil/util.cc
+++ b/src/libutil/util.cc
@@ -1249,7 +1249,7 @@ template StringSet tokenizeString(std::string_view s, const string & separators)
 template vector<string> tokenizeString(std::string_view s, const string & separators);
 
 
-string chomp(const string & s)
+string chomp(std::string_view s)
 {
     size_t i = s.find_last_not_of(" \n\r\t");
     return i == string::npos ? "" : string(s, 0, i + 1);
diff --git a/src/libutil/util.hh b/src/libutil/util.hh
index ab0bd865a..ad49c65b3 100644
--- a/src/libutil/util.hh
+++ b/src/libutil/util.hh
@@ -373,8 +373,9 @@ template<class C> Strings quoteStrings(const C & c)
 }
 
 
-/* Remove trailing whitespace from a string. */
-string chomp(const string & s);
+/* Remove trailing whitespace from a string. FIXME: return
+   std::string_view. */
+string chomp(std::string_view s);
 
 
 /* Remove whitespace from the start and end of a string. */