fix: Klipper/Moonraker upload errors show a raw Python traceback (#14841)

src/slic3r/Utils/PrintHost.cpp

@@ -6,6 +6,7 @@
 #include <boost/optional.hpp>
 #include <boost/log/trivial.hpp>
 #include <boost/filesystem.hpp>
+#include <nlohmann/json.hpp>
 
 #include <wx/string.h>
 #include <wx/app.h>
@@ -115,10 +116,67 @@ std::string PrintHost::get_print_host_webui(DynamicPrintConfig* config)
     return webui_url;
 }
 
+namespace {
+
+// Moonraker (Klipper's API server) reports a raised exception as { "error": { "code", "message", "traceback" } }
+// under every host type that connects to it, often with the cause only in the traceback. Returns the reason to show,
+// or empty for any other body.
+std::string moonraker_error_reason(const std::string &body)
+{
+    const auto root = nlohmann::json::parse(body, nullptr, false);
+    const auto err  = root.find("error");
+    if (err == root.end())
+        return {};
+    const auto message   = err->find("message");
+    const auto traceback = err->find("traceback");
+    if (message == err->end() || traceback == err->end() || !message->is_string() || !traceback->is_string())
+        return {};
+
+    const auto &msg = message->get_ref<const std::string &>();
+    const auto &tb  = traceback->get_ref<const std::string &>();
+    if (msg.empty())
+        return {};
+    const auto end = tb.find_last_not_of(" \t\r\n");
+    if (end == std::string::npos)
+        return msg;
+
+    // Chained exceptions each start a new traceback; the one that failed the request is the last.
+    const auto header = tb.rfind("Traceback (most recent call last):", end);
+
+    // Tornado renders a raised HTTPError as "HTTP <code>: <reason>[ (<detail>)]", and the detail may span lines.
+    const auto code = err->find("code");
+    if (code != err->end() && code->is_number_integer()) {
+        const std::string marker = "HTTP " + std::to_string(code->get<int>()) + ": ";
+        const auto        pos    = tb.rfind(marker, end);
+        if (pos != std::string::npos && (header == std::string::npos || pos > header) && pos + marker.size() <= end) {
+            const std::string reason = tb.substr(pos + marker.size(), end + 1 - pos - marker.size());
+            // An HTTPError whose detail equals its reason, like HTTPError(401, "Unauthorized"), renders the phrase twice.
+            return reason == msg + " (" + msg + ")" ? msg : reason;
+        }
+    }
+
+    // Any other exception's type and message are everything from the first unindented line after its frames.
+    auto begin = (header == std::string::npos) ? std::string::npos : tb.find('\n', header);
+    while (begin != std::string::npos && begin < end) {
+        ++begin;
+        if (tb[begin] != ' ' && tb[begin] != '\r' && tb[begin] != '\n')
+            break;
+        begin = tb.find('\n', begin);
+    }
+    if (begin == std::string::npos || begin > end) {
+        const auto nl = tb.rfind('\n', end);
+        begin         = (nl == std::string::npos) ? 0 : nl + 1;
+    }
+    return msg + " (" + tb.substr(begin, end + 1 - begin) + ")";
+}
+
+} // namespace
+
 wxString PrintHost::format_error(const std::string &body, const std::string &error, unsigned status) const
 {
     if (status != 0) {
-        auto wxbody = wxString::FromUTF8(body.data());
+        const std::string reason = moonraker_error_reason(body);
+        auto wxbody = wxString::FromUTF8(reason.empty() ? body : reason);
         return wxString::Format("HTTP %u: %s", status, wxbody);
     } else {
         if (error.find("curl:Timeout was reached") != std::string::npos) {

tests/slic3rutils/CMakeLists.txt

@@ -18,6 +18,7 @@ add_executable(${_TEST_NAME}_tests
     test_plugin_install.cpp
     test_plugin_lifecycle.cpp
     test_plugin_printer_agent.cpp
+    test_printhost.cpp
     test_slicing_pipeline_bindings.cpp
     test_slicing_pipeline_config.cpp
     test_plugin_sort.cpp

tests/slic3rutils/test_printhost.cpp

@@ -0,0 +1,213 @@
+#include <catch2/catch_all.hpp>
+
+#include <nlohmann/json.hpp>
+
+#include "slic3r/Utils/PrintHost.hpp"
+
+using namespace Slic3r;
+
+namespace {
+
+class TestPrintHost : public PrintHost
+{
+public:
+    using PrintHost::format_error;
+
+    const char* get_name() const override { return "Test"; }
+    bool test(wxString&) const override { return true; }
+    wxString get_test_ok_msg() const override { return {}; }
+    wxString get_test_failed_msg(wxString&) const override { return {}; }
+    bool upload(PrintHostUpload, ProgressFn, ErrorFn, InfoFn) const override { return true; }
+    bool has_auto_discovery() const override { return false; }
+    bool can_test() const override { return false; }
+    PrintHostPostUploadActions get_post_upload_actions() const override { return {}; }
+    std::string get_host() const override { return {}; }
+};
+
+std::string format_error(const std::string& body, const std::string& error, unsigned status)
+{
+    return TestPrintHost().format_error(body, error, status).ToStdString();
+}
+
+std::string envelope(int code, const std::string& message, const std::string& traceback)
+{
+    return nlohmann::json{{"error", {{"code", code}, {"message", message}, {"traceback", traceback}}}}.dump();
+}
+
+std::string moonraker_error(int code, const std::string& message, const std::string& detail = {})
+{
+    std::string line = "tornado.web.HTTPError: HTTP " + std::to_string(code) + ": " + message;
+    if (!detail.empty())
+        line += " (" + detail + ")";
+    return envelope(code, message, "Traceback (most recent call last):\n  ...\n" + line + "\n");
+}
+
+// A real Moonraker body for uploading a file that is being printed.
+constexpr const char* k_busy_file_403 =
+    R"JSON({"error": {"code": 403, "message": "Forbidden", "traceback": "Traceback (most recent call last):\n\n  File \"/home/lava/moonraker/moonraker/components/file_manager/file_manager.py\", line 1017, in _finish_gcode_upload\n    can_start = self._handle_operation_check(check_path)\n                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n\nmoonraker.utils.exceptions.ServerError: File currently in use\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n\n  File \"/home/lava/moonraker/moonraker/components/application.py\", line 1069, in post\n    raise tornado.web.HTTPError(\ntornado.web.HTTPError: HTTP 403: Forbidden (File is loaded, upload not permitted)\n"}})JSON";
+
+} // namespace
+
+TEST_CASE("A Klipper upload error shows its reason instead of a Python traceback", "[PrintHost][Regression]")
+{
+    const std::string msg = format_error(k_busy_file_403, "", 403);
+    INFO("actual: " << msg);
+
+    CHECK(msg == "HTTP 403: Forbidden (File is loaded, upload not permitted)");
+    CHECK_THAT(msg, !Catch::Matchers::ContainsSubstring("Traceback"));
+    CHECK_THAT(msg, !Catch::Matchers::ContainsSubstring("file_manager.py"));
+}
+
+TEST_CASE("The specific cause is recovered from a file endpoint's traceback", "[PrintHost]")
+{
+    SECTION("a plain detail")
+    {
+        const std::string body = moonraker_error(403, "Forbidden", "File is loaded, upload not permitted");
+        CHECK(format_error(body, "", 403) == "HTTP 403: Forbidden (File is loaded, upload not permitted)");
+    }
+
+    SECTION("a detail whose own parentheses nest (a filename)")
+    {
+        const std::string detail = "Directory does not exist (/home/pi/gcodes/plate (1).gcode)";
+        const std::string body   = moonraker_error(400, "Bad Request", detail);
+        CHECK(format_error(body, "", 400) == "HTTP 400: Bad Request (" + detail + ")");
+    }
+
+    SECTION("a detail that contains the reason phrase")
+    {
+        const std::string body = moonraker_error(403, "Forbidden", "Forbidden zone: access denied");
+        CHECK(format_error(body, "", 403) == "HTTP 403: Forbidden (Forbidden zone: access denied)");
+    }
+
+    SECTION("a detail that spans lines")
+    {
+        const std::string detail = "Move out of range\nX=250.000 Y=10.000";
+        const std::string body   = moonraker_error(400, "Bad Request", detail);
+        CHECK(format_error(body, "", 400) == "HTTP 400: Bad Request (" + detail + ")");
+    }
+
+    SECTION("a detail that only repeats the reason phrase is dropped")
+    {
+        const std::string body = moonraker_error(401, "Unauthorized", "Unauthorized");
+        CHECK(format_error(body, "", 401) == "HTTP 401: Unauthorized");
+    }
+}
+
+TEST_CASE("An unhandled exception shows its type and message", "[PrintHost]")
+{
+    const std::string frame = "Traceback (most recent call last):\n"
+                              "  File \"/home/pi/moonraker/moonraker/components/file_manager/file_manager.py\", line 1, in write\n"
+                              "    self._write(data)\n";
+
+    SECTION("a one-line message")
+    {
+        const std::string body = envelope(500, "Internal Server Error", frame + "OSError: [Errno 28] No space left on device\n");
+        CHECK(format_error(body, "", 500) == "HTTP 500: Internal Server Error (OSError: [Errno 28] No space left on device)");
+    }
+
+    SECTION("a message that spans lines")
+    {
+        const std::string body = envelope(500, "Internal Server Error", frame + "ServerError: Klippy request failed\n  see klippy.log\n");
+        CHECK(format_error(body, "", 500) == "HTTP 500: Internal Server Error (ServerError: Klippy request failed\n  see klippy.log)");
+    }
+
+    SECTION("raised while handling an HTTPError with the same code")
+    {
+        const std::string traceback = frame + "tornado.web.HTTPError: HTTP 500: Internal Server Error (Database locked)\n\n"
+                                              "During handling of the above exception, another exception occurred:\n\n" +
+                                      frame + "OSError: [Errno 5] Input/output error\n";
+        const std::string body      = envelope(500, "Internal Server Error", traceback);
+        CHECK(format_error(body, "", 500) == "HTTP 500: Internal Server Error (OSError: [Errno 5] Input/output error)");
+    }
+
+    SECTION("a traceback with no header")
+    {
+        const std::string body = envelope(500, "Internal Server Error", "OSError: [Errno 5] Input/output error");
+        CHECK(format_error(body, "", 500) == "HTTP 500: Internal Server Error (OSError: [Errno 5] Input/output error)");
+    }
+}
+
+TEST_CASE("A reason already complete in message is shown unchanged", "[PrintHost]")
+{
+    SECTION("message is the whole reason, no trailing detail")
+    {
+        const std::string body = moonraker_error(503, "Klippy is not ready");
+        CHECK(format_error(body, "", 503) == "HTTP 503: Klippy is not ready");
+    }
+
+    SECTION("a message that itself contains parentheses is not duplicated")
+    {
+        const std::string reason = "Requested blocks (0-5) are unavailable";
+        const std::string body   = moonraker_error(400, reason);
+        CHECK(format_error(body, "", 400) == "HTTP 400: " + reason);
+    }
+}
+
+TEST_CASE("A Moonraker error with no usable detail shows just the reason phrase", "[PrintHost]")
+{
+    struct Case
+    {
+        const char* name;
+        const char* body;
+        unsigned status;
+        const char* expected;
+    };
+
+    const auto c = GENERATE(
+        Case{"an empty traceback", R"JSON({"error": {"code": 500, "message": "Internal Server Error", "traceback": ""}})JSON", 500,
+             "HTTP 500: Internal Server Error"},
+        Case{"a traceback of only whitespace", R"JSON({"error": {"code": 500, "message": "Internal Server Error", "traceback": "\n \n"}})JSON",
+             500, "HTTP 500: Internal Server Error"});
+
+    DYNAMIC_SECTION(c.name) { CHECK(format_error(c.body, "", c.status) == c.expected); }
+}
+
+TEST_CASE("A percent sign in the reason is not a format specifier", "[PrintHost]")
+{
+    const std::string body = moonraker_error(507, "Insufficient Storage", "disk 100% full");
+    CHECK(format_error(body, "", 507) == "HTTP 507: Insufficient Storage (disk 100% full)");
+}
+
+TEST_CASE("Error bodies that are not a Moonraker envelope are left unchanged", "[PrintHost]")
+{
+    SECTION("OctoPrint's string-valued error member")
+    {
+        const std::string body = R"JSON({"error": "File not found"})JSON";
+        CHECK(format_error(body, "", 404) == "HTTP 404: " + body);
+    }
+
+    SECTION("PrusaLink's top-level message, not under error")
+    {
+        const std::string body = R"JSON({"title": "Conflict", "message": "Printer is printing"})JSON";
+        CHECK(format_error(body, "", 409) == "HTTP 409: " + body);
+    }
+
+    SECTION("a body that is not JSON")
+    {
+        const std::string html = "<html><head><title>502 Bad Gateway</title></head></html>";
+        CHECK(format_error(html, "", 502) == "HTTP 502: " + html);
+    }
+
+    SECTION("an error object with no traceback")
+    {
+        const std::string body = R"JSON({"error": {"code": 500, "message": "Internal Server Error"}})JSON";
+        CHECK(format_error(body, "", 500) == "HTTP 500: " + body);
+    }
+
+    SECTION("an error object whose traceback is null")
+    {
+        const std::string body = R"JSON({"error": {"code": 500, "message": "Internal Server Error", "traceback": null}})JSON";
+        CHECK(format_error(body, "", 500) == "HTTP 500: " + body);
+    }
+
+    SECTION("an envelope whose reason phrase is empty")
+    {
+        const std::string body = envelope(403, "", "Traceback (most recent call last):\nOSError: denied\n");
+        CHECK(format_error(body, "", 403) == "HTTP 403: " + body);
+    }
+
+    SECTION("a transport error with no HTTP status")
+    {
+        CHECK(format_error("", "curl:Could not connect", 0) == "curl:Could not connect");
+    }
+}