From 83d0a060fef610102ab4f6ffcbf7671b99d6efb6 Mon Sep 17 00:00:00 2001 From: Martino Ferrari Date: Wed, 1 Jul 2026 19:36:47 +0200 Subject: [PATCH] feat(e2e): add debug/tcplogger E2E scenario kinds using debugclient MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Adds a trimmed debug_e2e.cfg (DebugService on 8080/8081, TcpLogger on 9090) and two new scenarios (s55_debug_force_trace_break, kind=debug; s56_tcplogger_delivery, kind=tcplogger) reusing it, with matching run_e2e.sh scenario-list/dispatch wiring and debugclient build steps. Also fixes a real bug found while wiring s56: debugclient's tcplogger check was tautological (it matched MarteController's own local "CMD"-level echo of the outgoing command, which contains the same text as the triggered event, instead of a line actually delivered over the real TCPLogger TCP socket) and its trigger command (an invalid FORCE) never reaches DebugServiceBase's REPORT_ERROR at all. Switched the trigger to a MSG-to-missing-destination command (which does call REPORT_ERROR) and the match to require the real log text ("not found in ORD"), recorded only after a connect-settle baseline — verified with a positive run (real Warning-level TCPLogger line received) and a negative control (LogPort=0 disables TcpLogger and the scenario correctly FAILs). Co-Authored-By: Claude Opus 4.6 --- Test/E2E/suite/debug_e2e.cfg | 82 ++++++++++++++++++++++++++++++ Test/E2E/suite/debugclient/main.go | 72 +++++++++++++++++++++----- Test/E2E/suite/run_e2e.sh | 41 +++++++++++++-- Test/E2E/suite/scenarios.py | 30 ++++++++++- Test/E2E/suite/tests_py.py | 9 ++++ 5 files changed, 216 insertions(+), 18 deletions(-) create mode 100644 Test/E2E/suite/debug_e2e.cfg diff --git a/Test/E2E/suite/debug_e2e.cfg b/Test/E2E/suite/debug_e2e.cfg new file mode 100644 index 0000000..3e7c3d7 --- /dev/null +++ b/Test/E2E/suite/debug_e2e.cfg @@ -0,0 +1,82 @@ +/** + * Trimmed single-thread configuration for the "debug"/"tcplogger" E2E + * scenario kinds: exercises DebugService FORCE/TRACE/BREAK over TCP 8080 / + * UDP 8081 and TCPLogger delivery over TCP 9090, with no UDPStreamer path. + */ + +$App = { + Class = RealTimeApplication + + +Functions = { + Class = ReferenceContainer + + +TimerGAM = { + Class = IOGAM + InputSignals = { + Counter = { + DataSource = Timer + Type = uint32 + Frequency = 1000 + } + Time = { + DataSource = Timer + Type = uint32 + } + } + OutputSignals = { + Counter = { DataSource = DDB1 Type = uint32 } + Time = { DataSource = DDB1 Type = uint32 } + } + } + } + + +Data = { + Class = ReferenceContainer + DefaultDataSource = DDB1 + + +DDB1 = { Class = GAMDataSource } + + +Timer = { + Class = LinuxTimer + SleepNature = "Default" + Signals = { + Counter = { Type = uint32 } + Time = { Type = uint32 } + } + } + + +Timings = { Class = TimingDataSource } + } + + +States = { + Class = ReferenceContainer + +Running = { + Class = RealTimeState + +Threads = { + Class = ReferenceContainer + + +Thread1 = { + Class = RealTimeThread + CPUs = 0x1 + Functions = {TimerGAM} + } + } + } + } + + +Scheduler = { + Class = GAMScheduler + TimingDataSource = Timings + } +} + +// ── DebugService ────────────────────────────────────────────────────────────── +// Patches the broker registry at startup so every signal is traceable. +// TcpLogger is auto-injected on LogPort (9090) — no explicit DataSource needed. ++DebugService = { + Class = DebugService + ControlPort = 8080 + StreamPort = 8081 + LogPort = 9090 + StreamIP = "127.0.0.1" +} diff --git a/Test/E2E/suite/debugclient/main.go b/Test/E2E/suite/debugclient/main.go index 6c4d5dc..1d3757c 100644 --- a/Test/E2E/suite/debugclient/main.go +++ b/Test/E2E/suite/debugclient/main.go @@ -9,6 +9,7 @@ import ( "flag" "fmt" "os" + "strings" "sync" "time" @@ -54,13 +55,23 @@ func main() { time.Sleep(500 * time.Millisecond) // allow TCP/UDP/log connects to establish + // Snapshot the event count *after* the connect-settle sleep so + // runTcpLoggerScript only scans events recorded from here on. Without this, + // the "log" event that Connect() itself emits synchronously (a "Connecting + // to ..." INFO message, well before any TCPLogger TCP traffic happens) + // would satisfy the check instantly regardless of whether the real + // TCPLogger (port 9090) ever delivers anything for the triggered event. + mu.Lock() + baseline := len(events) + mu.Unlock() + var ok bool var msg string switch *mode { case "debug": ok, msg = runDebugScript(mc) case "tcplogger": - ok, msg = runTcpLoggerScript(mc, *dur, &events, &mu) + ok, msg = runTcpLoggerScript(mc, *dur, &events, &mu, baseline) default: fmt.Fprintf(os.Stderr, "unknown -mode %q\n", *mode) os.Exit(2) @@ -109,28 +120,61 @@ func runDebugScript(mc *debugger.MarteController) (bool, string) { return true, "FORCE/TRACE/BREAK sequence completed without disconnect" } -// runTcpLoggerScript triggers a log-worthy event (an invalid FORCE) and -// waits for a matching "log" event to arrive over the TCPLogger TCP port -// within dur. MarteController's runLog forwards each "LOG " -// line it reads from the TCPLogger connection through sink as -// map[string]any{"type": "log", "time": ..., "level": ..., "message": ...}, -// so we poll the captured events slice for that shape. -func runTcpLoggerScript(mc *debugger.MarteController, dur time.Duration, events *[]event, mu *sync.Mutex) (bool, string) { - mc.SendCommand("FORCE App.Data.DoesNotExist 1") +// runTcpLoggerScript triggers a log-worthy event and waits for a matching +// "log" event to arrive over the real TCPLogger TCP connection (port 9090) +// within dur. +// +// NOTE: an invalid "FORCE " is *not* usable here — +// DebugServiceBase::ForceSignal() silently no-ops (count stays 0, no +// REPORT_ERROR call) when no signal matches, so it never reaches the logger +// at all. Instead we send "MSG 0", which +// DebugServiceBase::HandleCommand's MSG handler always resolves via +// ObjectRegistryDatabase::Find() and, on failure, does call +// REPORT_ERROR_STATIC(Warning, "MSG: destination '%s' not found in ORD.") +// (Source/Components/Interfaces/DebugService/DebugServiceBase.cpp) — a real, +// synchronous, deterministic log emission that the framework's LoggerService +// broadcasts to the auto-injected TcpLogger, which then writes +// "LOG \n" to every connected TCP client (see +// Source/Components/Interfaces/TCPLogger/TcpLogger.cpp ConsumeLogMessage / +// Execute). MarteController's runLog reads that line from the real TCP 9090 +// socket and forwards it through sink as map[string]any{"type": "log", +// "time": ..., "level": ..., "message": ...}. +// +// baseline is the length of *events captured right after the initial +// connect-settle sleep, before this function sends the MSG command: only +// events recorded from index baseline onward are eligible, so the "log" +// event that MarteController.Connect() itself emits synchronously (a +// "Connecting to ..." INFO message, emitted before any TCP/UDP/log socket +// activity) can never satisfy this check. +func runTcpLoggerScript(mc *debugger.MarteController, dur time.Duration, events *[]event, mu *sync.Mutex, baseline int) (bool, string) { + const missingDest = "DebugClientNoSuchDestination" + mc.SendCommand(fmt.Sprintf("MSG %s SomeFunction 0", missingDest)) deadline := time.Now().Add(dur) for time.Now().Before(deadline) { mu.Lock() - for _, e := range *events { + for _, e := range (*events)[baseline:] { if m, ok := e.data.(map[string]any); ok && m["type"] == "log" { - mu.Unlock() - return true, fmt.Sprintf("received log event: %v", m) + msg, _ := m["message"].(string) + // MarteController.writeCmd() also emits a client-side "CMD" + // level log echoing every outgoing command as "→ " + // (see martecontrol.go) — since our own MSG command text + // contains missingDest, that local echo would otherwise + // satisfy a naive substring check instantly, before the real + // TCPLogger round-trip ever happens. Require the actual + // REPORT_ERROR text the DebugService MSG handler produces + // ("not found in ORD"), which can only arrive via runLog's + // real TCP 9090 read, never via the local echo. + if strings.Contains(msg, missingDest) && strings.Contains(msg, "not found in ORD") { + mu.Unlock() + return true, fmt.Sprintf("received real TCPLogger log event: %v", m) + } } } mu.Unlock() time.Sleep(100 * time.Millisecond) } if !mc.IsConnected() { - return false, "lost connection during tcplogger wait and no log event received" + return false, "lost connection during tcplogger wait and no matching log event received" } - return false, "no log event received within duration" + return false, "no matching log event received within duration" } diff --git a/Test/E2E/suite/run_e2e.sh b/Test/E2E/suite/run_e2e.sh index 1267768..cda42bb 100755 --- a/Test/E2E/suite/run_e2e.sh +++ b/Test/E2E/suite/run_e2e.sh @@ -47,6 +47,8 @@ export LD_LIBRARY_PATH="\ ${BUILD_DIR}/Components/DataSources/UDPStreamer:\ ${BUILD_DIR}/Components/DataSources/UDPStreamerClient:\ ${BUILD_DIR}/Components/Interfaces/UDPStream:\ +${BUILD_DIR}/Components/Interfaces/DebugService:\ +${BUILD_DIR}/Components/Interfaces/TCPLogger:\ ${MARTe2_DIR}/Build/${TARGET}/Core:\ ${COMP}/DataSources/LinuxTimer:\ ${COMP}/DataSources/FileDataSource:\ @@ -56,6 +58,7 @@ ${LD_LIBRARY_PATH:-}" MARTE_APP="${MARTe2_DIR}/Build/${TARGET}/App/MARTeApp.ex" STREAMHUB_EX="${BUILD_DIR}/StreamHub/StreamHub.ex" CLIENT="${SCRIPT_DIR}/client/chain-client" +DEBUGCLIENT="${SCRIPT_DIR}/debugclient/debugclient" PY="python3" SCEN() { ${PY} "${SCRIPT_DIR}/scenarios.py" >/dev/null 2>&1; } @@ -84,13 +87,18 @@ if [ ! -x "${CLIENT}" ]; then echo "── Building chain-client ──" (cd "${SCRIPT_DIR}/client" && go build -o chain-client .) || { echo "client build failed"; exit 1; } fi +if [ ! -x "${DEBUGCLIENT}" ]; then + echo "── Building debugclient ──" + (cd "${SCRIPT_DIR}/debugclient" && go build -o debugclient .) || { echo "debugclient build failed"; exit 1; } +fi [ -x "${MARTE_APP}" ] || { echo "ERROR: MARTeApp.ex not found at ${MARTE_APP}" >&2; exit 1; } [ -x "${STREAMHUB_EX}" ] || { echo "ERROR: StreamHub.ex not found" >&2; exit 1; } # ── Scenario list (kind|id|f2|f3|f4|f5|f6|f7) ──────────────────────────────── -# chain: kind|id|ws_port|udp_port0|network|oracle|trig|checks -# direct: kind|id|cfg|-|-|-|-|- -# recorder: kind|id|marte_cfg|hub_cfg|-|-|-|- +# chain: kind|id|ws_port|udp_port0|network|oracle|trig|checks +# direct: kind|id|cfg|-|-|-|-|- +# recorder: kind|id|marte_cfg|hub_cfg|-|-|-|- +# debug/tcplogger: kind|id|cfg|cmd_port|udp_port|log_port|-|- LIST="$(${PY} - "${ONLY}" <<'PY' import sys, os sys.path.insert(0, os.path.dirname(os.path.abspath("Test/E2E/suite/scenarios.py"))) @@ -112,6 +120,10 @@ for s in S.SCENARIOS: print("|".join([kind, s["id"], s["cfg"], "", "", "", "", ""])) elif kind == "recorder": print("|".join([kind, s["id"], s["marte_cfg"], s["hub_cfg"], "", "", "", ""])) + elif kind == "debug": + print("|".join([kind, s["id"], s["cfg"], str(s["cmd_port"]), str(s["udp_port"]), str(s["log_port"]), "", ""])) + elif kind == "tcplogger": + print("|".join([kind, s["id"], s["cfg"], str(s["cmd_port"]), str(s["udp_port"]), str(s["log_port"]), "", ""])) PY )" @@ -286,6 +298,28 @@ sys.exit(0 if ok else 1) fi ;; + debug|tcplogger) + CFG="${F2}"; CMDPORT="${F3}"; UDPPORT2="${F4}"; LOGPORT="${F5}" + echo "" + echo "══ scenario ${ID} (kind=${KIND} cfg=${CFG}) ══" + timeout 15 "${MARTE_APP}" -l RealTimeLoader -f "${REPO_ROOT}/${CFG}" -s Running \ + > "${OUT_DIR}/marte_${ID}.log" 2>&1 & + APP_PID=$! + sleep 1 + "${DEBUGCLIENT}" -host 127.0.0.1 \ + -cmdport "${CMDPORT}" -udpport "${UDPPORT2}" -logport "${LOGPORT}" \ + -mode "${KIND}" -scenario "${ID}" -out "${WORK}" -dur 4s \ + > "${OUT_DIR}/client_${ID}.log" 2>&1 + CLIENT_RC=$? + kill "${APP_PID}" 2>/dev/null; wait "${APP_PID}" 2>/dev/null; APP_PID="" + if [ "${CLIENT_RC}" -eq 0 ]; then + echo "PASS" > "${WORK}/status_${ID}.txt" + else + echo "FAIL" > "${WORK}/status_${ID}.txt" + fi + echo "${ID}: $(cat "${WORK}/status_${ID}.txt")" + ;; + *) echo " SKIP: unknown scenario kind '${KIND}' for ${ID}" echo "SKIP" > "${WORK}/status_${ID}.txt" @@ -375,6 +409,7 @@ if [ "${CPP_COV}" -eq 1 ]; then make -C "${REPO_ROOT}" -f Makefile.gcc clean >/dev/null 2>&1 || true make -C "${REPO_ROOT}" -f Makefile.gcc core apps TARGET="${TARGET}" 2>&1 | tail -1 (cd "${SCRIPT_DIR}/client" && go build -o chain-client . >/dev/null 2>&1) || true + (cd "${SCRIPT_DIR}/debugclient" && go build -o debugclient . >/dev/null 2>&1) || true fi # ── Consolidated report data (+ history/regression + trend plots) ──────────── diff --git a/Test/E2E/suite/scenarios.py b/Test/E2E/suite/scenarios.py index 9020a69..bea6342 100644 --- a/Test/E2E/suite/scenarios.py +++ b/Test/E2E/suite/scenarios.py @@ -144,6 +144,10 @@ def validate_scenario(s): if "hub_cfg" not in s or "marte_cfg" not in s: errs.append(f"recorder scenario {s.get('id')} missing hub_cfg/marte_cfg") return errs + if kind in ("debug", "tcplogger"): + if not all(k in s for k in ("cfg", "cmd_port", "udp_port", "log_port")): + errs.append(f"{kind} scenario {s.get('id')} missing cfg/cmd_port/udp_port/log_port") + return errs if kind != "chain": errs.append(f"unknown scenario kind: {kind}") return errs @@ -616,7 +620,31 @@ _RECORDER = [ }, ] -SCENARIOS = SCENARIOS + _DIRECT + _RECORDER +_DEBUG = [ + { + "id": "s55_debug_force_trace_break", + "desc": "DebugService FORCE/TRACE/BREAK over real TCP 8080 + UDP 8081", + "kind": "debug", + "cfg": "Test/E2E/suite/debug_e2e.cfg", + "cmd_port": 8080, "udp_port": 8081, "log_port": 9090, + "client_checks": [], + "known_issue": None, + }, +] + +_TCPLOGGER = [ + { + "id": "s56_tcplogger_delivery", + "desc": "TCPLogger delivers a log line for a triggered DebugService event", + "kind": "tcplogger", + "cfg": "Test/E2E/suite/debug_e2e.cfg", + "cmd_port": 8080, "udp_port": 8081, "log_port": 9090, + "client_checks": [], + "known_issue": None, + }, +] + +SCENARIOS = SCENARIOS + _DIRECT + _RECORDER + _DEBUG + _TCPLOGGER if __name__ == "__main__": diff --git a/Test/E2E/suite/tests_py.py b/Test/E2E/suite/tests_py.py index c16ec66..65af44a 100644 --- a/Test/E2E/suite/tests_py.py +++ b/Test/E2E/suite/tests_py.py @@ -76,6 +76,15 @@ class TestScenarios(unittest.TestCase): for s in S.SCENARIOS: S.validate_scenario(s) # must not raise + def test_debug_and_tcplogger_scenarios_present(self): + kinds = {s["kind"] for s in S.SCENARIOS} + self.assertIn("debug", kinds) + self.assertIn("tcplogger", kinds) + debug_ids = {s["id"] for s in S.SCENARIOS if s["kind"] == "debug"} + self.assertEqual(debug_ids, {"s55_debug_force_trace_break"}) + tcplogger_ids = {s["id"] for s in S.SCENARIOS if s["kind"] == "tcplogger"} + self.assertEqual(tcplogger_ids, {"s56_tcplogger_delivery"}) + class TestGenData(unittest.TestCase): def test_ground_truth_shapes(self):