feat(e2e): add debug/tcplogger E2E scenario kinds using debugclient

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 <noreply@anthropic.com>
This commit is contained in:
Martino Ferrari
2026-07-01 19:36:47 +02:00
parent efb4ea48fb
commit 83d0a060fe
5 changed files with 216 additions and 18 deletions
+82
View File
@@ -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"
}
+58 -14
View File
@@ -9,6 +9,7 @@ import (
"flag" "flag"
"fmt" "fmt"
"os" "os"
"strings"
"sync" "sync"
"time" "time"
@@ -54,13 +55,23 @@ func main() {
time.Sleep(500 * time.Millisecond) // allow TCP/UDP/log connects to establish 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 ok bool
var msg string var msg string
switch *mode { switch *mode {
case "debug": case "debug":
ok, msg = runDebugScript(mc) ok, msg = runDebugScript(mc)
case "tcplogger": case "tcplogger":
ok, msg = runTcpLoggerScript(mc, *dur, &events, &mu) ok, msg = runTcpLoggerScript(mc, *dur, &events, &mu, baseline)
default: default:
fmt.Fprintf(os.Stderr, "unknown -mode %q\n", *mode) fmt.Fprintf(os.Stderr, "unknown -mode %q\n", *mode)
os.Exit(2) os.Exit(2)
@@ -109,28 +120,61 @@ func runDebugScript(mc *debugger.MarteController) (bool, string) {
return true, "FORCE/TRACE/BREAK sequence completed without disconnect" return true, "FORCE/TRACE/BREAK sequence completed without disconnect"
} }
// runTcpLoggerScript triggers a log-worthy event (an invalid FORCE) and // runTcpLoggerScript triggers a log-worthy event and waits for a matching
// waits for a matching "log" event to arrive over the TCPLogger TCP port // "log" event to arrive over the real TCPLogger TCP connection (port 9090)
// within dur. MarteController's runLog forwards each "LOG <level> <msg>" // within dur.
// line it reads from the TCPLogger connection through sink as //
// map[string]any{"type": "log", "time": ..., "level": ..., "message": ...}, // NOTE: an invalid "FORCE <nonexistent signal> <val>" is *not* usable here —
// so we poll the captured events slice for that shape. // DebugServiceBase::ForceSignal() silently no-ops (count stays 0, no
func runTcpLoggerScript(mc *debugger.MarteController, dur time.Duration, events *[]event, mu *sync.Mutex) (bool, string) { // REPORT_ERROR call) when no signal matches, so it never reaches the logger
mc.SendCommand("FORCE App.Data.DoesNotExist 1") // at all. Instead we send "MSG <nonexistent destination> <fn> 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 <level> <description>\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) deadline := time.Now().Add(dur)
for time.Now().Before(deadline) { for time.Now().Before(deadline) {
mu.Lock() mu.Lock()
for _, e := range *events { for _, e := range (*events)[baseline:] {
if m, ok := e.data.(map[string]any); ok && m["type"] == "log" { if m, ok := e.data.(map[string]any); ok && m["type"] == "log" {
mu.Unlock() msg, _ := m["message"].(string)
return true, fmt.Sprintf("received log event: %v", m) // MarteController.writeCmd() also emits a client-side "CMD"
// level log echoing every outgoing command as "→ <cmd>"
// (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() mu.Unlock()
time.Sleep(100 * time.Millisecond) time.Sleep(100 * time.Millisecond)
} }
if !mc.IsConnected() { 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"
} }
+38 -3
View File
@@ -47,6 +47,8 @@ export LD_LIBRARY_PATH="\
${BUILD_DIR}/Components/DataSources/UDPStreamer:\ ${BUILD_DIR}/Components/DataSources/UDPStreamer:\
${BUILD_DIR}/Components/DataSources/UDPStreamerClient:\ ${BUILD_DIR}/Components/DataSources/UDPStreamerClient:\
${BUILD_DIR}/Components/Interfaces/UDPStream:\ ${BUILD_DIR}/Components/Interfaces/UDPStream:\
${BUILD_DIR}/Components/Interfaces/DebugService:\
${BUILD_DIR}/Components/Interfaces/TCPLogger:\
${MARTe2_DIR}/Build/${TARGET}/Core:\ ${MARTe2_DIR}/Build/${TARGET}/Core:\
${COMP}/DataSources/LinuxTimer:\ ${COMP}/DataSources/LinuxTimer:\
${COMP}/DataSources/FileDataSource:\ ${COMP}/DataSources/FileDataSource:\
@@ -56,6 +58,7 @@ ${LD_LIBRARY_PATH:-}"
MARTE_APP="${MARTe2_DIR}/Build/${TARGET}/App/MARTeApp.ex" MARTE_APP="${MARTe2_DIR}/Build/${TARGET}/App/MARTeApp.ex"
STREAMHUB_EX="${BUILD_DIR}/StreamHub/StreamHub.ex" STREAMHUB_EX="${BUILD_DIR}/StreamHub/StreamHub.ex"
CLIENT="${SCRIPT_DIR}/client/chain-client" CLIENT="${SCRIPT_DIR}/client/chain-client"
DEBUGCLIENT="${SCRIPT_DIR}/debugclient/debugclient"
PY="python3" PY="python3"
SCEN() { ${PY} "${SCRIPT_DIR}/scenarios.py" >/dev/null 2>&1; } SCEN() { ${PY} "${SCRIPT_DIR}/scenarios.py" >/dev/null 2>&1; }
@@ -84,13 +87,18 @@ if [ ! -x "${CLIENT}" ]; then
echo "── Building chain-client ──" echo "── Building chain-client ──"
(cd "${SCRIPT_DIR}/client" && go build -o chain-client .) || { echo "client build failed"; exit 1; } (cd "${SCRIPT_DIR}/client" && go build -o chain-client .) || { echo "client build failed"; exit 1; }
fi 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 "${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; } [ -x "${STREAMHUB_EX}" ] || { echo "ERROR: StreamHub.ex not found" >&2; exit 1; }
# ── Scenario list (kind|id|f2|f3|f4|f5|f6|f7) ──────────────────────────────── # ── Scenario list (kind|id|f2|f3|f4|f5|f6|f7) ────────────────────────────────
# chain: kind|id|ws_port|udp_port0|network|oracle|trig|checks # chain: kind|id|ws_port|udp_port0|network|oracle|trig|checks
# direct: kind|id|cfg|-|-|-|-|- # direct: kind|id|cfg|-|-|-|-|-
# recorder: kind|id|marte_cfg|hub_cfg|-|-|-|- # recorder: kind|id|marte_cfg|hub_cfg|-|-|-|-
# debug/tcplogger: kind|id|cfg|cmd_port|udp_port|log_port|-|-
LIST="$(${PY} - "${ONLY}" <<'PY' LIST="$(${PY} - "${ONLY}" <<'PY'
import sys, os import sys, os
sys.path.insert(0, os.path.dirname(os.path.abspath("Test/E2E/suite/scenarios.py"))) 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"], "", "", "", "", ""])) print("|".join([kind, s["id"], s["cfg"], "", "", "", "", ""]))
elif kind == "recorder": elif kind == "recorder":
print("|".join([kind, s["id"], s["marte_cfg"], s["hub_cfg"], "", "", "", ""])) 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 PY
)" )"
@@ -286,6 +298,28 @@ sys.exit(0 if ok else 1)
fi 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: unknown scenario kind '${KIND}' for ${ID}"
echo "SKIP" > "${WORK}/status_${ID}.txt" 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 clean >/dev/null 2>&1 || true
make -C "${REPO_ROOT}" -f Makefile.gcc core apps TARGET="${TARGET}" 2>&1 | tail -1 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}/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 fi
# ── Consolidated report data (+ history/regression + trend plots) ──────────── # ── Consolidated report data (+ history/regression + trend plots) ────────────
+29 -1
View File
@@ -144,6 +144,10 @@ def validate_scenario(s):
if "hub_cfg" not in s or "marte_cfg" not in 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") errs.append(f"recorder scenario {s.get('id')} missing hub_cfg/marte_cfg")
return errs 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": if kind != "chain":
errs.append(f"unknown scenario kind: {kind}") errs.append(f"unknown scenario kind: {kind}")
return errs 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__": if __name__ == "__main__":
+9
View File
@@ -76,6 +76,15 @@ class TestScenarios(unittest.TestCase):
for s in S.SCENARIOS: for s in S.SCENARIOS:
S.validate_scenario(s) # must not raise 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): class TestGenData(unittest.TestCase):
def test_ground_truth_shapes(self): def test_ground_truth_shapes(self):