diff --git a/e103-grouping/README.md b/e103-grouping/README.md new file mode 100644 index 0000000..2342b74 --- /dev/null +++ b/e103-grouping/README.md @@ -0,0 +1,100 @@ +# E103: multi-line grouping across containers + +A minimal reproduction of engine ask E103 on the shipped engine image. In the `elastic-hot-tier-budget` run, 71 of 848,190 returned records held lines from more than one container: kafka's four startup lines (seq 2751 to 2754) joined the jaeger record at seq 2750 and were filed under jaeger. This rig sends the same record shape over the same path and counts such records. + +## What runs + +The path is the hot-tier rig's, with Elasticsearch dropped. A sender writes Fluent Forward records to Fluent Bit on 24224. Fluent Bit moves the container into a `kubernetes` map (`fluent-bit/prep.lua`, the rig's `prep`), copies every record to `in.jsonl`, and forwards to the Receiver on `tenx:24224` with one worker and one connection. The Receiver returns records to Fluent Bit's second forward input on 24225, which writes them to `returned.jsonl`. + +The Receiver is started the way `gen-receiver-values.mjs` rendered it for the two-arm runs (`elastic-hot-tier-budget/results-two-arm*/values/compose.receiver.yaml`): + +- image `ghcr.io/log-10x/edge-10x:1.1.150@sha256:3e755bbc14780a27e643e09b76dfd7ec9616cab67833f70daf9420eff646d350` +- arguments `@run/input/forwarder/fluentbit @apps/receiver symbolMessageHashField tenx_hash outputEncodeField fullText("tenx_hash","routeState","message_pattern","severity_level","utf8Size")` +- environment `TENX_AIRGAPPED=true` and `TENX_FLUENTBIT_OUTPUT_HOST=fluent-bit` +- 0.5 CPU, 512 MB, tmpfs on `/tmp` + +The rendered `GH_*` variables (the policy branch) are left out, so no cap is set and nothing is held. The image keeps its config at `/etc/tenx/config` (`TENX_CONFIG`) and its modules at `/opt/tenx-edge/lib/app/modules` (`TENX_MODULES`). `E103_CONFIG_DIR` and `E103_MODULES_DIR` mount host directories read-only over them, so a candidate fix can be tested on the same image. `run.json` records the image ID and each directory's git commit. + +In the shipped modules, the Fluent Bit input takes the event's source from the Forward tag (`pipelines/run/modules/input/forwarder/fluentbit/stream.yaml`, `sourcePattern: \"tag\":\"(.*?)\"`). The group step's flush timeout counts per source (`pipelines/run/units/transform/group/unit.yaml`). The hot-tier sender gave every container the tag `app.replay`. + +## Cases + +`send.py` uses `pack` and `Sender` from `elastic-hot-tier-budget/rig/forward_send.py`. Every record carries `container_name`, `container_id`, `source`, `log` and `seq`. Every line ends with the token `e103id=`, which sits inside the JSON on the jaeger line. Each case has its own container names, and cases are 10 s apart. Cases a to d send every container under the tag `app.replay`, the way the hot-tier sender did. + +- **a.** orders logs an ERROR head. Then billing's timestamped INFO lines (1 to 3) arrive, and then orders' stack trace (3 to 8 lines of `\tat ...`, `Caused by: ...` and `\t... N more`). +- **b.** jaeger logs its JSON line. kafka's four startup lines from the hot-tier run follow (no timestamp, no level), then kafka's own timestamped INFO line. +- **c.** orders and payments are both partway through a stack trace. orders' head and two frames go out, then payments' head, then the remaining frames of both, alternating. +- **d.** Control with one container. orders sends a head and its stack trace, then 0 to 2 INFO lines. +- **e.** Cases a, b and c in rotation, with one tag per container (`docker.`, the fluentd driver's default tag). + +Each case sends 500 episodes back to back. Lines within an episode go out with no sleep between them, and episodes are 1 ms apart. Twelve paused episodes are spread through each case, with pauses of 1, 2, 3, 4, 5 and 6 s, twice each. The pause comes right after the first container's head, and in case c after orders' second frame. The full run sends 22,557 lines in 6,461 events. `groupFlushTimeout` is 5 s, and on a forwarder input a batch reaches the group step up to about 2 s after its line. + +## Scoring + +`score.py /data` splits each returned record's `log` on `"\n"` and matches every line to the line sent by its token. It reports the following, per case and in total: + +- records returned and lines returned +- cross-container records: records whose lines came from more than one sender container +- lines missing and lines duplicated +- stack-trace events returned whole: the head and every continuation line in one record that holds nothing else +- cross-container records by the pause in their episode +- records returned under the wrong tag: Fluent Bit stores the tag a record came back under as `_fb_tag`, and the scorer checks it equals `tenx.` followed by the tag its first line was sent under + +It exits 1 when there is any cross-container record, missing line, duplicated line or wrong tag, and 0 otherwise. + +`score.py --self-test` builds three inputs. A clean input must pass. The README's shape (a jaeger record holding kafka's banner lines) must fail, and so must a record returned under the wrong tag. All three verdicts came out as expected. On the full manifest, a simulated grouping in arrival order per tag gives 1,536 cross-container records and exit 1. A simulated grouping per container gives 0 and exit 0. + +## Running + +Docker must have no other rig running: `run.sh up` refuses to start when any container is up other than `e103-*` and `census-ch`. The rig publishes no host port. A run takes about 5 minutes. + +``` +./run.sh all # 1.1.150 as shipped, results in results/shipped-1.1.150/ +./run.sh extract /path/to/e103-fix # the image's own config and modules, to patch +E103_CONFIG_DIR=/path/to/e103-fix/config E103_MODULES_DIR=/path/to/e103-fix/modules E103_LABEL=fix ./run.sh all +E103_IMAGE=local/edge-10x:e103 E103_JAVA_HEAP=320M E103_LABEL=fix-1.1.151 ./run.sh all # another image +``` + +`E103_JAVA_HEAP` sets `TENX_JAVA_HEAP` for an image that runs the engine jar on a JVM, so the heap fits the 512 MB limit. + +`run.sh all` starts the containers with `docker run -d --name e103-*`, sends, waits for the returned records, saves logs and Fluent Bit's counters, scores, gzips the data and removes the containers and the network (`docker rm -f -v`). + +## Result on 1.1.150 + +Run 2026-10-25 from 22:50 to 22:55 UTC. Fluent Bit did not yet store the returned tag, so this run has no tag check. Results are in `results/shipped-1.1.150/`: `run.json` holds the image ID and launch, and `data/` holds the lines sent, the records Fluent Bit received and returned, and `score.json`. + +**Verdict: FAIL, with 1,533 cross-container records.** Fluent Bit took in 22,557 records, forwarded 22,557 to the Receiver and wrote 5,836 returned records. One of those is the Receiver's own connect message. + +| Case | Lines sent | Records | Lines returned | Cross-container records | Lines missing | Lines duplicated | Stack traces whole | +|---|---:|---:|---:|---:|---:|---:|---:| +| a | 4,428 | 1,554 | 4,428 | 512 | 0 | 0 | 0 of 512 | +| b | 3,072 | 1,036 | 3,072 | 509 | 0 | 0 | none sent | +| c | 6,602 | 1,024 | 6,602 | 512 | 0 | 0 | 0 of 1,024 | +| d | 3,781 | 1,027 | 3,781 | 0 | 0 | 0 | 509 of 512 | +| e | 4,674 | 1,194 | 4,674 | 0 | 0 | 0 | 508 of 511 | +| Total | 22,557 | 5,836 | 22,557 | 1,533 | 0 | 0 | | + +In cases a and c, every episode produced one cross-container record, paused or not. In case b, 509 of 512 episodes did. The three that did not were the two 6 s pauses and one 5 s pause, where the jaeger record was sealed before kafka's lines arrived. Case e sends the same three patterns with one tag per container and returns no cross-container record, so the cross-container records follow the shared tag. + +**Example from case b, the hot-tier shape.** The record with seq 4429 is filed under b-jaeger. It holds seq 4429 (b-jaeger, the JSON line) and seq 4430 to 4433 (b-kafka: `===> User`, `uid=1000(appuser) ...`, `===> Setting default values ...` and `===> Configuring ...`). All five lines were sent under the tag `app.replay`. + +Six stack traces in cases d and e came back split, three in each case. All six were in episodes paused 5 or 6 s after the head, and each came back as 4 to 7 records. + +## Result with the E103 fix + +Run 2026-10-26 from 00:00 to 00:04 UTC. Results are in `results/fix2-1.1.151/`. + +The fix is engine commit `0cd458f0f133daab281bfc9d067e38c1410ce050` (log-10x/engine, branch `fix/e103-sequence-key`: "Key a line's sequence values in any field order"). It ships with modules commit `6c69d90a015adaffc2163e927682d5f6304e504d` (log-10x/modules, branch `fix/e103-sequence-key`: "Sequence patterns capture the field name with its value"). The image `local/edge-10x:e103` (`sha256:8f74b8bbec2ef115fb83eb365172872afa5aec2cea4ae5fd065b49c1d77fe361`) is the 1.1.150 image with the engine jar from that commit and those modules at `/opt/tenx-edge/lib/app/modules`. Its modules match the modules commit file for file. The jar runs on a JVM, so the Receiver had `TENX_JAVA_HEAP=320M`. The arguments, other environment and limits are the same as the 1.1.150 run. + +**Verdict: PASS.** Fluent Bit took in 22,557 records, forwarded 22,557 and wrote 5,869 returned records, one of them the Receiver's connect message. All 5,868 records holding sent lines came back under `tenx.` followed by their sent tag: 4,674 under `tenx.app.replay` and 1,194 under `tenx.docker.`. + +| Case | Lines sent | Records (1.1.150) | Records (fix) | Lines returned | Cross-container records | Lines missing | Lines duplicated | Wrong tag | Stack traces whole (1.1.150) | Stack traces whole (fix) | +|---|---:|---:|---:|---:|---:|---:|---:|---:|---:|---:| +| a | 4,428 | 1,554 | 1,570 | 4,428 | 0 | 0 | 0 | 0 | 0 of 512 | 509 of 512 | +| b | 3,072 | 1,036 | 1,040 | 3,072 | 0 | 0 | 0 | 0 | none sent | none sent | +| c | 6,602 | 1,024 | 1,037 | 6,602 | 0 | 0 | 0 | 0 | 0 of 1,024 | 1,021 of 1,024 | +| d | 3,781 | 1,027 | 1,027 | 3,781 | 0 | 0 | 0 | 0 | 509 of 512 | 509 of 512 | +| e | 4,674 | 1,194 | 1,194 | 4,674 | 0 | 0 | 0 | 0 | 508 of 511 | 508 of 511 | +| Total | 22,557 | 5,836 | 5,869 | 22,557 | 0 | 0 | 0 | 0 | 1,017 | 2,547 | + +Every stack trace returned whole on 1.1.150 is returned whole with the fix. All twelve traces that came back split, three in each of cases a, c, d and e, were in episodes paused 5 or 6 s. Cases d and e split the same six on both runs. No returned record holds stack trace lines from more than one episode. diff --git a/e103-grouping/fluent-bit/fluent-bit.conf b/e103-grouping/fluent-bit/fluent-bit.conf new file mode 100644 index 0000000..c4cd7e7 --- /dev/null +++ b/e103-grouping/fluent-bit/fluent-bit.conf @@ -0,0 +1,71 @@ +# E103 grouping rig: the hot-tier rig's Fluent Bit path with Elasticsearch dropped. +# sender (Forward, 24224) -> prep -> [in.jsonl] -> Receiver (tenx:24224, one worker, one connection) +# Receiver (24225, Tag_Prefix tenx.) -> _fb_tag (the tag it came back under) -> [returned.jsonl] +# The forward output block is the hot-tier rig's, setting for setting. + +[SERVICE] + Flush 1 + Log_Level info + Grace 10 + HTTP_Server On + HTTP_Listen 0.0.0.0 + HTTP_Port 2020 + +[INPUT] + Name forward + Listen 0.0.0.0 + Port 24224 + Buffer_Max_Size 16M + Buffer_Chunk_Size 1M + +[FILTER] + Name lua + Match app.* + script /fluent-bit/etc/rig/prep.lua + call prep + +[FILTER] + Name lua + Match docker.* + script /fluent-bit/etc/rig/prep.lua + call prep + +[OUTPUT] + Name file + Match_Regex ^(app|docker)\. + Path /data + File in.jsonl + Format plain + +[OUTPUT] + Name forward + Match_Regex ^(app|docker)\. + Host tenx + Port 24224 + Retry_Limit False + Workers 1 + net.max_worker_connections 1 + net.keepalive on + net.keepalive_max_recycle 100000000 + net.keepalive_idle_timeout 300 + +[INPUT] + Name forward + Listen 0.0.0.0 + Port 24225 + Tag_Prefix tenx. + Buffer_Max_Size 16M + Buffer_Chunk_Size 1M + +[FILTER] + Name lua + Match tenx.* + script /fluent-bit/etc/rig/prep.lua + call return_tag + +[OUTPUT] + Name file + Match tenx.* + Path /data + File returned.jsonl + Format plain diff --git a/e103-grouping/fluent-bit/prep.lua b/e103-grouping/fluent-bit/prep.lua new file mode 100644 index 0000000..8bd50b8 --- /dev/null +++ b/e103-grouping/fluent-bit/prep.lua @@ -0,0 +1,19 @@ +-- prep from elastic-hot-tier-budget/rig/fluent-bit/rig.lua, unchanged: the container moves into a +-- Kubernetes-style `kubernetes` map (container_name, docker_id); fb_ts is the event time. +function prep(tag, ts, rec) + local c = rec["container_name"] + if c then c = (string.gsub(c, "^/", "")) end + local k = { container_name = c } + if rec["container_id"] then k["docker_id"] = rec["container_id"] end + rec["container_name"] = nil + rec["container_id"] = nil + rec["kubernetes"] = k + rec["fb_ts"] = string.format("%.3f", ts) + return 2, ts, rec +end + +-- returned records: the Forward tag they came back under (the Receiver's tag with the tenx. prefix) +function return_tag(tag, ts, rec) + rec["_fb_tag"] = tag + return 2, ts, rec +end diff --git a/e103-grouping/results/fix2-1.1.151/data/in.jsonl.gz b/e103-grouping/results/fix2-1.1.151/data/in.jsonl.gz new file mode 100644 index 0000000..bf42bd9 Binary files /dev/null and b/e103-grouping/results/fix2-1.1.151/data/in.jsonl.gz differ diff --git a/e103-grouping/results/fix2-1.1.151/data/returned.jsonl.gz b/e103-grouping/results/fix2-1.1.151/data/returned.jsonl.gz new file mode 100644 index 0000000..ac87f54 Binary files /dev/null and b/e103-grouping/results/fix2-1.1.151/data/returned.jsonl.gz differ diff --git a/e103-grouping/results/fix2-1.1.151/data/score.json b/e103-grouping/results/fix2-1.1.151/data/score.json new file mode 100644 index 0000000..dd4e5bb --- /dev/null +++ b/e103-grouping/results/fix2-1.1.151/data/score.json @@ -0,0 +1,55 @@ +{ + "verdict": "PASS", + "records_in_returned_file": 5869, + "fluent_bit_in_records": 22557, + "cases": { + "a": { + "records": 1570, + "lines_returned": 4428, + "lines_sent": 4428, + "trace_events": 512, + "trace_events_whole": 509, + "cross_container_by_pause_s": {} + }, + "b": { + "records": 1040, + "lines_returned": 3072, + "lines_sent": 3072, + "cross_container_by_pause_s": {} + }, + "c": { + "records": 1037, + "lines_returned": 6602, + "lines_sent": 6602, + "trace_events": 1024, + "trace_events_whole": 1021, + "cross_container_by_pause_s": {} + }, + "d": { + "records": 1027, + "lines_returned": 3781, + "lines_sent": 3781, + "trace_events": 512, + "trace_events_whole": 509, + "cross_container_by_pause_s": {} + }, + "e": { + "records": 1194, + "lines_returned": 4674, + "lines_sent": 4674, + "trace_events": 511, + "trace_events_whole": 508, + "cross_container_by_pause_s": {} + } + }, + "total": { + "records": 5869, + "lines_returned": 22557, + "lines_sent": 22557, + "trace_events": 2559, + "trace_events_whole": 2547, + "records_without_log": 1, + "tag_checked": 5868 + }, + "cross_container_examples": [] +} \ No newline at end of file diff --git a/e103-grouping/results/fix2-1.1.151/data/sent.jsonl.gz b/e103-grouping/results/fix2-1.1.151/data/sent.jsonl.gz new file mode 100644 index 0000000..e023898 Binary files /dev/null and b/e103-grouping/results/fix2-1.1.151/data/sent.jsonl.gz differ diff --git a/e103-grouping/results/fix2-1.1.151/fluent-bit-metrics.json b/e103-grouping/results/fix2-1.1.151/fluent-bit-metrics.json new file mode 100644 index 0000000..46f4e07 --- /dev/null +++ b/e103-grouping/results/fix2-1.1.151/fluent-bit-metrics.json @@ -0,0 +1 @@ +{"input":{"forward.0":{"records":22557,"bytes":5724518},"forward.1":{"records":5869,"bytes":4257869}},"filter":{"lua.0":{"drop_records":0,"add_records":0,"records":17883,"bytes":4987203,"drop_bytes":0},"lua.1":{"drop_records":0,"add_records":0,"records":4674,"bytes":1301240,"drop_bytes":0},"lua.2":{"drop_records":0,"add_records":0,"records":5869,"bytes":4468167,"drop_bytes":0}},"output":{"file.0":{"proc_records":22557,"proc_bytes":6288443,"errors":0,"retries":0,"retries_failed":0,"dropped_records":0,"retried_records":0},"forward.1":{"proc_records":22557,"proc_bytes":6288443,"errors":0,"retries":0,"retries_failed":0,"dropped_records":0,"retried_records":0},"file.2":{"proc_records":5869,"proc_bytes":4468167,"errors":0,"retries":0,"retries_failed":0,"dropped_records":0,"retried_records":0}}} diff --git a/e103-grouping/results/fix2-1.1.151/fluent-bit.log b/e103-grouping/results/fix2-1.1.151/fluent-bit.log new file mode 100644 index 0000000..d550c2a --- /dev/null +++ b/e103-grouping/results/fix2-1.1.151/fluent-bit.log @@ -0,0 +1,32 @@ +Fluent Bit v4.2.8 +* Copyright (C) 2015-2026 The Fluent Bit Authors +* Fluent Bit is a CNCF graduated project under the Fluent organization +* https://fluentbit.io + +______ _ _ ______ _ _ ___ _____ +| ___| | | | | ___ (_) | / | / __ \ +| |_ | |_ _ ___ _ __ | |_ | |_/ /_| |_ __ __/ /| | `' / /' +| _| | | | | |/ _ \ '_ \| __| | ___ \ | __| \ \ / / /_| | / / +| | | | |_| | __/ | | | |_ | |_/ / | |_ \ V /\___ |_./ /___ +\_| |_|\__,_|\___|_| |_|\__| \____/|_|\__| \_/ |_(_)_____/ + + Fluent Bit v4.2 – Direct Routes Ahead + Celebrating 10 Years of Open, Fluent Innovation! + +[2026/10/25 23:59:45.279046242] [ info] [fluent bit] version=4.2.8, commit=419540c428, pid=1 +[2026/10/25 23:59:45.279256912] [ info] [storage] ver=1.5.4, type=memory, sync=normal, checksum=off, max_chunks_up=128 +[2026/10/25 23:59:45.279274178] [ info] [simd ] SSE2 +[2026/10/25 23:59:45.279278183] [ info] [cmetrics] version=1.0.6 +[2026/10/25 23:59:45.279281967] [ info] [ctraces ] version=0.6.6 +[2026/10/25 23:59:45.279355303] [ info] [input:forward:forward.0] initializing +[2026/10/25 23:59:45.279363817] [ info] [input:forward:forward.0] storage_strategy='memory' (memory only) +[2026/10/25 23:59:45.279490244] [ info] [input:forward:forward.0] listening on 0.0.0.0:24224 +[2026/10/25 23:59:45.279532687] [ info] [input:forward:forward.1] initializing +[2026/10/25 23:59:45.279537698] [ info] [input:forward:forward.1] storage_strategy='memory' (memory only) +[2026/10/25 23:59:45.279569595] [ info] [input:forward:forward.1] listening on 0.0.0.0:24225 +[2026/10/25 23:59:45.309599825] [ info] [output:forward:forward.1] worker #0 started +[2026/10/25 23:59:45.309601028] [ info] [output:file:file.2] worker #0 started +[2026/10/25 23:59:45.309632131] [ info] [output:file:file.0] worker #0 started +[2026/10/25 23:59:45.311057193] [ info] [http_server] listen iface=0.0.0.0 tcp_port=2020 +[2026/10/25 23:59:45.311101039] [ info] [sp] stream processor started +[2026/10/25 23:59:45.311140443] [ info] [engine] Shutdown Grace Period=10, Shutdown Input Grace Period=5 diff --git a/e103-grouping/results/fix2-1.1.151/run.json b/e103-grouping/results/fix2-1.1.151/run.json new file mode 100644 index 0000000..d770d57 --- /dev/null +++ b/e103-grouping/results/fix2-1.1.151/run.json @@ -0,0 +1,26 @@ +{ + "started_utc": "2026-10-26T00:00:14Z", + "image": "local/edge-10x:e103", + "image_id": "sha256:8f74b8bbec2ef115fb83eb365172872afa5aec2cea4ae5fd065b49c1d77fe361", + "args": [ + "@run/input/forwarder/fluentbit", + "@apps/receiver", + "symbolMessageHashField", + "tenx_hash", + "outputEncodeField", + "fullText(\"tenx_hash\",\"routeState\",\"message_pattern\",\"severity_level\",\"utf8Size\")" + ], + "env": [ + "TENX_AIRGAPPED=true", + "TENX_FLUENTBIT_OUTPUT_HOST=fluent-bit", + "TENX_JAVA_HEAP=320M" + ], + "cpus": 0.5, + "memory": "512m", + "config_dir": null, + "config_commit": null, + "modules_dir": null, + "modules_commit": null, + "fluent_bit_image": "fluent/fluent-bit:4.2", + "fluent_bit_image_id": "sha256:6806769c10acf11b41d14083b3101a24433b4ca113a1ab7a6b1a1b7cad86a7e8" +} \ No newline at end of file diff --git a/e103-grouping/results/fix2-1.1.151/score.md b/e103-grouping/results/fix2-1.1.151/score.md new file mode 100644 index 0000000..6112a20 --- /dev/null +++ b/e103-grouping/results/fix2-1.1.151/score.md @@ -0,0 +1,9 @@ +| case | lines_sent | records | lines_returned | cross_container_records | lines_in_cross_container_records | lines_missing | lines_duplicated | records_wrong_tag | trace_events | trace_events_whole | cross by pause (s) | +|---|---|---|---|---|---|---|---|---|---|---|---| +| a | 4428 | 1570 | 4428 | 0 | 0 | 0 | 0 | 0 | 512 | 509 | {} | +| b | 3072 | 1040 | 3072 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | {} | +| c | 6602 | 1037 | 6602 | 0 | 0 | 0 | 0 | 0 | 1024 | 1021 | {} | +| d | 3781 | 1027 | 3781 | 0 | 0 | 0 | 0 | 0 | 512 | 509 | {} | +| e | 4674 | 1194 | 4674 | 0 | 0 | 0 | 0 | 0 | 511 | 508 | {} | +| total | 22557 | 5869 | 22557 | 0 | 0 | 0 | 0 | 0 | 2559 | 2547 | | +{"verdict": "PASS", "records_in_returned_file": 5869, "fluent_bit_in_records": 22557, "records_without_sent_line": 0, "records_without_log": 1, "nonblank_lines_without_token": 0, "tag_checked": 5868} diff --git a/e103-grouping/results/fix2-1.1.151/send.log b/e103-grouping/results/fix2-1.1.151/send.log new file mode 100644 index 0000000..c6fe43b --- /dev/null +++ b/e103-grouping/results/fix2-1.1.151/send.log @@ -0,0 +1,6 @@ +{"case": "a", "episodes": 512, "lines": 4428, "seconds": 44.0} +{"case": "b", "episodes": 512, "lines": 3072, "seconds": 43.6} +{"case": "c", "episodes": 512, "lines": 6602, "seconds": 44.2} +{"case": "d", "episodes": 512, "lines": 3781, "seconds": 43.8} +{"case": "e", "episodes": 512, "lines": 4674, "seconds": 43.9} +{"final_seq": 22557} diff --git a/e103-grouping/results/fix2-1.1.151/tenx.log b/e103-grouping/results/fix2-1.1.151/tenx.log new file mode 100644 index 0000000..3e7177a --- /dev/null +++ b/e103-grouping/results/fix2-1.1.151/tenx.log @@ -0,0 +1,27 @@ +[INFO ] 2026-10-26 00:00:00.293 [main] PipelineLauncher - launching 10x engine v1.1.151, flavor: 'runtime', pipeline: 'run' +[INFO ] 2026-10-26 00:00:00.295 [main] PipelineLauncher - log4j2 config file loaded from: /etc/tenx/config/log4j2.yaml +[WARN ] 2026-10-26 00:00:01.794 [main] PipelineLauncher - No license configured; running on the built-in free tier: up to 10 nodes, airgapped. +[WARN ] 2026-10-26 00:00:01.795 [main] PipelineLauncher - Above 10 nodes, a paid license token is required: set licenseFile / licenseKey, the TENX_LICENSE_FILE / TENX_LICENSE_KEY env var, or a licenseKey/licenseFile entry in your bootstrap .yaml. See https://doc.log10x.com/manage/license/ +[INFO ] 2026-10-26 00:00:03.488 [main] PipelineLauncher - pipelineConfigLoader took: 1611ms +[INFO ] 2026-10-26 00:00:03.577 [main] ExecutionPipeline - executing /opt/tenx-edge/lib/app/modules/pipelines/run/pipeline.yaml (myReceiver) +[INFO ] 2026-10-26 00:00:03.789 [main] ExecutionPipeline - pipeline units: configLoader => symbolLoader(shared/symbols, tenx/symbols) => templateLoader => readStream(stream:fluentbit) => parallelize(0.5 / 1) => transform => group => aggregateSingle(emitted_events: 10000/2s) => aggregateSingle(all_events: 10000/2s) => logOutput(run/modules/output/event/forward) => printProgress => monitor => tokenizeStats => publishEnvMetrics +πŸͺ΅ Initializing 10x engine. Logging to SYS_OUT +πŸš€ Launching 10x Engine: Receiver app +πŸ“š Loading symbol libraries from: /etc/tenx/config/data/shared/symbols,/etc/tenx/symbols +πŸ“‚ Loaded symbol files: /etc/tenx/symbols/tenx-symbols-1.1.150.10x.tar +πŸ“‚ Loading TenXTemplates from: data/templates/*.json,data/sample/output/*.json +πŸ“₯ Reading events from Fluent Bit via Forward protocol on tcp://0.0.0.0:24224 +🚦 Applying rate regulator to: fluentbit +[INFO ] 2026-10-26 00:00:10.988 [main] ForwardProtocolInputStream - initializing Forward protocol input stream on TCP port: 24224 +[INFO ] 2026-10-26 00:00:10.994 [main] ForwardProtocolInputStream - Forward protocol server listening on TCP port: 24224 +βš™οΈ Transforming events into TenXObjects using 50% of available cores +ℹ️ Enriching TenXObjects with severity field: 'severity_level' +πŸ”² Consolidating multi-line events into logical TenXObject groups +πŸ’¬ Enriching TenXObjects with message field: 'message_pattern' +🌐 Enriching TenXObjects with HTTP code field: 'http_code' +πŸ“‹ Enriching TenXObjects with lookup field: 'http_message' from file: /etc/tenx/config/pipelines/run/initialize/lookup/http.csv +☸️ Enriching TenXObjects with k8s container context using fluentK8s +[INFO ] 2026-10-26 00:00:12.595 [main] EventLogPublisherConfigBuilder - Added new loggers to log4j: [tenxForward__fluent-bit_24225] +πŸ“ Writing TenXObject field: 'fullText("tenx_hash","routeState","message_pattern","severity_level","utf8Size")' β†’ Fluentd: fluent-bit:24225 +[INFO ] 2026-10-26 00:00:13.085 [main] ResourceReloadUnit - resource reload: starting with 3 watched path(s); pollInterval=10s +[INFO ] 2026-10-26 00:00:15.867 [AsyncWorkerTaskInput: readStream 00:00:13] ForwardProtocolInputStream - client connected to Forward protocol input: tcp://0.0.0.0:24224 diff --git a/e103-grouping/results/shipped-1.1.150/data/in.jsonl.gz b/e103-grouping/results/shipped-1.1.150/data/in.jsonl.gz new file mode 100644 index 0000000..54ea5c0 Binary files /dev/null and b/e103-grouping/results/shipped-1.1.150/data/in.jsonl.gz differ diff --git a/e103-grouping/results/shipped-1.1.150/data/returned.jsonl.gz b/e103-grouping/results/shipped-1.1.150/data/returned.jsonl.gz new file mode 100644 index 0000000..0d52105 Binary files /dev/null and b/e103-grouping/results/shipped-1.1.150/data/returned.jsonl.gz differ diff --git a/e103-grouping/results/shipped-1.1.150/data/score.json b/e103-grouping/results/shipped-1.1.150/data/score.json new file mode 100644 index 0000000..5ef853f --- /dev/null +++ b/e103-grouping/results/shipped-1.1.150/data/score.json @@ -0,0 +1,886 @@ +{ + "verdict": "FAIL", + "records_in_returned_file": 5836, + "fluent_bit_in_records": 22557, + "cases": { + "a": { + "records": 1554, + "lines_returned": 4428, + "cross_container_records": 512, + "lines_in_cross_container_records": 3386, + "lines_sent": 4428, + "trace_events": 512, + "trace_events_whole": 0, + "cross_container_by_pause_s": { + "0": 500, + "1": 2, + "2": 2, + "3": 2, + "4": 2, + "5": 2, + "6": 2 + } + }, + "b": { + "records": 1036, + "lines_returned": 3072, + "cross_container_records": 509, + "lines_in_cross_container_records": 2545, + "lines_sent": 3072, + "cross_container_by_pause_s": { + "0": 500, + "1": 2, + "2": 2, + "3": 2, + "4": 2, + "5": 1 + } + }, + "c": { + "records": 1024, + "lines_returned": 6602, + "cross_container_records": 512, + "lines_in_cross_container_records": 5066, + "lines_sent": 6602, + "trace_events": 1024, + "trace_events_whole": 0, + "cross_container_by_pause_s": { + "0": 500, + "1": 2, + "2": 2, + "3": 2, + "4": 2, + "5": 2, + "6": 2 + } + }, + "d": { + "records": 1027, + "lines_returned": 3781, + "lines_sent": 3781, + "trace_events": 512, + "trace_events_whole": 509, + "cross_container_by_pause_s": {} + }, + "e": { + "records": 1194, + "lines_returned": 4674, + "lines_sent": 4674, + "trace_events": 511, + "trace_events_whole": 508, + "cross_container_by_pause_s": {} + } + }, + "total": { + "records": 5836, + "lines_returned": 22557, + "cross_container_records": 1533, + "lines_in_cross_container_records": 10997, + "lines_sent": 22557, + "trace_events": 2559, + "trace_events_whole": 1017, + "records_without_log": 1 + }, + "cross_container_examples": [ + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 2, + "lines": [ + { + "seq": 2, + "container": "a-billing", + "line": "2026-10-25T22:50:25.511Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-736685 amount=540.47 e103id=2" + }, + { + "seq": 3, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:87) e103id=3" + }, + { + "seq": 4, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:76) e103id=4" + }, + { + "seq": 5, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:874) e103id=5" + }, + { + "seq": 6, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:506) e103id=6" + }, + { + "seq": 7, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=7" + }, + { + "seq": 8, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:152) e103id=8" + }, + { + "seq": 9, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceRepository.load(OrderServiceRepository.java:44) e103id=9" + }, + { + "seq": 10, + "container": "a-orders", + "line": "\t... 26 more e103id=10" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 12, + "lines": [ + { + "seq": 12, + "container": "a-billing", + "line": "2026-10-25T22:50:25.515Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-190252 amount=382.35 e103id=12" + }, + { + "seq": 13, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:395) e103id=13" + }, + { + "seq": 14, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:168) e103id=14" + }, + { + "seq": 15, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:892) e103id=15" + }, + { + "seq": 16, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:672) e103id=16" + }, + { + "seq": 17, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=17" + }, + { + "seq": 18, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:176) e103id=18" + }, + { + "seq": 19, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceRepository.load(OrderServiceRepository.java:44) e103id=19" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 23, + "lines": [ + { + "seq": 23, + "container": "a-billing", + "line": "2026-10-25T22:50:25.518Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-410891 amount=47.71 e103id=23" + }, + { + "seq": 24, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:374) e103id=24" + }, + { + "seq": 25, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:178) e103id=25" + }, + { + "seq": 26, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:865) e103id=26" + }, + { + "seq": 27, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:621) e103id=27" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 31, + "lines": [ + { + "seq": 31, + "container": "a-billing", + "line": "2026-10-25T22:50:25.522Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-230269 amount=581.22 e103id=31" + }, + { + "seq": 32, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:235) e103id=32" + }, + { + "seq": 33, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:151) e103id=33" + }, + { + "seq": 34, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:832) e103id=34" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 37, + "lines": [ + { + "seq": 37, + "container": "a-billing", + "line": "2026-10-25T22:50:25.524Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-285128 amount=460.15 e103id=37" + }, + { + "seq": 38, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:30) e103id=38" + }, + { + "seq": 39, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:160) e103id=39" + }, + { + "seq": 40, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:861) e103id=40" + }, + { + "seq": 41, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:652) e103id=41" + }, + { + "seq": 42, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=42" + }, + { + "seq": 43, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:189) e103id=43" + }, + { + "seq": 44, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceRepository.load(OrderServiceRepository.java:55) e103id=44" + }, + { + "seq": 45, + "container": "a-orders", + "line": "\t... 44 more e103id=45" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 48, + "lines": [ + { + "seq": 48, + "container": "a-billing", + "line": "2026-10-25T22:50:25.527Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-777675 amount=691.58 e103id=48" + }, + { + "seq": 49, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:25) e103id=49" + }, + { + "seq": 50, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:159) e103id=50" + }, + { + "seq": 51, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:830) e103id=51" + }, + { + "seq": 52, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:644) e103id=52" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 55, + "lines": [ + { + "seq": 55, + "container": "a-billing", + "line": "2026-10-25T22:50:25.530Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-662496 amount=102.68 e103id=55" + }, + { + "seq": 56, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:252) e103id=56" + }, + { + "seq": 57, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:104) e103id=57" + }, + { + "seq": 58, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:811) e103id=58" + }, + { + "seq": 59, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:641) e103id=59" + }, + { + "seq": 60, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=60" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 64, + "lines": [ + { + "seq": 64, + "container": "a-billing", + "line": "2026-10-25T22:50:25.533Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-462345 amount=141.52 e103id=64" + }, + { + "seq": 65, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:112) e103id=65" + }, + { + "seq": 66, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:66) e103id=66" + }, + { + "seq": 67, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:834) e103id=67" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 70, + "lines": [ + { + "seq": 70, + "container": "a-billing", + "line": "2026-10-25T22:50:25.536Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-726134 amount=746.79 e103id=70" + }, + { + "seq": 71, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:34) e103id=71" + }, + { + "seq": 72, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:179) e103id=72" + }, + { + "seq": 73, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:849) e103id=73" + }, + { + "seq": 74, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:660) e103id=74" + }, + { + "seq": 75, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=75" + }, + { + "seq": 76, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:196) e103id=76" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 79, + "lines": [ + { + "seq": 79, + "container": "a-billing", + "line": "2026-10-25T22:50:25.539Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-248160 amount=144.68 e103id=79" + }, + { + "seq": 80, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:149) e103id=80" + }, + { + "seq": 81, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:88) e103id=81" + }, + { + "seq": 82, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:866) e103id=82" + }, + { + "seq": 83, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:508) e103id=83" + }, + { + "seq": 84, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=84" + }, + { + "seq": 85, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:175) e103id=85" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 88, + "lines": [ + { + "seq": 88, + "container": "a-billing", + "line": "2026-10-25T22:50:25.542Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-583794 amount=729.96 e103id=88" + }, + { + "seq": 89, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:299) e103id=89" + }, + { + "seq": 90, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:189) e103id=90" + }, + { + "seq": 91, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:897) e103id=91" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 93, + "lines": [ + { + "seq": 93, + "container": "a-billing", + "line": "2026-10-25T22:50:25.545Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-744702 amount=58.27 e103id=93" + }, + { + "seq": 94, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:153) e103id=94" + }, + { + "seq": 95, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:193) e103id=95" + }, + { + "seq": 96, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:801) e103id=96" + }, + { + "seq": 97, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:666) e103id=97" + }, + { + "seq": 98, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=98" + }, + { + "seq": 99, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:188) e103id=99" + }, + { + "seq": 100, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceRepository.load(OrderServiceRepository.java:80) e103id=100" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 103, + "lines": [ + { + "seq": 103, + "container": "a-billing", + "line": "2026-10-25T22:50:25.548Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-894242 amount=394.84 e103id=103" + }, + { + "seq": 104, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:199) e103id=104" + }, + { + "seq": 105, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:32) e103id=105" + }, + { + "seq": 106, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:896) e103id=106" + }, + { + "seq": 107, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:643) e103id=107" + }, + { + "seq": 108, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=108" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 112, + "lines": [ + { + "seq": 112, + "container": "a-billing", + "line": "2026-10-25T22:50:25.551Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-742757 amount=711.75 e103id=112" + }, + { + "seq": 113, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:119) e103id=113" + }, + { + "seq": 114, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:125) e103id=114" + }, + { + "seq": 115, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885) e103id=115" + }, + { + "seq": 116, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:667) e103id=116" + }, + { + "seq": 117, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=117" + }, + { + "seq": 118, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:186) e103id=118" + }, + { + "seq": 119, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceRepository.load(OrderServiceRepository.java:62) e103id=119" + }, + { + "seq": 120, + "container": "a-orders", + "line": "\t... 49 more e103id=120" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 122, + "lines": [ + { + "seq": 122, + "container": "a-billing", + "line": "2026-10-25T22:50:25.555Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-240940 amount=815.32 e103id=122" + }, + { + "seq": 123, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:260) e103id=123" + }, + { + "seq": 124, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:137) e103id=124" + }, + { + "seq": 125, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:851) e103id=125" + }, + { + "seq": 126, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:695) e103id=126" + }, + { + "seq": 127, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=127" + }, + { + "seq": 128, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:195) e103id=128" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 130, + "lines": [ + { + "seq": 130, + "container": "a-billing", + "line": "2026-10-25T22:50:25.558Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-230984 amount=115.18 e103id=130" + }, + { + "seq": 131, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:330) e103id=131" + }, + { + "seq": 132, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:81) e103id=132" + }, + { + "seq": 133, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:841) e103id=133" + }, + { + "seq": 134, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:574) e103id=134" + }, + { + "seq": 135, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=135" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 139, + "lines": [ + { + "seq": 139, + "container": "a-billing", + "line": "2026-10-25T22:50:25.561Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-414795 amount=691.48 e103id=139" + }, + { + "seq": 140, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:252) e103id=140" + }, + { + "seq": 141, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:90) e103id=141" + }, + { + "seq": 142, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:818) e103id=142" + }, + { + "seq": 143, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:612) e103id=143" + }, + { + "seq": 144, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=144" + }, + { + "seq": 145, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:170) e103id=145" + }, + { + "seq": 146, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceRepository.load(OrderServiceRepository.java:86) e103id=146" + }, + { + "seq": 147, + "container": "a-orders", + "line": "\t... 40 more e103id=147" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 151, + "lines": [ + { + "seq": 151, + "container": "a-billing", + "line": "2026-10-25T22:50:25.566Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-887396 amount=169.62 e103id=151" + }, + { + "seq": 152, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:191) e103id=152" + }, + { + "seq": 153, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:189) e103id=153" + }, + { + "seq": 154, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:895) e103id=154" + }, + { + "seq": 155, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:634) e103id=155" + }, + { + "seq": 156, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=156" + }, + { + "seq": 157, + "container": "a-orders", + "line": "\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:170) e103id=157" + }, + { + "seq": 158, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceRepository.load(OrderServiceRepository.java:82) e103id=158" + }, + { + "seq": 159, + "container": "a-orders", + "line": "\t... 48 more e103id=159" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 161, + "lines": [ + { + "seq": 161, + "container": "a-billing", + "line": "2026-10-25T22:50:25.569Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-855326 amount=263.98 e103id=161" + }, + { + "seq": 162, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:345) e103id=162" + }, + { + "seq": 163, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:183) e103id=163" + }, + { + "seq": 164, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:884) e103id=164" + }, + { + "seq": 165, + "container": "a-orders", + "line": "\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:589) e103id=165" + }, + { + "seq": 166, + "container": "a-orders", + "line": "Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. e103id=166" + } + ] + }, + { + "case": "a", + "filed_under": "a-billing", + "record_seq": 169, + "lines": [ + { + "seq": 169, + "container": "a-billing", + "line": "2026-10-25T22:50:25.572Z INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-860571 amount=12.88 e103id=169" + }, + { + "seq": 170, + "container": "a-orders", + "line": "\tat com.example.orders.OrderService.place(OrderService.java:364) e103id=170" + }, + { + "seq": 171, + "container": "a-orders", + "line": "\tat com.example.orders.OrderServiceController.handle(OrderServiceController.java:27) e103id=171" + }, + { + "seq": 172, + "container": "a-orders", + "line": "\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:858) e103id=172" + } + ] + } + ] +} \ No newline at end of file diff --git a/e103-grouping/results/shipped-1.1.150/data/sent.jsonl.gz b/e103-grouping/results/shipped-1.1.150/data/sent.jsonl.gz new file mode 100644 index 0000000..7aa3d97 Binary files /dev/null and b/e103-grouping/results/shipped-1.1.150/data/sent.jsonl.gz differ diff --git a/e103-grouping/results/shipped-1.1.150/fluent-bit-metrics.json b/e103-grouping/results/shipped-1.1.150/fluent-bit-metrics.json new file mode 100644 index 0000000..4909e9e --- /dev/null +++ b/e103-grouping/results/shipped-1.1.150/fluent-bit-metrics.json @@ -0,0 +1 @@ +{"input":{"forward.0":{"records":22557,"bytes":5724518},"forward.1":{"records":5836,"bytes":4210322}},"filter":{"lua.0":{"drop_records":0,"add_records":0,"records":17883,"bytes":4987203,"drop_bytes":0},"lua.1":{"drop_records":0,"add_records":0,"records":4674,"bytes":1301240,"drop_bytes":0}},"output":{"file.0":{"proc_records":22557,"proc_bytes":6288443,"errors":0,"retries":0,"retries_failed":0,"dropped_records":0,"retried_records":0},"forward.1":{"proc_records":22557,"proc_bytes":6288443,"errors":0,"retries":0,"retries_failed":0,"dropped_records":0,"retried_records":0},"file.2":{"proc_records":5836,"proc_bytes":4210322,"errors":0,"retries":0,"retries_failed":0,"dropped_records":0,"retried_records":0}}} diff --git a/e103-grouping/results/shipped-1.1.150/fluent-bit.log b/e103-grouping/results/shipped-1.1.150/fluent-bit.log new file mode 100644 index 0000000..0852107 --- /dev/null +++ b/e103-grouping/results/shipped-1.1.150/fluent-bit.log @@ -0,0 +1,32 @@ +Fluent Bit v4.2.8 +* Copyright (C) 2015-2026 The Fluent Bit Authors +* Fluent Bit is a CNCF graduated project under the Fluent organization +* https://fluentbit.io + +______ _ _ ______ _ _ ___ _____ +| ___| | | | | ___ (_) | / | / __ \ +| |_ | |_ _ ___ _ __ | |_ | |_/ /_| |_ __ __/ /| | `' / /' +| _| | | | | |/ _ \ '_ \| __| | ___ \ | __| \ \ / / /_| | / / +| | | | |_| | __/ | | | |_ | |_/ / | |_ \ V /\___ |_./ /___ +\_| |_|\__,_|\___|_| |_|\__| \____/|_|\__| \_/ |_(_)_____/ + + Fluent Bit v4.2 – Direct Routes Ahead + Celebrating 10 Years of Open, Fluent Innovation! + +[2026/10/25 22:50:15.493487865] [ info] [fluent bit] version=4.2.8, commit=419540c428, pid=1 +[2026/10/25 22:50:15.493764436] [ info] [storage] ver=1.5.4, type=memory, sync=normal, checksum=off, max_chunks_up=128 +[2026/10/25 22:50:15.493886486] [ info] [simd ] SSE2 +[2026/10/25 22:50:15.493898412] [ info] [cmetrics] version=1.0.6 +[2026/10/25 22:50:15.493942381] [ info] [ctraces ] version=0.6.6 +[2026/10/25 22:50:15.494256436] [ info] [input:forward:forward.0] initializing +[2026/10/25 22:50:15.494265193] [ info] [input:forward:forward.0] storage_strategy='memory' (memory only) +[2026/10/25 22:50:15.494399992] [ info] [input:forward:forward.0] listening on 0.0.0.0:24224 +[2026/10/25 22:50:15.494451273] [ info] [input:forward:forward.1] initializing +[2026/10/25 22:50:15.494458422] [ info] [input:forward:forward.1] storage_strategy='memory' (memory only) +[2026/10/25 22:50:15.494494314] [ info] [input:forward:forward.1] listening on 0.0.0.0:24225 +[2026/10/25 22:50:15.520015224] [ info] [output:forward:forward.1] worker #0 started +[2026/10/25 22:50:15.520960583] [ info] [output:file:file.0] worker #0 started +[2026/10/25 22:50:15.521373823] [ info] [output:file:file.2] worker #0 started +[2026/10/25 22:50:15.528724960] [ info] [http_server] listen iface=0.0.0.0 tcp_port=2020 +[2026/10/25 22:50:15.528824532] [ info] [sp] stream processor started +[2026/10/25 22:50:15.528883735] [ info] [engine] Shutdown Grace Period=10, Shutdown Input Grace Period=5 diff --git a/e103-grouping/results/shipped-1.1.150/run.json b/e103-grouping/results/shipped-1.1.150/run.json new file mode 100644 index 0000000..e67d99b --- /dev/null +++ b/e103-grouping/results/shipped-1.1.150/run.json @@ -0,0 +1,25 @@ +{ + "started_utc": "2026-10-25T22:50:24Z", + "image": "ghcr.io/log-10x/edge-10x:1.1.150@sha256:3e755bbc14780a27e643e09b76dfd7ec9616cab67833f70daf9420eff646d350", + "image_id": "sha256:3e755bbc14780a27e643e09b76dfd7ec9616cab67833f70daf9420eff646d350", + "args": [ + "@run/input/forwarder/fluentbit", + "@apps/receiver", + "symbolMessageHashField", + "tenx_hash", + "outputEncodeField", + "fullText(\"tenx_hash\",\"routeState\",\"message_pattern\",\"severity_level\",\"utf8Size\")" + ], + "env": [ + "TENX_AIRGAPPED=true", + "TENX_FLUENTBIT_OUTPUT_HOST=fluent-bit" + ], + "cpus": 0.5, + "memory": "512m", + "config_dir": null, + "config_commit": null, + "modules_dir": null, + "modules_commit": null, + "fluent_bit_image": "fluent/fluent-bit:4.2", + "fluent_bit_image_id": "sha256:6806769c10acf11b41d14083b3101a24433b4ca113a1ab7a6b1a1b7cad86a7e8" +} \ No newline at end of file diff --git a/e103-grouping/results/shipped-1.1.150/score.md b/e103-grouping/results/shipped-1.1.150/score.md new file mode 100644 index 0000000..c0b7e79 --- /dev/null +++ b/e103-grouping/results/shipped-1.1.150/score.md @@ -0,0 +1,9 @@ +| case | lines_sent | records | lines_returned | cross_container_records | lines_in_cross_container_records | lines_missing | lines_duplicated | trace_events | trace_events_whole | cross by pause (s) | +|---|---|---|---|---|---|---|---|---|---|---| +| a | 4428 | 1554 | 4428 | 512 | 3386 | 0 | 0 | 512 | 0 | {"0": 500, "1": 2, "2": 2, "3": 2, "4": 2, "5": 2, "6": 2} | +| b | 3072 | 1036 | 3072 | 509 | 2545 | 0 | 0 | 0 | 0 | {"0": 500, "1": 2, "2": 2, "3": 2, "4": 2, "5": 1} | +| c | 6602 | 1024 | 6602 | 512 | 5066 | 0 | 0 | 1024 | 0 | {"0": 500, "1": 2, "2": 2, "3": 2, "4": 2, "5": 2, "6": 2} | +| d | 3781 | 1027 | 3781 | 0 | 0 | 0 | 0 | 512 | 509 | {} | +| e | 4674 | 1194 | 4674 | 0 | 0 | 0 | 0 | 511 | 508 | {} | +| total | 22557 | 5836 | 22557 | 1533 | 10997 | 0 | 0 | 2559 | 1017 | | +{"verdict": "FAIL", "records_in_returned_file": 5836, "fluent_bit_in_records": 22557, "records_without_sent_line": 0, "records_without_log": 1, "nonblank_lines_without_token": 0} diff --git a/e103-grouping/results/shipped-1.1.150/send.log b/e103-grouping/results/shipped-1.1.150/send.log new file mode 100644 index 0000000..cb3917c --- /dev/null +++ b/e103-grouping/results/shipped-1.1.150/send.log @@ -0,0 +1,6 @@ +{"case": "a", "episodes": 512, "lines": 4428, "seconds": 43.8} +{"case": "b", "episodes": 512, "lines": 3072, "seconds": 43.6} +{"case": "c", "episodes": 512, "lines": 6602, "seconds": 44.4} +{"case": "d", "episodes": 512, "lines": 3781, "seconds": 43.9} +{"case": "e", "episodes": 512, "lines": 4674, "seconds": 44.0} +{"final_seq": 22557} diff --git a/e103-grouping/results/shipped-1.1.150/tenx.log b/e103-grouping/results/shipped-1.1.150/tenx.log new file mode 100644 index 0000000..bdfbfab --- /dev/null +++ b/e103-grouping/results/shipped-1.1.150/tenx.log @@ -0,0 +1,27 @@ +[INFO ] 2026-10-25 22:50:16.949 [main] PipelineLauncher - launching 10x engine v1.1.150, flavor: 'runtime', pipeline: 'run' +[INFO ] 2026-10-25 22:50:16.950 [main] PipelineLauncher - log4j2 config file loaded from: /etc/tenx/config/log4j2.yaml +[WARN ] 2026-10-25 22:50:17.126 [main] PipelineLauncher - No license configured; running on the built-in free tier: up to 10 nodes, airgapped. +[WARN ] 2026-10-25 22:50:17.126 [main] PipelineLauncher - Above 10 nodes, a paid license token is required: set licenseFile / licenseKey, the TENX_LICENSE_FILE / TENX_LICENSE_KEY env var, or a licenseKey/licenseFile entry in your bootstrap .yaml. See https://doc.log10x.com/manage/license/ +[INFO ] 2026-10-25 22:50:17.228 [main] PipelineLauncher - pipelineConfigLoader took: 102ms +[INFO ] 2026-10-25 22:50:17.228 [main] ExecutionPipeline - executing /opt/tenx-edge/lib/app/modules/pipelines/run/pipeline.yaml (myReceiver) +[INFO ] 2026-10-25 22:50:17.229 [main] ExecutionPipeline - pipeline units: configLoader => symbolLoader(shared/symbols, tenx/symbols) => templateLoader => readStream(stream:fluentbit) => parallelize(0.5 / 1) => transform => group => aggregateSingle(emitted_events: 10000/2s) => aggregateSingle(all_events: 10000/2s) => logOutput(run/modules/output/event/forward) => printProgress => monitor => tokenizeStats => publishEnvMetrics +πŸͺ΅ Initializing 10x engine. Logging to SYS_OUT +πŸš€ Launching 10x Engine: Receiver app +πŸ“š Loading symbol libraries from: /etc/tenx/config/data/shared/symbols,/etc/tenx/symbols +πŸ“‚ Loaded symbol files: /etc/tenx/symbols/tenx-symbols-1.1.150.10x.tar +πŸ“‚ Loading TenXTemplates from: data/templates/*.json,data/sample/output/*.json +πŸ“₯ Reading events from Fluent Bit via Forward protocol on tcp://0.0.0.0:24224 +🚦 Applying rate regulator to: fluentbit +[INFO ] 2026-10-25 22:50:18.851 [main] ForwardProtocolInputStream - initializing Forward protocol input stream on TCP port: 24224 +[INFO ] 2026-10-25 22:50:18.851 [main] ForwardProtocolInputStream - Forward protocol server listening on TCP port: 24224 +βš™οΈ Transforming events into TenXObjects using 50% of available cores +ℹ️ Enriching TenXObjects with severity field: 'severity_level' +πŸ”² Consolidating multi-line events into logical TenXObject groups +πŸ’¬ Enriching TenXObjects with message field: 'message_pattern' +🌐 Enriching TenXObjects with HTTP code field: 'http_code' +πŸ“‹ Enriching TenXObjects with lookup field: 'http_message' from file: /etc/tenx/config/pipelines/run/initialize/lookup/http.csv +☸️ Enriching TenXObjects with k8s container context using fluentK8s +[INFO ] 2026-10-25 22:50:19.026 [main] EventLogPublisherConfigBuilder - Added new loggers to log4j: [tenxForward__fluent-bit_24225] +πŸ“ Writing TenXObject field: 'fullText("tenx_hash","routeState","message_pattern","severity_level","utf8Size")' β†’ Fluentd: fluent-bit:24225 +[INFO ] 2026-10-25 22:50:19.109 [main] ResourceReloadUnit - resource reload: starting with 3 watched path(s); pollInterval=10s +[INFO ] 2026-10-25 22:50:25.535 [AsyncWorkerTaskInput: readStream 22:50:19] ForwardProtocolInputStream - client connected to Forward protocol input: tcp://0.0.0.0:24224 diff --git a/e103-grouping/run.sh b/e103-grouping/run.sh new file mode 100755 index 0000000..5e27ba4 --- /dev/null +++ b/e103-grouping/run.sh @@ -0,0 +1,151 @@ +#!/bin/bash +# E103 grouping rig. Fluent Bit and the Receiver as the elastic-hot-tier-budget rig starts them, without +# Elasticsearch: the returned records go to a file. Subcommands: +# all check no other rig is running, up, send, wait for the returned records, score, clean +# up network e103, Fluent Bit (e103-fluent-bit), the Receiver (e103-tenx) +# send [cases] [n] send.py in a container (e103-send) on the network, waits for it to finish +# drain waits until every sent line is back or nothing new arrives for 20 s (at most 180 s) +# score score.py on the results dir (exit 1 on any cross-container record, missing or duplicate) +# logs saves the Receiver and Fluent Bit logs and Fluent Bit's counters to the results dir +# clean docker rm -f -v of every e103-* container, removes the e103 network +# extract copies the image's bundled config and modules to /config and /modules +# Environment: +# E103_IMAGE engine image (default: ghcr.io/log-10x/edge-10x:1.1.150, pinned by digest) +# E103_CONFIG_DIR host directory mounted read-only over the image's config (/etc/tenx/config) +# E103_MODULES_DIR host directory mounted read-only over the image's modules (/opt/tenx-edge/lib/app/modules) +# E103_LABEL results subdirectory name (default: shipped-1.1.150, or override when a dir is set) +# E103_JAVA_HEAP sets TENX_JAVA_HEAP on the Receiver, for an image that runs the engine jar on a JVM +set -euo pipefail +HERE=$(cd "$(dirname "$0")" && pwd) +RIG=$(cd "$HERE/../elastic-hot-tier-budget/rig" && pwd) +IMAGE=${E103_IMAGE:-ghcr.io/log-10x/edge-10x:1.1.150@sha256:3e755bbc14780a27e643e09b76dfd7ec9616cab67833f70daf9420eff646d350} +FB_IMAGE=fluent/fluent-bit:4.2 +PY_IMAGE=python:3.12-slim +NET=e103 +if [ -n "${E103_CONFIG_DIR:-}${E103_MODULES_DIR:-}" ]; then LABEL=${E103_LABEL:-override}; else LABEL=${E103_LABEL:-shipped-1.1.150}; fi +RES=$HERE/results/$LABEL +DATA=$RES/data +# the Receiver's arguments and environment, as gen-receiver-values.mjs renders them for the hot-tier run +# (results-two-arm*/values/compose.receiver.yaml); GH_* (the policy branch) is left out: nothing is held +ARGS=(@run/input/forwarder/fluentbit @apps/receiver symbolMessageHashField tenx_hash outputEncodeField + 'fullText("tenx_hash","routeState","message_pattern","severity_level","utf8Size")') +ENVLIST=(TENX_AIRGAPPED=true TENX_FLUENTBIT_OUTPUT_HOST=fluent-bit) +[ -z "${E103_JAVA_HEAP:-}" ] || ENVLIST+=(TENX_JAVA_HEAP="$E103_JAVA_HEAP") +ENVS=(); for e in "${ENVLIST[@]}"; do ENVS+=(-e "$e"); done + +# census-ch (another session's ClickHouse, host port 8124) may run alongside; this rig publishes no host port +# grep without -q reads all of docker logs, so pipefail does not see a SIGPIPE +listening() { docker logs e103-tenx 2>&1 | grep 'Forward protocol server listening' >/dev/null; } +foreign() { docker ps --format '{{.Names}}' | grep -v -e '^e103-' -e '^census-ch$' || true; } + +up() { + [ -z "$(foreign)" ] || { echo "other containers are running, not starting:"; foreign; exit 3; } + mkdir -p "$DATA" + rm -f "$DATA"/*.jsonl + docker network inspect "$NET" >/dev/null 2>&1 || docker network create "$NET" >/dev/null + docker run -d --name e103-fluent-bit --network "$NET" --network-alias fluent-bit --memory 300m \ + -v "$HERE/fluent-bit:/fluent-bit/etc/rig:ro" -v "$DATA:/data" \ + "$FB_IMAGE" /fluent-bit/bin/fluent-bit -c /fluent-bit/etc/rig/fluent-bit.conf >/dev/null + MOUNTS=() + [ -z "${E103_CONFIG_DIR:-}" ] || MOUNTS+=(-v "$(cd "$E103_CONFIG_DIR" && pwd):/etc/tenx/config:ro") + [ -z "${E103_MODULES_DIR:-}" ] || MOUNTS+=(-v "$(cd "$E103_MODULES_DIR" && pwd):/opt/tenx-edge/lib/app/modules:ro") + docker run -d --name e103-tenx --network "$NET" --network-alias tenx --cpus 0.5 --memory 512m --tmpfs /tmp \ + "${ENVS[@]}" ${MOUNTS[@]+"${MOUNTS[@]}"} "$IMAGE" "${ARGS[@]}" >/dev/null + for _ in $(seq 1 60); do + listening && break + [ "$(docker inspect -f '{{.State.Running}}' e103-tenx)" = true ] || break + sleep 2 + done + listening || { echo "the Receiver did not start"; docker logs --tail 30 e103-tenx; exit 1; } + sleep 3 + commit() { git -C "$1" rev-parse HEAD 2>/dev/null || echo "not a git checkout"; } + E103_ENVLIST=$(printf '%s\n' "${ENVLIST[@]}") python3 - "$RES/run.json" "$IMAGE" "$(docker inspect -f '{{.Image}}' e103-tenx)" "${E103_CONFIG_DIR:-}" "${E103_MODULES_DIR:-}" \ + "$( [ -n "${E103_CONFIG_DIR:-}" ] && commit "$E103_CONFIG_DIR")" "$( [ -n "${E103_MODULES_DIR:-}" ] && commit "$E103_MODULES_DIR")" \ + "$(docker inspect -f '{{.Image}}' e103-fluent-bit)" "${ARGS[@]}" <<'EOF' +import json, os, sys, time +out, image, image_id, cdir, mdir, ccommit, mcommit, fb_id, *args = sys.argv[1:] +json.dump({'started_utc': time.strftime('%Y-%m-%dT%H:%M:%SZ', time.gmtime()), 'image': image, 'image_id': image_id, + 'args': args, 'env': os.environ['E103_ENVLIST'].split(), 'cpus': 0.5, 'memory': '512m', + 'config_dir': cdir or None, 'config_commit': ccommit or None, 'modules_dir': mdir or None, 'modules_commit': mcommit or None, + 'fluent_bit_image': 'fluent/fluent-bit:4.2', 'fluent_bit_image_id': fb_id}, open(out, 'w'), indent=1) +EOF + echo "up: $LABEL" +} + +send() { + docker rm -f -v e103-send >/dev/null 2>&1 || true + docker run -d --name e103-send --network "$NET" -v "$HERE:/e103:ro" -v "$RIG:/rig:ro" -v "$DATA:/out" \ + "$PY_IMAGE" python3 -u /e103/send.py fluent-bit 24224 /out/sent.jsonl "${1:-abcde}" "${2:-500}" >/dev/null + docker wait e103-send >/dev/null + docker logs e103-send > "$RES/send.log" 2>&1 + docker rm -f -v e103-send >/dev/null + cat "$RES/send.log" +} + +drain() { + python3 - "$DATA" <<'EOF' +import json, os, re, sys, time +d = sys.argv[1] +want = sum(1 for _ in open(os.path.join(d, 'sent.jsonl'))) +tok = re.compile(r'e103id\W{1,3}(\d+)') +def back(): + p = os.path.join(d, 'returned.jsonl') + n = 0 + if os.path.exists(p): + for l in open(p): + try: + m = json.loads(l).get('log') + except ValueError: + continue + n += len(tok.findall(m)) if isinstance(m, str) else 0 + return n +t0 = last_t = time.time(); last = -1 +while time.time() - t0 < 180: + n = back() + if n != last: + last, last_t = n, time.time() + if n >= want or time.time() - last_t > 20: + break + time.sleep(3) +print(json.dumps({'sent_lines': want, 'returned_tokens': last, 'waited_s': round(time.time() - t0)})) +EOF +} + +logs() { + docker logs e103-tenx > "$RES/tenx.log" 2>&1 || true + docker logs e103-fluent-bit > "$RES/fluent-bit.log" 2>&1 || true + docker rm -f -v e103-fbmetrics >/dev/null 2>&1 || true + docker run -d --name e103-fbmetrics --network "$NET" "$PY_IMAGE" python3 -c \ + "import urllib.request; print(urllib.request.urlopen('http://fluent-bit:2020/api/v1/metrics').read().decode())" >/dev/null + docker wait e103-fbmetrics >/dev/null; docker logs e103-fbmetrics > "$RES/fluent-bit-metrics.json" 2>&1 || true + docker rm -f -v e103-fbmetrics >/dev/null 2>&1 || true +} + +clean() { + for c in $(docker ps -a --format '{{.Names}}' | grep '^e103-' || true); do docker rm -f -v "$c" >/dev/null; done + docker network rm "$NET" >/dev/null 2>&1 || true +} + +case "${1:-}" in + up) up ;; + send) send "${2:-abcde}" "${3:-500}" ;; + drain) drain ;; + score) python3 "$HERE/score.py" "$DATA" ;; + logs) logs ;; + clean) clean ;; + extract) + dir=${2:?target dir}; mkdir -p "$dir" + docker rm -f e103-extract >/dev/null 2>&1 || true + docker create --name e103-extract "$IMAGE" >/dev/null + docker cp e103-extract:/etc/tenx/config "$dir/config" >/dev/null + docker cp e103-extract:/opt/tenx-edge/lib/app/modules "$dir/modules" >/dev/null + docker rm -f -v e103-extract >/dev/null + echo "$dir/config $dir/modules" ;; + all) + trap clean EXIT + up; send "${2:-abcde}" "${3:-500}"; drain; logs + set +e; python3 "$HERE/score.py" "$DATA" | tee "$RES/score.md"; rc=${PIPESTATUS[0]}; set -e + gzip -f "$DATA"/*.jsonl + exit $rc ;; + *) sed -n '2,18p' "$0"; exit 2 ;; +esac diff --git a/e103-grouping/score.py b/e103-grouping/score.py new file mode 100755 index 0000000..0ce82a6 --- /dev/null +++ b/e103-grouping/score.py @@ -0,0 +1,171 @@ +#!/usr/bin/env python3 +"""E103 scorer. Reads the sender's manifest (one row per line sent: seq, case, container, event) and the +records the Receiver returned (Fluent Bit's file output, one JSON record per line). Each returned record's +message (`log`) is split on "\\n" and each line is matched to the line sent by its token e103id=. +Reports, per case and in total: records returned, lines returned, cross-container records (a record whose +lines came from more than one sender container), lines missing, lines duplicated; and, as diagnostics, the +stack-trace events returned whole (head and every continuation line in one record holding nothing else) +and the cross-container records by the pause in their episode. When the returned records carry _fb_tag (the +Forward tag they came back under), records whose tag is not tenx.. +Exit status: 0 PASS; 1 FAIL (any cross-container record, missing line, duplicated line or wrong tag); 2 bad input. + score.py reads sent.jsonl[.gz], returned.jsonl[.gz], in.jsonl[.gz]; writes score.json + score.py --self-test checks the verdict on a built clean input and a built broken input""" +import collections, gzip, json, os, re, sys, tempfile + +TOKEN = re.compile(r'e103id\W{1,3}(\d+)') + + +def rows(path): + for p in (path, path + '.gz'): + if os.path.exists(p): + f = gzip.open(p, 'rt') if p.endswith('.gz') else open(p) + with f: + for l in f: + l = l.strip() + if l: + try: + yield json.loads(l) + except ValueError: + yield {'_unparsed': l} + return + raise FileNotFoundError(path) + + +def score(R): + sent = {r['seq']: r for r in rows(os.path.join(R, 'sent.jsonl'))} + recs = list(rows(os.path.join(R, 'returned.jsonl'))) + try: + fb_in = sum(1 for r in rows(os.path.join(R, 'in.jsonl')) if 'seq' in r) + except FileNotFoundError: + fb_in = None + cases = sorted({r['case'] for r in sent.values()}) + per = {c: collections.Counter() for c in cases} + seen = collections.Counter() + tot = collections.Counter() + cross, cross_by_pause = [], {c: collections.Counter() for c in cases} + ev_records = collections.defaultdict(set) # event -> record indices holding any of its lines + rec_events = [] # record index -> set of events + for i, rec in enumerate(recs): + msg = rec.get('log') + if not isinstance(msg, str): + tot['records_without_log'] += 1 + rec_events.append(set()) + continue + lines = msg.split('\n') + seqs = [] + for l in lines: + m = TOKEN.search(l) + if m and int(m.group(1)) in sent: + seqs.append(int(m.group(1))) + elif l.strip(): + tot['nonblank_lines_without_token'] += 1 + tot['lines_returned'] += len(lines) + if not seqs: + tot['records_without_sent_line'] += 1 + rec_events.append(set()) + continue + for s in seqs: + seen[s] += 1 + case = sent[seqs[0]]['case'] + per[case]['records'] += 1 + if '_fb_tag' in rec: + tot['tag_checked'] += 1 + if rec['_fb_tag'] != 'tenx.' + sent[seqs[0]]['tag']: + per[case]['records_wrong_tag'] += 1 + per[case]['lines_returned'] += len(lines) + conts = [sent[s]['container'] for s in seqs] + evs = {sent[s]['event'] for s in seqs} + rec_events.append(evs) + for e in evs: + ev_records[e].add(i) + if len(set(conts)) > 1: + per[case]['cross_container_records'] += 1 + per[case]['lines_in_cross_container_records'] += len(seqs) + cross_by_pause[case][max(sent[s]['pause'] for s in seqs)] += 1 + k = (rec.get('kubernetes') or {}).get('container_name') if isinstance(rec.get('kubernetes'), dict) else None + cross.append({'case': case, 'filed_under': k, 'record_seq': rec.get('seq'), + 'lines': [{'seq': s, 'container': sent[s]['container'], 'line': sent[s]['line']} for s in seqs]}) + events = collections.defaultdict(list) + for s, r in sent.items(): + per[r['case']]['lines_sent'] += 1 + if seen[s] == 0: + per[r['case']]['lines_missing'] += 1 + elif seen[s] > 1: + per[r['case']]['lines_duplicated'] += 1 + if r['kind'] == 'trace': + events[r['event']].append(s) + for e, ss in events.items(): + c = sent[ss[0]]['case'] + per[c]['trace_events'] += 1 + held = ev_records.get(e, set()) + whole = len(held) == 1 and rec_events[next(iter(held))] == {e} and all(seen[s] == 1 for s in ss) + per[c]['trace_events_whole'] += int(whole) + total = collections.Counter() + for c in cases: + total.update(per[c]) + total.update({k: v for k, v in tot.items() if k != 'lines_returned'}) + total['records'] += tot['records_without_sent_line'] + tot['records_without_log'] + total['lines_returned'] = tot['lines_returned'] + verdict = 'PASS' if not (total['cross_container_records'] or total['lines_missing'] or total['lines_duplicated'] or total['records_wrong_tag']) else 'FAIL' + out = {'verdict': verdict, 'records_in_returned_file': len(recs), 'fluent_bit_in_records': fb_in, + 'cases': {c: dict(per[c], cross_container_by_pause_s={str(k): v for k, v in sorted(cross_by_pause[c].items())}) for c in cases}, + 'total': dict(total), 'cross_container_examples': cross[:20]} + return out + + +KEYS = ['lines_sent', 'records', 'lines_returned', 'cross_container_records', 'lines_in_cross_container_records', + 'lines_missing', 'lines_duplicated', 'records_wrong_tag', 'trace_events', 'trace_events_whole'] + + +def report(out): + print('| case | ' + ' | '.join(KEYS) + ' | cross by pause (s) |') + print('|' + '---|' * (len(KEYS) + 2)) + for c, d in out['cases'].items(): + print(f'| {c} | ' + ' | '.join(str(d.get(k, 0)) for k in KEYS) + f" | {json.dumps(d['cross_container_by_pause_s'])} |") + t = out['total'] + print(f'| total | ' + ' | '.join(str(t.get(k, 0)) for k in KEYS) + ' | |') + print(json.dumps({k: out[k] for k in ('verdict', 'records_in_returned_file', 'fluent_bit_in_records')} | + {k: t.get(k, 0) for k in ('records_without_sent_line', 'records_without_log', 'nonblank_lines_without_token', 'tag_checked')})) + + +def self_test(): + """A clean input must PASS; the same input with one cross-container record (the README's shape: a + jaeger head that took kafka's banner lines) must FAIL, and so must one record back under the wrong tag.""" + def build(d, broken, bad_tag=False): + sent = [(1, 'b', 'b-jaeger', 'b0A', 'single'), (2, 'b', 'b-kafka', 'b0Bbanner', 'banner'), (3, 'b', 'b-kafka', 'b0Bbanner', 'banner'), + (4, 'd', 'd-orders', 'd0A', 'trace'), (5, 'd', 'd-orders', 'd0A', 'trace')] + with open(os.path.join(d, 'sent.jsonl'), 'w') as f: + for s, c, cont, ev, kind in sent: + f.write(json.dumps({'seq': s, 'case': c, 'ep': 0, 'pause': 0, 'tag': 'app.replay', 'container': cont, 'event': ev, 'kind': kind, + 'role': 'head', 'line': f'line e103id={s}'}) + '\n') + recs = ([['line e103id=1', 'banner e103id=2', 'banner e103id=3']] if broken else [['line e103id=1'], ['banner e103id=2', 'banner e103id=3']]) + recs.append(['head e103id=4', '\tat x e103id=5']) + with open(os.path.join(d, 'returned.jsonl'), 'w') as f: + for i, r in enumerate(recs): + tag = 'tenx.wrong' if bad_tag and i == 0 else 'tenx.app.replay' + f.write(json.dumps({'log': '\n'.join(r), 'kubernetes': {'container_name': 'x'}, '_fb_tag': tag}) + '\n') + ok = True + for name, broken, bad_tag, want in (('clean', False, False, 'PASS'), ('cross-container', True, False, 'FAIL'), ('wrong tag', False, True, 'FAIL')): + with tempfile.TemporaryDirectory() as d: + build(d, broken, bad_tag) + got = score(d) + print(json.dumps({'input': name, 'want': want, 'got': got['verdict'], + 'cross_container_records': got['total'].get('cross_container_records', 0), + 'records_wrong_tag': got['total'].get('records_wrong_tag', 0)})) + ok &= got['verdict'] == want + return ok + + +if __name__ == '__main__': + if sys.argv[1:] == ['--self-test']: + sys.exit(0 if self_test() else 1) + if len(sys.argv) != 2: + raise SystemExit(__doc__) + try: + out = score(sys.argv[1]) + except FileNotFoundError as e: + print(f'missing input: {e}', file=sys.stderr) + sys.exit(2) + json.dump(out, open(os.path.join(sys.argv[1], 'score.json'), 'w'), indent=1) + report(out) + sys.exit(0 if out['verdict'] == 'PASS' else 1) diff --git a/e103-grouping/send.py b/e103-grouping/send.py new file mode 100755 index 0000000..2609114 --- /dev/null +++ b/e103-grouping/send.py @@ -0,0 +1,177 @@ +#!/usr/bin/env python3 +"""E103 sender. Interleaves containers on one Fluent Forward connection, in the record shape the Docker +fluentd driver sends (container_name, container_id, source, log) plus seq, through the pack and Sender of +elastic-hot-tier-budget/rig/forward_send.py (mounted at /rig, standard library only). Every line carries +the token e103id= (inside the JSON for the JSON line), and every line is written to the manifest. + +Cases, each with its own container names, 10 s of quiet between cases: + a orders logs an ERROR head; billing's timestamped INFO lines arrive; then orders' stack trace lines. + b jaeger logs a JSON line; kafka's four startup banner lines arrive (no timestamp, no level, the lines of + the hot-tier run), then kafka's own timestamped INFO line. + c orders and payments are both mid stack trace: orders' head and two frames, payments' head, then the + remaining frames of both, alternating. + d control, orders only: the head, the stack trace, then 0 to 2 INFO lines. + e a, b and c in rotation, with one Fluent tag per container (docker., the fluentd driver's + default tag) instead of the shared app.replay tag of a to d. +Per case: episodes sent back to back (lines within an episode with no sleep, 1 ms between +episodes) and twelve paused episodes (1, 2, 3, 4, 5, 6 s, twice each) spread through them, the pause sent +right after orders' (or jaeger's) head, for c after orders' second frame. + send.py [cases=abcde] [episodes=500]""" +import hashlib, json, os, random, socket, sys, time +from datetime import datetime, timezone + +sys.path.insert(0, os.environ.get('E103_RIG', '/rig')) +from forward_send import Sender, event_time, pack # noqa: E402 + +SHARED_TAG = 'app.replay' +GAP_S = 10 +PAUSES = [1, 2, 3, 4, 5, 6] * 2 + + +class TaggedSender(Sender): + def send(self, rec, tag=SHARED_TAG): + msg = b'\x93' + pack(tag) + event_time(time.time()) + pack(rec) + while True: + try: + if self.s is None: + self.s = socket.create_connection(self.addr, timeout=10) + self.s.sendall(msg) + return + except OSError: + self.s = None + time.sleep(1) + + +def cid(name): + return hashlib.sha256(name.encode()).hexdigest() + + +def fill(text, seq): + now = datetime.now(timezone.utc) + ms = now.microsecond // 1000 + text = (text.replace('{TS}', now.strftime('%Y-%m-%dT%H:%M:%S.') + f'{ms:03d}Z') + .replace('{KTS}', now.strftime('%Y-%m-%d %H:%M:%S,') + f'{ms:03d}') + .replace('{EPOCH}', f'{now.timestamp():.7f}')) + if '{TOK}' in text: + return text.replace('{TOK}', str(seq)) + return f'{text} e103id={seq}' + + +def trace(rng, svc, cls, method, msg, cause): + """A Java ERROR head and its continuation lines (frames, Caused by, ... N more).""" + f = cls + '.java' + head = f'{{TS}} ERROR [http-nio-8080-exec-{rng.randint(1, 40)}] c.e.{svc}.{cls} - {msg}' + frames = [f'\tat com.example.{svc}.{cls}.{method}({f}:{rng.randint(20, 400)})', + f'\tat com.example.{svc}.{cls}Controller.handle({cls}Controller.java:{rng.randint(20, 200)})', + f'\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:{rng.randint(800, 900)})', + f'\tat jakarta.servlet.http.HttpServlet.service(HttpServlet.java:{rng.randint(500, 700)})', + f'Caused by: {cause}', + f'\tat com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:{rng.randint(150, 200)})', + f'\tat com.example.{svc}.{cls}Repository.load({cls}Repository.java:{rng.randint(30, 90)})', + f'\t... {rng.randint(20, 60)} more'] + n = rng.randint(3, 8) + return head, frames[:n] + + +def orders_trace(rng): + return trace(rng, 'orders', 'OrderService', 'place', f'Failed to place order {rng.randint(10000, 99999)}', + 'java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.') + + +def payments_trace(rng): + return trace(rng, 'payments', 'ChargeService', 'charge', f'Charge declined for card ending {rng.randint(1000, 9999)}', + 'java.net.SocketTimeoutException: Read timed out') + + +JAEGER = ('{"level":"info","ts":{EPOCH},"caller":"grpc@v1.60.0/clientconn.go:532",' + '"msg":"[core][Channel #1] Channel Connectivity change to READY","system":"grpc","grpc_log":true,"e103id":"{TOK}"}') +KAFKA_BANNER = ['===> User', 'uid=1000(appuser) gid=1000(appuser) groups=1000(appuser)', + '===> Setting default values of environment variables if not already set.', '===> Configuring ...'] + + +def episode(case, pattern, rng): + """Steps in send order: ('line', container, event, kind, role, text) or ('pause',).""" + c = lambda n: f'{case}-{n}' + if pattern == 'a': + head, conts = orders_trace(rng) + s = [('line', c('orders'), 'A', 'trace', 'head', head), ('pause',)] + for k in range(rng.randint(1, 3)): + s.append(('line', c('billing'), f'B{k}', 'single', 'head', + f'{{TS}} INFO [scheduling-1] c.e.billing.InvoiceJob - Posted invoice INV-{rng.randint(100000, 999999)} amount={rng.randint(5, 900)}.{rng.randint(10, 99)}')) + s += [('line', c('orders'), 'A', 'trace', 'cont', t) for t in conts] + return s + if pattern == 'b': + s = [('line', c('jaeger'), 'A', 'single', 'head', JAEGER), ('pause',)] + s += [('line', c('kafka'), 'Bbanner', 'banner', 'cont', t) for t in KAFKA_BANNER] + s.append(('line', c('kafka'), 'B', 'single', 'head', + f'[{{KTS}}] INFO [KafkaRaftServer nodeId=1] Kafka Server started (kafka.server.KafkaRaftServer)')) + return s + if pattern == 'c': + ah, ac = orders_trace(rng) + bh, bc = payments_trace(rng) + s = [('line', c('orders'), 'A', 'trace', 'head', ah)] + s += [('line', c('orders'), 'A', 'trace', 'cont', t) for t in ac[:2]] + s.append(('pause',)) + s.append(('line', c('payments'), 'B', 'trace', 'head', bh)) + ra, rb = ac[2:], list(bc) + while ra or rb: + if rb: + s.append(('line', c('payments'), 'B', 'trace', 'cont', rb.pop(0))) + if ra: + s.append(('line', c('orders'), 'A', 'trace', 'cont', ra.pop(0))) + return s + if pattern == 'd': + head, conts = orders_trace(rng) + s = [('line', c('orders'), 'A', 'trace', 'head', head), ('pause',)] + s += [('line', c('orders'), 'A', 'trace', 'cont', t) for t in conts] + for k in range(rng.randint(0, 2)): + s.append(('line', c('orders'), f'I{k}', 'single', 'head', + f'{{TS}} INFO [http-nio-8080-exec-{rng.randint(1, 40)}] c.e.orders.OrderService - Order {rng.randint(10000, 99999)} placed in {rng.randint(3, 300)} ms')) + return s + raise ValueError(pattern) + + +def main(): + host, port, manifest = sys.argv[1], int(sys.argv[2]), sys.argv[3] + cases = sys.argv[4] if len(sys.argv) > 4 else 'abcde' + n_ep = int(sys.argv[5]) if len(sys.argv) > 5 else 500 + rng = random.Random(103) + out = TaggedSender(host, port) + seq = 0 + with open(manifest, 'w') as m: + for ci, case in enumerate(cases): + if ci: + time.sleep(GAP_S) + pauses = list(PAUSES) + rng.shuffle(pauses) + every = max(1, n_ep // len(pauses)) + plan = [] + for i in range(n_ep): + plan.append(0) + if pauses and i % every == every // 2: + plan.append(pauses.pop()) + plan += pauses + t0, lines0 = time.time(), seq + for ep, pause in enumerate(plan): + pattern = 'abc'[ep % 3] if case == 'e' else case + for st in episode(case, pattern, rng): + if st[0] == 'pause': + if pause: + time.sleep(pause) + continue + _, cont, ev, kind, role, text = st + seq += 1 + line = fill(text, seq) + tag = 'docker.' + cid(cont)[:12] if case == 'e' else SHARED_TAG + out.send({'container_name': '/' + cont, 'container_id': cid(cont), 'source': 'stdout', 'log': line, 'seq': seq}, tag) + m.write(json.dumps({'seq': seq, 'case': case, 'ep': ep, 'pause': pause, 'pattern': pattern, 'tag': tag, 'container': cont, + 'event': f'{case}{ep}{ev}', 'kind': kind, 'role': role, 't': round(time.time(), 6), 'line': line}) + '\n') + time.sleep(0.001) + print(json.dumps({'case': case, 'episodes': len(plan), 'lines': seq - lines0, 'seconds': round(time.time() - t0, 1)}), flush=True) + if out.s is not None: + out.s.close() + print(json.dumps({'final_seq': seq}), flush=True) + + +if __name__ == '__main__': + main()