fix: a called workflow's failure now reaches its own error workflow

A sub-workflow was started with no callback at all:

    execute(sub_workflow, "workflow", sub_trigger, nullptr);

The comment gave the reason - forwarding its node events would light up nodes
the caller's canvas does not have. That does not happen: an event is broadcast
on a channel keyed by execution id, and the child has its own. Only the
workflowId stamp would have been wrong.

What it cost was everything the child never reported. Its error workflow never
ran, because that is driven by execution.failed reaching the webserver. Its
runs never updated the executions list while they happened. Its own canvas
showed nothing while it worked. A sub-workflow that failed was silent by
construction, and this is visible in the record: six failures of one workflow
with triggerType "workflow" and no handler run between them, against two
manual failures of the same workflow where the handler ran seconds later.

The child now gets a callback that stamps its own workflow id, and the runner's
wrapper fills in a missing id instead of overwriting one already set -
otherwise a called workflow's run is attributed to its caller.

Two silent returns in runErrorWorkflow now say why they gave up. "No error
workflow is configured" and "that workflow could not be read" both returned
without a word, so a handler that never ran looked exactly like one that had
nothing to do, and the only way to tell was to read the function.

Also: the loop body logged each node's entire input at INFO. A loop carrying an
image wrote the whole base64 payload to the journal on every node of every
iteration - one execution came to 170KB of embedded JPEG, which is slow to
write, expensive to keep, and unreadable exactly when something has gone wrong.
It now goes through the truncation the stored records already use, capped.

The sd.cpp test fixtures move to https://mulan:8077, following that server.
They were the three suite failures: it switched to TLS on the same port, and an
HTTPS server closes a plaintext request without answering.

Node suite: 92 passed, 0 failed.

src/runner/runner_service.cpp

@@ -144,7 +144,17 @@ grpc::Status RunnerServiceImpl::ExecuteWorkflow(grpc::ServerContext* context,
     if (event_callback_) {
         callback = [this, &workflow](const std::string& event_type, const nlohmann::json& data) {
             nlohmann::json event_data = data;
-            event_data["workflowId"] = workflow.id;
+            // Filled in, not overwritten. Most of the engine's per-node events
+            // do not carry a workflow id and this is where they get one - but a
+            // sub-workflow's events arrive already stamped with the workflow
+            // that actually produced them, and overwriting that with the
+            // caller's would attribute a called workflow's run to its caller.
+            const bool already_attributed = event_data.contains("workflowId") &&
+                                            event_data["workflowId"].is_string() &&
+                                            !event_data["workflowId"].get<std::string>().empty();
+            if (!already_attributed) {
+                event_data["workflowId"] = workflow.id;
+            }
             event_callback_(event_type, event_data);
         };
     }

src/runner/workflow_engine.cpp

@@ -925,7 +925,7 @@ Result<ExecutionResult> WorkflowEngine::execute(const Workflow& workflow,
                 node_result = *cached;
 
                 marker_outcome = applyNodeMarkers(node_result, node_id, node_id, result,
-                                                  nlohmann::json::object(), {}, -1);
+                                                  nlohmann::json::object(), {}, -1, callback);
 
                 if (callback) {
                     callback("node.completed", {
@@ -983,7 +983,7 @@ Result<ExecutionResult> WorkflowEngine::execute(const Workflow& workflow,
                 }
 
                 marker_outcome = applyNodeMarkers(node_result, node_id, node_id, result,
-                                                  overlay, overlay_ignored, -1);
+                                                  overlay, overlay_ignored, -1, callback);
 
                 if (callback) {
                     nlohmann::json event_data = {
@@ -2220,7 +2220,8 @@ WorkflowEngine::MarkerOutcome WorkflowEngine::applyNodeMarkers(
     ExecutionResult& result,
     const nlohmann::json& overlay,
     const std::vector<std::string>& overlay_ignored,
-    int iteration) {
+    int iteration,
+    const ExecutionCallback& callback) {
 
     const bool in_loop = iteration >= 0;
     const std::string where = in_loop
@@ -2238,7 +2239,7 @@ WorkflowEngine::MarkerOutcome WorkflowEngine::applyNodeMarkers(
     // has no way to reach the engine, and this is the point where the result
     // can still become its output.
     if (node_result.output.contains("_callWorkflow")) {
-        runSubWorkflow(node_result, result.call_depth, result.execution_id);
+        runSubWorkflow(node_result, result.call_depth, result.execution_id, callback);
     }
 
     // A pause cannot work inside a loop: there is no way to resume one item of
@@ -2397,7 +2398,8 @@ WorkflowEngine::MarkerOutcome WorkflowEngine::applyNodeMarkers(
 }
 
 bool WorkflowEngine::runSubWorkflow(NodeExecutionResult& node_result, int call_depth,
-                                    const std::string& parent_execution_id) {
+                                    const std::string& parent_execution_id,
+                                    const ExecutionCallback& parent_callback) {
     const auto call = node_result.output["_callWorkflow"];
     const std::string workflow_id = call.value("workflowId", "");
     node_result.output.erase("_callWorkflow");
@@ -2460,9 +2462,22 @@ bool WorkflowEngine::runSubWorkflow(NodeExecutionResult& node_result, int call_d
     LOG_INFO("Execution {} calls workflow {} at depth {}", parent_execution_id, workflow_id,
              call_depth + 1);
 
-    // No callback: the sub-workflow reports its own progress against its own
-    // execution, and forwarding its node events to the parent's subscribers
-    // would make the parent's canvas light up nodes it does not have.
+    // The sub-workflow reports against ITS OWN execution and workflow, not the
+    // caller's.
+    //
+    // It used to be given no callback at all, on the reasoning that its node
+    // events would light up nodes the parent's canvas does not have. They would
+    // not: an event is broadcast on a channel keyed by execution id, and the
+    // child has its own. What the old arrangement actually cost was everything
+    // the child never reported - its error workflow never ran, because that is
+    // driven by execution.failed reaching the webserver; its runs never
+    // appeared live in the executions list; and its own canvas showed nothing
+    // while it worked. A sub-workflow that failed was silent by construction.
+    //
+    // The one thing that does have to be corrected is attribution: the runner's
+    // own wrapper stamps the workflow id it was built with, which is the
+    // caller's. This re-stamps the child's before handing the event on, and the
+    // wrapper now leaves an id that is already set alone.
     // The id is generated inside execute(), so a caller cannot know it in
     // advance. It is handed in on the trigger data instead, and recorded
     // against the caller as soon as it is known - which is what lets a cancel
@@ -2474,7 +2489,18 @@ bool WorkflowEngine::runSubWorkflow(NodeExecutionResult& node_result, int call_d
         child_executions_[parent_execution_id].insert(child_execution_id);
     }
 
-    auto outcome = execute(sub_workflow, "workflow", sub_trigger, nullptr);
+    ExecutionCallback child_callback;
+    if (parent_callback) {
+        const std::string child_workflow_id = sub_workflow.id;
+        child_callback = [parent_callback, child_workflow_id](const std::string& event_type,
+                                                              const nlohmann::json& data) {
+            nlohmann::json event_data = data;
+            event_data["workflowId"] = child_workflow_id;
+            parent_callback(event_type, event_data);
+        };
+    }
+
+    auto outcome = execute(sub_workflow, "workflow", sub_trigger, child_callback);
     if (outcome.failed()) {
         node_result.status = NodeStatus::Failed;
         node_result.error = "Call Workflow: " + outcome.error().message();
@@ -3381,7 +3407,7 @@ bool WorkflowEngine::executeLoopBody(
                     const MarkerOutcome cached_outcome = applyNodeMarkers(
                         cached_result, body_node_id,
                         key_prefix + body_node_id + "_iter_" + std::to_string(i), result,
-                        nlohmann::json::object(), {}, static_cast<int>(i));
+                        nlohmann::json::object(), {}, static_cast<int>(i), callback);
 
                     iteration_results[body_node_id] = cached_result;
 
@@ -3430,7 +3456,22 @@ bool WorkflowEngine::executeLoopBody(
             }
 
             // Execute the body node
-            LOG_INFO("Executing body node {} with input: {}", body_node_id, node_input.dump());
+            // Truncated twice over: truncateLargeValues replaces a long string
+            // with a note of its size, and the whole line is then capped.
+            //
+            // This used to dump the input whole. A loop body carrying an image
+            // wrote the entire base64 payload to the journal on every node of
+            // every iteration - one execution ran to 170KB of embedded JPEG,
+            // which is slow to write, expensive to keep, and makes the log
+            // unreadable exactly when something has gone wrong and you need it.
+            {
+                std::string shown = truncateLargeValues(node_input).dump();
+                if (shown.size() > 400) {
+                    shown = shown.substr(0, 400) + "... (" + std::to_string(shown.size()) +
+                            " bytes)";
+                }
+                LOG_INFO("Executing body node {} with input: {}", body_node_id, shown);
+            }
 
             // Send running event before execution
             if (callback) {
@@ -3556,7 +3597,7 @@ bool WorkflowEngine::executeLoopBody(
 
             const MarkerOutcome body_outcome = applyNodeMarkers(
                 body_result, body_node_id, result_key, result,
-                body_overlay, body_overlay_ignored, static_cast<int>(i));
+                body_overlay, body_overlay_ignored, static_cast<int>(i), callback);
 
             if (inner_loop_left_early) {
                 iteration_failed = true;

src/runner/workflow_engine.hpp

@@ -361,7 +361,8 @@ private:
     // Run another workflow as a step and put its result on the calling node.
     // Returns false and fills node_result.error when the call cannot be made.
     bool runSubWorkflow(NodeExecutionResult& node_result, int call_depth,
-                        const std::string& parent_execution_id);
+                        const std::string& parent_execution_id,
+                        const ExecutionCallback& parent_callback = nullptr);
 
     nlohmann::json collectConfigOverlay(
         const std::string& node_id,
@@ -474,7 +475,10 @@ private:
                                    ExecutionResult& result,
                                    const nlohmann::json& overlay,
                                    const std::vector<std::string>& overlay_ignored,
-                                   int iteration);
+                                   int iteration,
+                                   // Carried only so a Call Workflow marker can hand it to the
+                                   // run it starts. See runSubWorkflow.
+                                   const ExecutionCallback& callback = nullptr);
 
     // key_prefix disambiguates result_key across nested loops: a loop node
     // used inside another loop's body runs once per outer iteration, and

src/webserver/webserver_service.cpp

@@ -803,15 +803,26 @@ void WebServerService::runErrorWorkflow(const std::string& failed_workflow_id,
 
     auto failed = storage_->get("workflows", failed_workflow_id);
     if (failed.failed()) {
+        // Said out loud. This used to return in silence, so a workflow whose
+        // error handler never ran looked identical to one that had none - and
+        // the only way to tell them apart was to read this function.
+        LOG_WARN("Execution {} of workflow {} failed, but that workflow could not be read "
+                 "({}), so no error workflow was run",
+                 failed_execution_id, failed_workflow_id, failed.error().message());
         return;
     }
 
     const auto settings = failed.value().value("settings", nlohmann::json::object());
     const std::string handler_id = settings.value("errorWorkflowId", std::string());
     if (handler_id.empty()) {
+        LOG_DEBUG("Execution {} of workflow {} failed; no error workflow is configured",
+                  failed_execution_id, failed_workflow_id);
         return;
     }
 
+    LOG_INFO("Execution {} of workflow {} failed; running its error workflow {}",
+             failed_execution_id, failed_workflow_id, handler_id);
+
     // A handler that fails must not summon itself, which would run forever.
     if (handler_id == failed_workflow_id) {
         LOG_WARN("Workflow {} names itself as its error workflow; not running it",

tests/nodes/sdcpp-health.json

@@ -3,7 +3,7 @@
   "nodes": [
     {"id": "n1", "name": "Trigger", "type": "click-trigger", "position": {"x": 0, "y": 0}, "config": {}},
     {"id": "up", "name": "Reachable", "type": "sdcpp-health", "position": {"x": 0, "y": 100},
-     "config": {"serverUrl": "http://mulan:8077"}},
+     "config": {"serverUrl": "https://mulan:8077"}},
     {"id": "down", "name": "Unreachable", "type": "sdcpp-health", "position": {"x": 0, "y": 200},
      "config": {"serverUrl": "http://localhost:9", "timeout": 3000}}
   ],

tests/nodes/sdcpp-load-options-mismatch.json

@@ -1,7 +1,7 @@
 {
  "name": "diag-load-options-mismatch",
  "requires": {
-  "http": "http://mulan:8077/health",
+  "http": "https://mulan:8077/health",
   "expect": {
    "model_loaded": true
   }
@@ -26,7 +26,7 @@
     "y": 100
    },
    "config": {
-    "serverUrl": "http://mulan:8077"
+    "serverUrl": "https://mulan:8077"
    }
   },
   {
@@ -38,7 +38,7 @@
     "y": 220
    },
    "config": {
-    "serverUrl": "http://mulan:8077",
+    "serverUrl": "https://mulan:8077",
     "credentialId": "cred_62748b40-e9d1-4659-b175-6dbc691cc0b1",
     "modelName": "{{$node[\"Health\"].modelName}}",
     "streamLayers": false,

tests/nodes/sdcpp-model-load-assert.json

@@ -3,7 +3,7 @@
   "nodes": [
     {"id": "n1", "name": "Trigger", "type": "click-trigger", "position": {"x": 0, "y": 0}, "config": {}},
     {"id": "load", "name": "Load", "type": "sdcpp-model-load", "position": {"x": 0, "y": 120},
-     "config": {"serverUrl": "http://mulan:8077",
+     "config": {"serverUrl": "https://mulan:8077",
                 "credentialId": "cred_62748b40-e9d1-4659-b175-6dbc691cc0b1",
                 "modelName": "SD1x/definitely-not-loaded.safetensors",
                 "whenDifferent": "fail"}}

tests/nodes/sdcpp-model-load-idempotent.json

@@ -1,7 +1,7 @@
 {
  "name": "verify-sdcpp-model-load-idempotent",
  "requires": {
-  "http": "http://mulan:8077/health",
+  "http": "https://mulan:8077/health",
   "expect": {
    "model_loaded": true
   }
@@ -30,7 +30,7 @@
     "settings": [
      {
       "name": "serverUrl",
-      "value": "http://mulan:8077"
+      "value": "https://mulan:8077"
      },
      {
       "name": "credentialId",