diff --git a/.github/workflows/logship.yml b/.github/workflows/logship.yml new file mode 100644 index 00000000..9273dcb7 --- /dev/null +++ b/.github/workflows/logship.yml @@ -0,0 +1,78 @@ +name: logship + +on: + workflow_dispatch: + pull_request: + branches: [main] + paths: + - 'log-shipper/**' + - 'scripts/tc959-*.mjs' + - 'docker-compose.dstack-postgres.yaml' + - '.github/workflows/logship.yml' + - 'deploy/ingress/redacted-logging.conf' + push: + branches: [main] + paths: + - 'log-shipper/**' + - 'scripts/tc959-*.mjs' + - 'docker-compose.dstack-postgres.yaml' + - '.github/workflows/logship.yml' + - 'deploy/ingress/redacted-logging.conf' + +permissions: + contents: read + +jobs: + boundary: + runs-on: ubuntu-latest + timeout-minutes: 10 + steps: + - uses: actions/checkout@v4 + with: + persist-credentials: false + ref: ${{ github.event.pull_request.head.sha || github.sha }} + - uses: actions/setup-node@v4 + with: + node-version: 22 + - name: Verify request budgets and hosted acceptance guards + run: node --test log-shipper/budget.test.mjs log-shipper/profile.test.mjs scripts/tc959-docker.test.mjs scripts/tc959-readiness.test.mjs + - name: Check schema provenance and compose boundary without env interpolation + run: node scripts/tc959-check.mjs + - name: Install checksum-pinned native Vector + run: | + curl --fail --location --silent --show-error https://github.com/vectordotdev/vector/releases/download/v0.59.0/vector-0.59.0-x86_64-unknown-linux-gnu.tar.gz --output /tmp/tc959-vector.tar.gz + printf '%s\n' 'fb15878d1cd68445e0658792a8fa7ccf02ae8a353c6cc5d6fe867b171993e19f /tmp/tc959-vector.tar.gz' | sha256sum --check + tar -xzf /tmp/tc959-vector.tar.gz -C /tmp + - name: Run native request and forbidden-value boundary cases + run: | + node scripts/tc959-logship.mjs render-tests /tmp/tc959-errors-slow.json errors_slow + /tmp/vector-x86_64-unknown-linux-gnu/bin/vector test /tmp/tc959-errors-slow.json + node scripts/tc959-logship.mjs render-tests /tmp/tc959-all-requests.json all_requests + /tmp/vector-x86_64-unknown-linux-gnu/bin/vector test /tmp/tc959-all-requests.json + - name: Exercise native UDP-to-HTTP delivery and console leak canaries + run: node log-shipper/native-check.mjs /tmp/vector-x86_64-unknown-linux-gnu/bin/vector + - name: Validate the actual HTTP sink without contacting it + run: | + node scripts/tc959-logship.mjs render-vector /tmp/tc959-runtime.json http://127.0.0.1:9599/ + /tmp/vector-x86_64-unknown-linux-gnu/bin/vector validate --no-environment --skip-healthchecks /tmp/tc959-runtime.json + + hosted-compose-proof: + needs: boundary + # Only GitHub's disposable Linux VM; never a self-hosted production Docker socket. + runs-on: ubuntu-24.04 + timeout-minutes: 12 + steps: + - uses: actions/checkout@v4 + with: + persist-credentials: false + ref: ${{ github.event.pull_request.head.sha || github.sha }} + - uses: actions/setup-node@v4 + with: + node-version: 22 + - name: Prove exact-compose boundary with immutable public images and synthetic inputs + timeout-minutes: 8 + run: node scripts/tc959-docker.mjs --go --ci + - name: Always diagnose before owner-only cleanup, including proof timeout + if: always() + timeout-minutes: 3 + run: node scripts/tc959-docker.mjs --go --ci --cleanup-only diff --git a/CHANGELOG.md b/CHANGELOG.md index 18907086..f0065106 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,7 @@ - Account delegation session discovery keyset-pages delegation rows independently of ability fan-out, using a composite delegator/id index so large grant sets are not truncated (TC-1195). - `/attestation` quotes the SHA-256 of `key_binding` as REPORTDATA and returns it as `key_binding_sha256`; the quote no longer carries the raw binding. Before answering 200 the node checks that the returned TDX v4 quote's REPORTDATA field holds that digest (a structural check; it does not verify the quote). When the TEE can't produce a bound quote, the endpoint returns 503 instead of 200 `mode: "classic"`, and the dstack client reports a guest-agent error status instead of a parse error. `nonce` must be 1-64 characters of `A-Z a-z 0-9 - _` (400 otherwise), and the endpoint now shares the public routes' per-IP rate limit. Verifiers recompute the digest from their own nonce and expected DID and must still verify the quote; see `docs/attestation.md` (TC-963). +- Prepare a compose-only GELF-to-Vector sidecar for the unchanged node 1.20.6 and ingress image digests. The default unsampled `errors_slow` profile emits valid requests with status >=400 or duration strictly over one second; explicit `all_requests` remains available, and all accepted typed WARN/ERROR diagnostics remain eligible for bounded count aggregation. Document eligible-request volume accounting, accepted BEST-EFFORT outage loss, the failed local burst evidence and required zero-observed-loss healthy hosted burst, plus the config-only deployment/rollback privacy packet. No Rust or application image change and no deployment authorization; see `docs/runbooks/tc-959-n0-log-shipping.md` (TC-959 N0). ## [1.20.7] - 2026-10-14 diff --git a/docker-compose.dstack-postgres.yaml b/docker-compose.dstack-postgres.yaml index 9afa4196..d661d530 100644 --- a/docker-compose.dstack-postgres.yaml +++ b/docker-compose.dstack-postgres.yaml @@ -8,19 +8,22 @@ services: tinycloud: - # DuckDB-enabled images are opt-in and use the -duckdb suffix, for example: - # ghcr.io/tinycloudlabs/tinycloud-node:1.4.0-dstack-duckdb - image: ghcr.io/tinycloudlabs/tinycloud-node:dstack + # N0: unchanged production 1.20.6 binary; this is not a new app release. + image: ghcr.io/tinycloudlabs/tinycloud-node@sha256:4bdae4fc232d886bb56bfbce4ec62ed4b8fb4e1369a01f6afb73d06dd68c188f restart: unless-stopped - # TC-970: cap the node's Docker log (stdout: one line per request plus - # application logs) at 3 x 50 MB instead of the guest daemon default - # (current dstack OS images: json-file, 10 x 100 MB). json-file keeps the - # dstack log API (`/logs/`) working. + labels: + tc.logship: tinycloud-node + # Host Docker daemon sends GELF; the app never joins Vector's network. + # Nonblocking UDP can lose logs. No raw Docker cache or /logs fallback. logging: - driver: json-file + driver: gelf options: - max-size: "50m" - max-file: "3" + gelf-address: udp://127.0.0.1:12201 + gelf-compression-type: none + labels: tc.logship + mode: non-blocking + max-buffer-size: 4m + cache-disabled: "true" ports: - "8000:8000" volumes: @@ -35,6 +38,7 @@ services: AWS_SECRET_ACCESS_KEY: "${AWS_SECRET}" AWS_DEFAULT_REGION: "${AWS_REGION}" TINYCLOUD_LOG_LEVEL: normal + TINYCLOUD_LOG__FORMAT: Json # Enable Prometheus telemetry (metrics, span histograms, pool gauges). # The metrics handler is intentionally NOT gateway-exposed: port 8001 is # not published here, so the unauthenticated /metrics endpoint stays @@ -106,15 +110,17 @@ services: - /var/run/dstack.sock:/var/run/dstack.sock - cert-data:/etc/letsencrypt restart: unless-stopped - # TC-970: the ingress logs one JSON line per request to stdout. Cap its - # Docker log at 3 x 50 MB instead of relying on the guest daemon default - # (current dstack OS images ship json-file with 10 x 100 MB). json-file - # keeps the dstack log API (`/logs/`) working. + labels: + tc.logship: tinycloud-ingress logging: - driver: json-file + driver: gelf options: - max-size: "50m" - max-file: "3" + gelf-address: udp://127.0.0.1:12201 + gelf-compression-type: none + labels: tc.logship + mode: non-blocking + max-buffer-size: 4m + cache-disabled: "true" # The dstack gateway's TLS-terminating routes (-.:443) # only forward to compose-published ports, so guest sshd on :22 is @@ -130,5 +136,42 @@ services: - "host.docker.internal:host-gateway" command: TCP-LISTEN:10022,fork,reuseaddr TCP:host.docker.internal:22 + vector: + restart: unless-stopped + image: timberio/vector:0.59.0-alpine@sha256:0e36bc2a290039e9b6a5e92f04bd2f133223506f72d09682c1df16c015172b7a + init: true + user: 10001:10001 + read_only: true + cap_drop: + - ALL + security_opt: + - no-new-privileges:true + mem_limit: 64m + memswap_limit: 64m + cpus: 0.5 + ports: + - 127.0.0.1:12201:12201/udp + networks: + - logship + tmpfs: + - /var/lib/vector:rw,noexec,nosuid,size=8m,uid=10001,gid=10001,mode=0700 + environment: + TINYCLOUD_LOGSHIP_PROFILE: ${TINYCLOUD_LOGSHIP_PROFILE:-errors_slow} + BETTERSTACK_SOURCE_TOKEN: ${BETTERSTACK_SOURCE_TOKEN:?seal the node source token before enabling log shipping} + VECTOR_CONFIG_JSON: "{\"data_dir\":\"/var/lib/vector\",\"sources\":{\"gelf_in\":{\"type\":\"socket\",\"mode\":\"udp\",\"address\":\"0.0.0.0:12201\",\"max_length\":262144,\"receive_buffer_bytes\":8388608,\"framing\":{\"method\":\"chunked_gelf\",\"chunked_gelf\":{\"decompression\":\"Auto\"}},\"decoding\":{\"codec\":\"bytes\"}}},\"transforms\":{\"gelf_envelope\":{\"type\":\"remap\",\"inputs\":[\"gelf_in\"],\"source\":\"packet = string(.message) ?? \\\"\\\"\\nif length(packet) > 262144 {\\n . = {\\\"reason\\\": \\\"oversized\\\"}\\n} else {\\n outer, err = parse_json(packet)\\n if err != null || !is_object(outer) || (outer.version != \\\"1.1\\\" && outer.version != \\\"1.0\\\") {\\n . = {\\\"reason\\\": \\\"malformed_envelope\\\"}\\n } else if exists(outer.partial_message) || exists(outer._partial_message) {\\n . = {\\\"reason\\\": \\\"partial\\\"}\\n } else {\\n label = get(outer, [\\\"_tc.logship\\\"]) ?? null\\n . = {\\\"_tc.logship\\\": label, \\\"message\\\": outer.short_message}\\n }\\n}\",\"drop_on_error\":true,\"drop_on_abort\":true},\"logship_gate\":{\"type\":\"remap\",\"inputs\":[\"gelf_envelope\"],\"source\":\"if exists(.reason) {\\n . = {\\\"reason\\\": .reason}\\n} else {\\nlabel = string(get(., [\\\"_tc.logship\\\"]) ?? null) ?? \\\"\\\"\\nraw = .message\\nreason = \\\"\\\"\\nif label == \\\"\\\" { reason = \\\"unlabelled\\\" }\\nelse if !includes([\\\"tinycloud-node\\\", \\\"tinycloud-ingress\\\"], label) { reason = \\\"unexpected_label\\\" }\\nelse if exists(.partial_message) { reason = \\\"partial\\\" }\\nelse if !is_string(raw) { reason = \\\"malformed_envelope\\\" }\\nelse if length(string!(raw)) > 65536 { reason = \\\"oversized\\\" }\\nif reason != \\\"\\\" {\\n . = {\\\"reason\\\": reason}\\n} else {\\n parsed, err = parse_json(string!(raw))\\n if err != null || !is_object(parsed) { . = {\\\"reason\\\": \\\"non_json\\\"} }\\n else if exists(parsed.partial_message) { . = {\\\"reason\\\": \\\"partial\\\"} }\\n else {\\n target = string(parsed.target) ?? \\\"\\\"\\n level = downcase(string(parsed.level) ?? \\\"\\\")\\n if label == \\\"tinycloud-node\\\" && !includes([\\\"warn\\\", \\\"error\\\"], level) && target != \\\"tinycloud\\\" && !starts_with(target, \\\"tinycloud::\\\") && target != \\\"tinycloud_core\\\" && !starts_with(target, \\\"tinycloud_core::\\\") {\\n . = {\\\"reason\\\": \\\"unknown_target\\\"}\\n } else if label == \\\"tinycloud-node\\\" && !includes([\\\"warn\\\", \\\"error\\\"], level) && (target != \\\"tinycloud::request\\\" || level != \\\"info\\\") {\\n . = {\\\"reason\\\": \\\"filtered_level\\\"}\\n } else { . = {\\\"label\\\": label, \\\"parsed\\\": parsed} }\\n }\\n}\\n}\",\"drop_on_error\":true,\"drop_on_abort\":true},\"gate_route\":{\"type\":\"route\",\"inputs\":[\"logship_gate\"],\"route\":{\"candidate\":\"exists(.parsed)\",\"rejected\":\"exists(.reason)\"}},\"allowlist\":{\"type\":\"remap\",\"inputs\":[\"gate_route.candidate\"],\"source\":\"# Only this fresh object can leave the process boundary. No envelope, span,\\n# message, error, identity, URI or unknown key is copied into it.\\nj = .parsed\\nlabel = .label\\nout = {}\\nts = \\\"\\\"\\nif label == \\\"tinycloud-node\\\" {\\n target = string(j.target) ?? \\\"\\\"\\n level = downcase(string!(j.level))\\n f = object(j.fields) ?? {}\\n msg = string(f.message) ?? \\\"\\\"\\n ts = string!(j.timestamp)\\n if target == \\\"tinycloud::request\\\" && level == \\\"info\\\" && msg == \\\"request\\\" {\\n method = string!(f.method)\\n if includes([\\\"TRACE\\\", \\\"CONNECT\\\"], method) { method = \\\"\\\" }\\n route = string!(f.route)\\n # Literal Rocket template aliases only; never split an arbitrary URI.\\n aliases = {\\\"/attestation?\\\":\\\"/attestation\\\",\\\"/.well-known/encryption/network/?\\\":\\\"/.well-known/encryption/network/\\\",\\\"/hooks/events?\\\":\\\"/hooks/events\\\",\\\"/hooks/webhooks?\\\":\\\"/hooks/webhooks\\\",\\\"/public//kv?\\\":\\\"/public//kv\\\"}\\n canonical_route = get(aliases, [route]) ?? null\\n if is_string(canonical_route) { route = canonical_route }\\n if !includes([\\\"GET\\\",\\\"HEAD\\\",\\\"POST\\\",\\\"PUT\\\",\\\"PATCH\\\",\\\"DELETE\\\",\\\"OPTIONS\\\",\\\"\\\"], method) || !includes([\\\"/healthz\\\",\\\"/info\\\",\\\"/version\\\",\\\"/invoke\\\",\\\"/delegate\\\",\\\"/revoke\\\",\\\"/attestation\\\",\\\"/signed/kv\\\",\\\"/signed/kv/\\\",\\\"/admin/quota\\\",\\\"/admin/quota/\\\",\\\"/admin/usage\\\",\\\"/hooks/events\\\",\\\"/hooks/tickets\\\",\\\"/hooks/webhooks\\\",\\\"/hooks/webhooks/\\\",\\\"/delegation/query\\\",\\\"/delegation/status\\\",\\\"/encryption/networks\\\",\\\"/encryption/networks/\\\",\\\"/encryption/networks//revoke\\\",\\\"/encryption/networks//decrypt\\\",\\\"/policy/v3/status\\\",\\\"/policy/v3/status/\\\",\\\"/policy/v3/policies\\\",\\\"/policy/v3/challenges\\\",\\\"/policy/v3/delegations\\\",\\\"/policy/v3/enforcer-bindings\\\",\\\"/policy/v3/deliveries/authorize\\\",\\\"/.well-known/tinycloud/node-keys\\\",\\\"/.well-known/encryption/network/\\\",\\\"/public//kv\\\",\\\"/public//kv/\\\",\\\"/peer/generate/\\\",\\\"/evidences/\\\",\\\"/share/v2/readiness\\\",\\\"/share/v2/policies\\\",\\\"/share/v2/policy/challenges\\\",\\\"/share/v2/policy/session\\\",\\\"/share/v2/invoke\\\",\\\"/share/v2/deliveries/authorize\\\",\\\"/<_s..>\\\",\\\"/public/<_space_id>/kv/<_key..>\\\",\\\"\\\"], route) { abort }\\n status = f.status\\n latency = f.latency_us\\n if !is_integer(status) || !is_integer(latency) { abort }\\n status = int!(status)\\n latency = int!(latency)\\n if status < 100 || status > 599 || latency < 0 || latency > 9007199254740991 { abort }\\n out = {\\\"event\\\": \\\"node_request\\\", \\\"svc\\\": \\\"api\\\", \\\"level\\\": \\\"info\\\", \\\"method\\\": method, \\\"route\\\": route, \\\"status\\\": status, \\\"latency_us\\\": latency}\\n } else {\\n if !includes([\\\"warn\\\", \\\"error\\\"], level) { abort }\\n code = \\\"unclassified\\\"\\n if target == \\\"tinycloud\\\" || starts_with(target, \\\"tinycloud::\\\") || target == \\\"tinycloud_core\\\" || starts_with(target, \\\"tinycloud_core::\\\") {\\n codes = {\\\"invocation replay insert failed\\\":\\\"invocation_replay_insert_failed\\\",\\\"invocation replay cleanup failed\\\":\\\"invocation_replay_cleanup_failed\\\",\\\"share-v2 local-tee feature active: deriving a deterministic, non-attested TEE identity from node key material\\\":\\\"share_local_tee_identity\\\",\\\"retention: delivered hook delivery prune failed\\\":\\\"retention_hook_delivery_prune_failed\\\",\\\"retention: dead-letter hook delivery prune failed\\\":\\\"retention_dead_letter_prune_failed\\\",\\\"retention: signed KV ticket prune failed\\\":\\\"retention_signed_ticket_prune_failed\\\",\\\"failed to load tunnel state; tunnel not started\\\":\\\"tunnel_state_load_failed\\\",\\\"invalid loopback API address; tunnel not started\\\":\\\"tunnel_address_invalid\\\",\\\"failed to load link state; LAN listener not started\\\":\\\"link_state_load_failed\\\",\\\"invalid link bind address; LAN listener not started\\\":\\\"link_bind_invalid\\\",\\\"invalid loopback API address; LAN listener not started\\\":\\\"link_address_invalid\\\",\\\"failed to bind link LAN listener; LAN listener not started\\\":\\\"link_bind_failed\\\",\\\"failed to build TLS config; LAN listener not started\\\":\\\"link_tls_config_failed\\\",\\\"link LAN listener exited with error\\\":\\\"link_listener_error\\\",\\\"failed to record link listener bind state\\\":\\\"link_listener_state_write_failed\\\",\\\"failed to record link listener bind failure\\\":\\\"link_bind_state_write_failed\\\",\\\"failed to load config for auto-renew\\\":\\\"link_auto_renew_config_failed\\\",\\\"link auto-renew failed\\\":\\\"link_auto_renew_failed\\\",\\\"failed to hot-reload renewed link cert\\\":\\\"link_cert_reload_failed\\\",\\\"link auto-renew succeeded but no state.json found; skipping cert hot-reload\\\":\\\"link_cert_state_missing\\\",\\\"failed to reload TLS material after link auto-renew\\\":\\\"link_listener_cert_reload_failed\\\",\\\"link disable: service delete failed; local state removed anyway\\\":\\\"link_disable_failed\\\",\\\"link connection error\\\":\\\"link_connection_error\\\",\\\"link listener accept error\\\":\\\"link_listener_accept_failed\\\",\\\"webhook delivery attempt failed\\\":\\\"webhook_delivery_failed\\\",\\\"webhook dispatcher loop failed\\\":\\\"webhook_dispatcher_failed\\\",\\\"addressed delegation authorization failed\\\":\\\"share_authorization_failed\\\",\\\"native share authorization denied\\\":\\\"share_native_authorization_denied\\\",\\\"native share KV put failed\\\":\\\"share_native_kv_put_failed\\\",\\\"share v2 readiness probe failed\\\":\\\"share_v2_readiness_failed\\\",\\\"share v2 is enabled but shareEmail.invitationPublicKey is unset\\\":\\\"share_invitation_key_missing\\\",\\\"configured share invitation key does not match the node's derived signing key\\\":\\\"share_invitation_key_mismatch\\\",\\\"share/v2 policy challenge denied\\\":\\\"share_policy_denied\\\",\\\"failed to read committed hook events\\\":\\\"hook_events_read_failed\\\",\\\"failed to load kv write hook rows\\\":\\\"hook_rows_load_failed\\\",\\\"failed to load kv delete hook rows\\\":\\\"hook_rows_load_failed\\\",\\\"missing committed kv hook row for invocation\\\":\\\"missing_committed_hook_row\\\",\\\"database write committed but webhook enqueue failed\\\":\\\"webhook_enqueue_failed\\\",\\\"tunnel: failed to prepare connection attempt\\\":\\\"tunnel_connection_prepare_failed\\\",\\\"tunnel: no frame within idle timeout; treating connection as dead\\\":\\\"tunnel_idle_timeout\\\",\\\"tunnel: read error\\\":\\\"tunnel_read_failed\\\",\\\"tunnel: dropping malformed frame\\\":\\\"tunnel_malformed_frame\\\",\\\"tunnel: relay sent an error frame\\\":\\\"tunnel_relay_error\\\",\\\"tunnel: failed to write frame\\\":\\\"tunnel_write_failed\\\",\\\"tunnel: failed to record runtime state\\\":\\\"tunnel_state_record_failed\\\",\\\"tunnel: failed to clear runtime state after disable\\\":\\\"tunnel_state_clear_failed\\\",\\\"tunnel authentication rejected\\\":\\\"tunnel_auth_rejected\\\",\\\"network DID resolution enabled: did:web/did:tz fetches use the unhardened ssi client (TC-1080)\\\":\\\"network_did_resolution_enabled\\\"}\\n known = get(codes, [msg]) ?? null\\n if is_string(known) { code = known }\\n if starts_with(msg, \\\"quota service returned \\\") { code = \\\"quota_fallback\\\" }\\nif starts_with(msg, \\\"Failed to get TDX quote: \\\") { code = \\\"attestation_quote_failed\\\" }\\nif starts_with(msg, \\\"quota service returned an invalid body: \\\") { code = \\\"quota_invalid_body\\\" }\\nif starts_with(msg, \\\"dstack socket available but get_info failed: \\\") { code = \\\"dstack_get_info_failed\\\" }\\n }\\n event = if level == \\\"warn\\\" { \\\"node_warning\\\" } else { \\\"node_error\\\" }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": code, \\\"event_count\\\": 1}\\n }\\n} else {\\n ts = string!(j.time)\\n method = string!(j.method)\\n route = string!(j.route)\\n if route == \\\"\\\" { route = \\\"\\\" }\\n if !includes([\\\"GET\\\",\\\"HEAD\\\",\\\"POST\\\",\\\"PUT\\\",\\\"PATCH\\\",\\\"DELETE\\\",\\\"OPTIONS\\\",\\\"\\\"], method) || !includes([\\\"/healthz\\\",\\\"/info\\\",\\\"/version\\\",\\\"/invoke\\\",\\\"/delegate\\\",\\\"/revoke\\\",\\\"/attestation\\\",\\\"/signed/kv\\\",\\\"/signed/kv/\\\",\\\"/admin/quota\\\",\\\"/admin/quota/\\\",\\\"/admin/usage\\\",\\\"/hooks/events\\\",\\\"/hooks/tickets\\\",\\\"/hooks/webhooks\\\",\\\"/hooks/webhooks/\\\",\\\"/delegation/query\\\",\\\"/delegation/status\\\",\\\"/encryption/networks\\\",\\\"/encryption/networks/\\\",\\\"/encryption/networks//revoke\\\",\\\"/encryption/networks//decrypt\\\",\\\"/policy/v3/status\\\",\\\"/policy/v3/status/\\\",\\\"/policy/v3/policies\\\",\\\"/policy/v3/challenges\\\",\\\"/policy/v3/delegations\\\",\\\"/policy/v3/enforcer-bindings\\\",\\\"/policy/v3/deliveries/authorize\\\",\\\"/.well-known/tinycloud/node-keys\\\",\\\"/.well-known/encryption/network/\\\",\\\"/public//kv\\\",\\\"/public//kv/\\\",\\\"/peer/generate/\\\",\\\"/evidences/\\\",\\\"/share/v2/readiness\\\",\\\"/share/v2/policies\\\",\\\"/share/v2/policy/challenges\\\",\\\"/share/v2/policy/session\\\",\\\"/share/v2/invoke\\\",\\\"/share/v2/deliveries/authorize\\\",\\\"/<_s..>\\\",\\\"/public/<_space_id>/kv/<_key..>\\\",\\\"\\\"], route) { abort }\\n status = j.status\\n request_time = j.request_time\\n if !is_integer(status) || !(is_integer(request_time) || is_float(request_time)) { abort }\\n status = int!(status)\\n request_time = to_float!(request_time)\\n if status < 100 || status > 599 || request_time < 0 || request_time > 86400 { abort }\\n out = {\\\"event\\\": \\\"ingress_request\\\", \\\"svc\\\": \\\"ingress\\\", \\\"level\\\": \\\"info\\\", \\\"method\\\": method, \\\"route\\\": route, \\\"status\\\": status, \\\"request_time_seconds\\\": request_time}\\n}\\nif length(ts) > 64 { abort }\\nparsed_ts = parse_timestamp!(ts, format: \\\"%+\\\")\\nout.ts = format_timestamp!(parsed_ts, format: \\\"%Y-%m-%dT%H:%M:%S%.3fZ\\\")\\n. = out\\n\",\"drop_on_error\":true,\"drop_on_abort\":true,\"reroute_dropped\":true},\"gate_counts\":{\"type\":\"remap\",\"inputs\":[\"gate_route.rejected\",\"gate_route._unmatched\",\"allowlist.dropped\",\"event_route._unmatched\"],\"source\":\"reason = .reason\\nif !includes([\\\"malformed_envelope\\\",\\\"unexpected_label\\\",\\\"unlabelled\\\",\\\"non_json\\\",\\\"oversized\\\",\\\"partial\\\",\\\"invalid_fields\\\",\\\"unknown_target\\\",\\\"filtered_level\\\"], reason) { reason = \\\"invalid_fields\\\" }\\n. = {\\\"reason\\\": reason, \\\"count\\\": 1}\",\"drop_on_error\":true,\"drop_on_abort\":true},\"gate_reduce\":{\"type\":\"reduce\",\"inputs\":[\"gate_counts\"],\"group_by\":[\"reason\"],\"end_every_period_ms\":60000,\"expire_after_ms\":75000,\"flush_period_ms\":1000,\"merge_strategies\":{\"count\":\"sum\"}},\"gate_output\":{\"type\":\"remap\",\"inputs\":[\"gate_reduce\"],\"source\":\". = {\\\"ts\\\": format_timestamp!(now(), format: \\\"%Y-%m-%dT%H:%M:%S%.3fZ\\\"), \\\"level\\\": \\\"warn\\\", \\\"event\\\": \\\"logship_gate_summary_total\\\", \\\"svc\\\": \\\"logship\\\", \\\"reason\\\": .reason, \\\"count\\\": .count}\",\"drop_on_error\":true,\"drop_on_abort\":true},\"request_profile\":{\"type\":\"filter\",\"inputs\":[\"allowlist\"],\"condition\":\"\\\"$${TINYCLOUD_LOGSHIP_PROFILE}\\\" == \\\"all_requests\\\" || includes([\\\"node_warning\\\", \\\"node_error\\\"], .event) || (int(.status) ?? 0) >= 400 || (.event == \\\"node_request\\\" && (int(.latency_us) ?? 0) > 1000000) || (.event == \\\"ingress_request\\\" && (to_float(.request_time_seconds) ?? 0.0) > 1.000000)\"},\"event_route\":{\"type\":\"route\",\"inputs\":[\"request_profile\"],\"route\":{\"request\":\".event == \\\"node_request\\\" || .event == \\\"ingress_request\\\"\",\"diagnostic\":\".event == \\\"node_warning\\\" || .event == \\\"node_error\\\"\"}},\"diagnostic_reduce\":{\"type\":\"reduce\",\"inputs\":[\"event_route.diagnostic\"],\"group_by\":[\"event\",\"event_code\",\"level\",\"svc\"],\"end_every_period_ms\":60000,\"expire_after_ms\":75000,\"flush_period_ms\":1000,\"merge_strategies\":{\"event_count\":\"sum\",\"ts\":\"discard\"}},\"diagnostic_output\":{\"type\":\"remap\",\"inputs\":[\"diagnostic_reduce\"],\"source\":\". = {\\\"ts\\\": format_timestamp!(now(), format: \\\"%Y-%m-%dT%H:%M:%S%.3fZ\\\"), \\\"level\\\": .level, \\\"event\\\": .event, \\\"svc\\\": \\\"api\\\", \\\"event_code\\\": .event_code, \\\"event_count\\\": .event_count}\",\"drop_on_error\":true,\"drop_on_abort\":true}},\"sinks\":{\"betterstack\":{\"type\":\"http\",\"inputs\":[\"event_route.request\",\"diagnostic_output\",\"gate_output\"],\"method\":\"post\",\"uri\":\"https://s2795437.us-west-2a.betterstackdata.com/\",\"encoding\":{\"codec\":\"json\"},\"framing\":{\"method\":\"newline_delimited\"},\"compression\":\"gzip\",\"auth\":{\"strategy\":\"bearer\",\"token\":\"SECRET[bs.bs_token]\"},\"batch\":{\"max_bytes\":262144,\"timeout_secs\":1},\"buffer\":{\"type\":\"memory\",\"max_events\":1000,\"when_full\":\"block\"},\"request\":{\"timeout_secs\":10,\"retry_max_duration_secs\":300},\"healthcheck\":{\"enabled\":false}}},\"secret\":{\"bs\":{\"type\":\"directory\",\"path\":\"/var/lib/vector/secrets\",\"remove_trailing_whitespace\":true}}}" + entrypoint: + - /bin/sh + - -ec + - "umask 077\nmkdir -p /var/lib/vector/secrets\ncase \"$$TINYCLOUD_LOGSHIP_PROFILE\" in\n errors_slow|all_requests) ;;\n *) printf '%s\\n' 'logship profile invalid' >&2; exit 78 ;;\nesac\nif [ -z \"$$BETTERSTACK_SOURCE_TOKEN\" ]; then\n printf '%s\\n' 'logship source token missing' >&2\n exit 78\nfi\nprintf '%s' \"$$BETTERSTACK_SOURCE_TOKEN\" > /var/lib/vector/secrets/bs_token\nprintf '%s' \"$$VECTOR_CONFIG_JSON\" > /var/lib/vector/runtime.json\nunset BETTERSTACK_SOURCE_TOKEN VECTOR_CONFIG_JSON\nexec vector --config /var/lib/vector/runtime.json\n" + logging: + driver: json-file + options: + max-size: 10m + max-file: '3' + volumes: cert-data: + +networks: + logship: + driver: bridge diff --git a/docs/runbooks/tc-959-n0-log-shipping.md b/docs/runbooks/tc-959-n0-log-shipping.md new file mode 100644 index 00000000..45314668 --- /dev/null +++ b/docs/runbooks/tc-959-n0-log-shipping.md @@ -0,0 +1,222 @@ +# TC-959 N0: unchanged-binary request logging + +Tracking: [TC-959](https://linear.app/tinycloud-labs/issue/TC-959). This change prepares a compose-only sidecar, not a deployment authorization. Existing operator promotion holds remain in force. No Rust, application image build, database migration, ingress image change, automatic deployment or secret provisioning is part of N0. + +## Immutable runtime + +- Node 1.20.6-dstack, revision `e18578ff9162986ddd813259c60f73866e3e60d1`: `ghcr.io/tinycloudlabs/tinycloud-node@sha256:4bdae4fc232d886bb56bfbce4ec62ed4b8fb4e1369a01f6afb73d06dd68c188f`. +- Existing ingress: `ghcr.io/tinycloudlabs/tinycloud-node-ingress@sha256:63c1c44e2ded5b73a5f174807b91ca677826974df0f9ab3045f6ec87865a5744`. +- Vector 0.59.0: `timberio/vector:0.59.0-alpine@sha256:0e36bc2a290039e9b6a5e92f04bd2f133223506f72d09682c1df16c015172b7a`. + +Only node JSON formatting (`TINYCLOUD_LOG__FORMAT=Json`), Docker logging drivers/labels, and the sidecar are changed. App environment, ingress ports/certificate settings, storage, SSH helper, authentication and routing are otherwise unchanged. The node and ingress do not depend on Vector or join its network. A separate future operator action must provision the source's ingest token in the sealed environment. Compose refuses a missing token; Vector's entrypoint independently fails with a fixed message. Do not read or print any production token to test this change. + +The host Docker daemon sends labelled stdout/stderr over UDP to the Vector listener published **only on 127.0.0.1:12201**. The app cannot select a different destination by including text in a message. Labels select a source; they are not cryptographic authentication. Host/Docker-daemon principals can forge a labelled message and already control the containers. + +Vector has UID/GID 10001, a read-only root, all capabilities dropped, no-new-privileges, CPU 0.5, memory and swap capped at 64 MiB, and an 8 MiB tmpfs. It has no Docker/dstack socket, app data, host files or application-network membership. Its production network needs outbound HTTPS to the configured sink; this is not a general outbound sandbox. Do not equate separate network membership with proof that every host-published app port is unreachable. The local acceptance reports reverse reachability explicitly. + +## Wire contract and privacy boundary + +`log-shipper/sanitize.vrl` reconstructs fresh bounded objects. `scripts/tc959-logship.mjs` compiles route/method/code enums from the vendored canonical schema and embeds the same program in compose. No raw envelope field, arbitrary key, free-text error/message, target, span, SQL, URI/query value, address, DID/wallet, token, body or header reaches the HTTP sink. + +GELF chunk/decompression framing feeds a **bytes** decoder, then explicit VRL +parses the outer JSON and retains only the selected label and short message. +The native GELF JSON codec is deliberately not used: malformed metadata can +make its diagnostic quote the raw value in Vector's console. A real native +regression observed one console canary hit before this change and zero after; +five valid safe request controls reach the local HTTP sink after the change. +Parsing failures become fixed counters; no log-level suppression is used. + +| Event | Fields beyond `ts`, `level`, `event`, `svc` | Delivery policy | +| --- | --- | --- | +| `node_request`, `svc=api` | `method`, canonical `route` template, integer `status`, nonnegative integer `latency_us` | Individually when valid and eligible under the selected request profile; no sampling | +| `ingress_request`, `svc=ingress` | Same method/route/status, distinct numeric `request_time_seconds` | Individually when valid and eligible under the selected request profile; no sampling | +| `node_warning` / `node_error`, `svc=api` | Fixed `event_code`, integer `event_count` | All accepted typed application WARN/ERROR records remain eligible under either profile; grouped counts approximately every 60 seconds | +| `logship_gate_summary_total`, `svc=logship` | Fixed `reason`, integer `count` | Count every rejection that reaches the boundary; emit approximately every 60 seconds per fixed reason | + +### Request profiles + +Sam approved **`errors_slow` as the deployment default**. Compose exposes `TINYCLOUD_LOGSHIP_PROFILE`, defaulting to `errors_slow`; the sidecar entrypoint accepts only `errors_slow` or `all_requests`. The profile is selected at Vector startup, not by per-record environment lookup. + +- `errors_slow`: forward each valid node request with `status >= 400` **or** `latency_us > 1000000`; forward each valid ingress request with `status >= 400` **or** `request_time_seconds > 1.0`. +- Exactly one second does **not** qualify as slow. A request at that equality still qualifies when its status is at least 400. +- `all_requests`: explicitly forward every valid node/ingress request, including 1xx, 2xx and 3xx. It is an operator-selected alternative, not an automatic fallback. + +Both profiles are unsampled: there is no sampler, random selection, throttle or byte-budget drop. All accepted typed WARN/ERROR diagnostics bypass request-profile filtering and retain their existing fixed-code count aggregation. Invalid records still go to content-free gate counts, not to request output. Profile selection does not make transport durable or imply a volume allowance. + +Rocket logs template query parts such as `/attestation?` and `/public//kv?`. Only explicit literal aliases map to canonical paths; arbitrary input is never split at `?` or normalized into a supposedly safe URI. `` is a fixed sentinel. TRACE/CONNECT map to ``; ingress's existing `` route maps to ``. All other unexpected typed fields are rejected and counted, never relayed. + +Every node-labelled JSON WARN/ERROR record with a valid formatter timestamp is eligible, including dependency targets, missing targets and missing message fields. Only the actual `tinycloud` / `tinycloud::*` and `tinycloud_core` / `tinycloud_core::*` targets may map known messages to internal fixed codes. Other targets always become `unclassified`; a dependency cannot borrow an internal code by matching its message. No target/message/error value is copied. Plaintext, malformed JSON/timestamps and oversized records remain content-free gate rejections, not a promise to classify unstructured stderr. + +**No fatal-panic claim:** 1.20.6's panic hook emits plain text, not a typed JSON panic event. Non-JSON panic lines contribute only to a content-free rejection count if received. N0 neither emits nor declares `node_fatal_panic`, and cannot distinguish a panic from other non-JSON output. Request IDs, replacement flags, account/space HMACs, DB timings and trace propagation require N2. N0 ignores and omits them, including forged input values. Shared future contract: canonical `ops/logging/request-id.md` and `request-id-vectors.json`, version 1, at the revision in `log-shipper/canonical.json`. + +## Volume: explicit limit, never hidden sampling + +Run `node log-shipper/budget.mjs `. The decimal **requests-only** allocation is **480,000,000 bytes per 30 days**, not a promise of free ingestion. A through-ingress request whose node and ingress records both qualify contributes one eligible pair. Representative long valid fields cost 198 node bytes + 223 ingress bytes = **421 bytes/eligible pair** including NDJSON newlines. These are exact serialized representative records, not a proven float-serializer ceiling or provider billing formula. + +Under `errors_slow`, node and ingress eligibility are evaluated independently: a slow record on only one side is one event, not a full eligible pair. Measure eligible node and ingress event rates separately where they differ; use their measured byte rates rather than assuming every incoming request contributes a pair. Under `all_requests`, each valid through-ingress request normally contributes a pair. No error fraction, slow-request fraction, gzip discount, HTTP overhead, provider enrichment or retry duplication is assumed. + +| Eligible request pairs/minute | Request bytes / 30 days | Requests-only allocation | +| ---: | ---: | --- | +| 1 | 18,187,200 | Within | +| 26 | 472,867,200 | Within | +| 27 | 491,054,400 | Exceeds | +| 60 | 1,091,232,000 | Exceeds | +| 600 | 10,912,320,000 | Exceeds | + +The representative requests-only rate is **26.39 eligible pairs/minute**, or **26 whole eligible pairs/minute**. A singleton JSON-array framing assumption gives 423 bytes/pair and 26.27/minute; production explicitly uses NDJSON. This is arithmetic, not a claim that either profile fits a budget at actual traffic. + +Diagnostics are **additional**, not secretly subtracted, sampled or dropped. The continuous storm model covers all 52 codes at both severities (104 groups/minute) plus nine rejection groups/minute: **811,339,200 bytes/30 days** with maximum-width count records, separate from the request allocation. Real idle/no-diagnostic traffic is lower; grouped reduce flush timing is not a strict calendar-minute emission ceiling. At 60 **eligible pairs/minute** plus that continuous storm, the model totals 1,902,571,200 bytes. [Public Better Stack pricing](https://betterstack.com/pricing), read 2026-10-16, lists 3 GB/month retained for three days. That allowance is shared with other sources; it is not a service allocation, spend approval or assurance that an account cannot exceed it. Measure actual eligible traffic and billing before an authorized promotion; profile approval alone does not establish budget fit. + +## Known transport and process risks + +- The release formatter has **uncapped lines**. Vector rejects inner messages above 64 KiB after GELF framing and safe envelope parsing, but this does not cap emitter allocation, Docker framing, UDP chunk reassembly or decompression. The socket's configured maximum is 256 KiB; truncated/malformed framing may fail before VRL and cannot be reconstructed or fully counted there. Malformed outer JSON is counted by VRL without native decoder free text. Vector's memory cap bounds its process, not upstream allocations. +- **BEST-EFFORT outage loss is accepted.** GELF/UDP is not lossless or durable. Missing chunks, kernel queues, decoder failures and an absent/paused/OOM shipper can lose messages before the gate. Docker uses a bounded 4 MiB nonblocking queue; overflow can drop logs. This keeps the app independent of sink availability, not loss-free. Acceptance of outage loss does not waive the healthy unpaced 500-request burst gate below. +- Vector has a 1,000-event memory queue with `when_full=block`. HTTP retries/temporary outages can fill it, then backpressure the UDP reader and lose packets upstream. Process restart loses queued events and unfinished diagnostic groups. HTTP retries may duplicate events; no event ID exists in N0 to deduplicate reliably. The UDP source requests `receive_buffer_bytes=8388608`; this is a request, not evidence of the effective kernel socket buffer. Measure the effective buffer in the hosted runner without changing sysctls. Initial isolation remains 0.5 CPU / 64 MiB. +- **Docker logs are intentionally unavailable** for node/ingress after the GELF cutover: raw log caching is disabled. The dstack `/logs` API and `docker logs` are not a fallback. Do not restore raw cache or relay raw startup/panic/tunnel output as a workaround. A separate authorized privileged attach may inspect process output; N0 grants no such production access. +- Gate counters account for processed rejects, not all transport loss. Compare emitted synthetic canary counts, source/sink component metrics where available, and sink arrival; a zero gate count alone does not prove complete delivery or silence health. There is no new production monitor/alert in this PR. +- The sealed token is written only to the sidecar tmpfs and unset before Vector exec. Docker configuration and init's initial environment remain visible to Docker-daemon/equivalent principals. This is not a protection against that host authority. + +## Verification and maintenance + +```sh +node --test log-shipper/budget.test.mjs log-shipper/profile.test.mjs scripts/tc959-docker.test.mjs scripts/tc959-readiness.test.mjs +node scripts/tc959-logship.mjs render-tests /tmp/tc959-errors-slow.json errors_slow +vector test /tmp/tc959-errors-slow.json +node scripts/tc959-logship.mjs render-tests /tmp/tc959-all-requests.json all_requests +vector test /tmp/tc959-all-requests.json +node log-shipper/native-check.mjs /path/to/vector +node scripts/tc959-logship.mjs render-vector /tmp/tc959-vector.json http://127.0.0.1:9599/ +vector validate --no-environment --skip-healthchecks /tmp/tc959-vector.json +``` + +The canonical repo is private. CI verifies the vendored bytes against the reviewed canonical commit/hash pin, the immutable image pins, the process/network constraints, and structural equality of compiled/embedded Vector config without env interpolation (`--env-file /dev/null`). It does not pretend unauthenticated CI can follow private canonical `main`. A schema change must land in a separate canonical PR, update both identical copies and the explicit provenance pin, and pass canonical consumer tests. The canonical active-vendor drift mechanism remains pending until this shipper is merged; promotion must reconcile its activation deliberately. + +After changing VRL/schema/compiler sources, regenerate the embedded `VECTOR_CONFIG_JSON` scalar and rerun the parity gate in CI. Preserve `$${TINYCLOUD_LOGSHIP_PROFILE}` in YAML so Compose passes the literal `${TINYCLOUD_LOGSHIP_PROFILE}` to Vector's startup interpolation. The source program is authoritative; never maintain a second hand-edited VRL copy. The application image is not rebuilt for this validation. + +### Local evidence: failed acceptance, no further host Docker + +No further local host Docker run is authorized. Do not create, restart, recreate or remove Docker resources to extend this evidence. Local evidence is historical and does not replace the hosted-runner acceptance gate. + +Earlier attempts included combined readiness failure and a run with source/gate/sink counters all zero despite healthy node/ingress; each cleaned all labelled resources. Native reproduction delivered 0/3 packets sent before the UDP socket opened and 3/3 after it opened, establishing a startup-loss race but not the cause of a separate Docker failure. Missing metrics are unknown, never fabricated zeroes. + +The **last local run** passed real node+ingress flow, actual loopback port-binding checks, and both app-injection-blocked gates. It then failed after an **unpaced 500-request burst sent by one `printf` in one exec**. The totals below span **controls plus burst**, not the burst alone: + +| Observed stage | Total events | +| --- | ---: | +| Source | 203 | +| Gate | 203 | +| Allowlist | 202 | +| HTTP sink | 201 | +| Capture | 201 | + +At least **299 burst events were not captured**, but the exact missing subset was not persisted. These totals do not establish a root cause. No OOM or startup errors were observed. Remaining continuity and diagnostic gates were not reached. Cleanup reported **0 containers / 0 networks / 0 volumes** and no active proof resources; Clarissa directly acknowledged closure at **18:29:07**, and QA's **18:33** post-sanity confirmed browser starts and stable interfaces. This is a failed burst gate, not an absolute zero-loss result. Sam's remaining proof is CI-only; no further host Docker is authorized. + +### Required GitHub Actions evidence + +The healthy, unpaced, mostly-error **500-request burst must show zero observed loss** in the GitHub Actions runner, under the selected profile and unchanged image pins. Compare the exact eligible request set and capture, not just aggregate totals spanning controls. Outage/paused-sink experiments are separate BEST-EFFORT evidence and may lose records; they must not hide a healthy-burst failure. + +Collect per-stage counters through source, gate, request-profile/allowlist, HTTP sink and capture, plus socket/kernel/cgroup evidence sufficient to distinguish transport, filtering and resource pressure. Record requested and effective UDP receive buffers; do not change sysctls. Preserve 0.5 CPU / 64 MiB initially. Report positive leak controls, actual host port binding, app-injection isolation, continuity and diagnostic aggregation results separately. No local Docker rerun or production requests are authorized for this evidence. + +The `logship / hosted-compose-proof` job runs only on a disposable GitHub-hosted Linux VM, with public immutable images, a synthetic bearer and a complete synthetic Compose environment. It renders this exact production compose, derives container settings, and compares actual image/logging/network/mount/security/resource/entrypoint/configuration values. SQLite/static keys/TEE-off, local ingress bootstrap, dynamic loopback ports and the local capture sink are explicit test substitutions; this is logging-boundary proof, not dstack/TLS deployment proof. The job has read-only repository permission and an `always()` owner-only cleanup step; it never prunes or reads production/GitHub secrets. + +The single-exec burst has 500 distinct status-503 requests with safe latency markers 100000–100499 microseconds: fast errors, not success records made eligible by synthetic slow timings. The proof records exact marker sets, duplicates, timed per-hop plateaus, socket drops/effective receive capacity versus `rmem_max`, and CPU throttling. It also checks known and dependency WARN/ERROR controls by summed occurrence counts, not output rows. An 8 MiB receive buffer is requested; the kernel may cap/double it, so configuration alone is not evidence of effective capacity. + +## Amos: config-only deployment packet and hold + +This packet is preparation only. Keep node Draft PR **#309** Draft until required CI and Astra review pass. **Do not merge, dispatch or deploy now.** There are no Rust/app-image changes. Future operator notices go **directly to Clarissa / the lead**, not to sitrep or roci-board chat. + +### Source, sealed input and exact runtime + +- Better Stack source: **2795437**. +- GitHub production secret **name only**: `PROD_TINYCLOUD_BETTERSTACK_SOURCE_TOKEN` → sealed runtime variable `BETTERSTACK_SOURCE_TOKEN`, supplied only to the sidecar. Never print/read token values or an actual production env file. Compose/entrypoint must reject a missing token; there is no silent raw-log fallback. +- Compose deployment artifact: repository-root **`docker-compose.dstack-postgres.yaml`**, resolved with the exact pinned images above. The actual node image remains **1.20.6-dstack**, revision **`e18578ff9162986ddd813259c60f73866e3e60d1`**; inputs, labels and summaries must remain truthful to that image. +- Node digest remains **`sha256:4bdae4fc232d886bb56bfbce4ec62ed4b8fb4e1369a01f6afb73d06dd68c188f`**; ingress remains **`sha256:63c1c44e2ded5b73a5f174807b91ca677826974df0f9ab3045f6ec87865a5744`**. +- Deploy profile is `TINYCLOUD_LOGSHIP_PROFILE=errors_slow`; switching to `all_requests` requires an explicit operator choice, never an automatic outage response. +- Previously recorded live privacy flags: **`public_logs=false`, `public_sysinfo=false`, `public_tcbinfo=true`**. These supplied observations are not a new production check. Preserve the private-log/private-sysinfo settings; do not silently change TCB-info exposure. + +### Before/after compose identity and rollback + +The preserved **current pre-N0** rollback compose is **`/home/tinycloud/scratch/tc959-n0-release/rollback-compose.yaml`**, mode **0600**, with no inline secret values. Local metadata/hash inspection confirmed mode 0600 and raw-file SHA-256 **`df239749ca0a9c09893a855ae2a8abb94090b8556515ad002105c58ac91f4c91`** without reading its contents or any env file. + +Keep these identities distinct: + +| Identity | Recorded value / meaning | +| --- | --- | +| Before: verifier `docker_compose_file` / hash | Raw preserved pre-N0 compose: `df239749ca0a9c09893a855ae2a8abb94090b8556515ad002105c58ac91f4c91` | +| Before: application `compose_hash` | `bfe9028a58b23238188aa7d70b82282a7cd6414cd83dcc47a3b295c6f64fe2f8`; a distinct reported identity, not the raw-file hash | +| After: current profile-enabled raw compose | `ca110b0bae6d5a06a1002fb80df3f71cffec11659c9f9dbfa5d72624735546f6`; bind this artifact to the final reviewed PR head before any promotion | + +The raw after hash identifies the profile-enabled compose, not deployment approval. Record its final reviewed PR head and required CI evidence in the officer handoff. Do not infer a raw-file hash from the distinct application-reported compose hash. + +### Approved workflow contract: no deployment authorization + +The canonical release contract is [#313 `docs/releasing.md` at `63d11dd67e07378acb9213ecd8e3b895c7be5931`](https://github.com/TinyCloudLabs/tinycloud-node/blob/63d11dd67e07378acb9213ecd8e3b895c7be5931/docs/releasing.md), approved by the same Astra in [comment 6226203726](https://github.com/TinyCloudLabs/tinycloud-node/pull/313#issuecomment-6226203726). It supersedes the earlier N0-specific quota snapshot input and the separate #310 candidate packet. + +**HOLD:** #313 remains unmerged until Holden/Sam provision the runner-only `PROD_TINYCLOUD_BILLING_ADMIN_SECRET`. This document does not provision or read it. The billing credential never belongs in the CVM environment or `allowed_envs`. Workflow/security recovery must land as the approved combined lineage first; the N0 sidecar compose belongs only to a later separately approved logging window. No command below is merge, privacy-choice or dispatch authorization. + +| Operation | Required inputs / approval | Effect | +| --- | --- | --- | +| Every `deploy_phala=true` dispatch | Explicit `authorize_quota_values=true` and fresh authorization for the reviewed values and authority in `ops/quota-overrides.json` | One-dispatch authorization, not an N0-only snapshot or evergreen permission to reuse old values | +| Current-compose promotion or same-image recovery | Recorded immutable image identity; no captured-rollback/privacy inputs | Uses current main compose and preserves its current logging policy | +| Captured pre-N0 compose rollback | `rollback_pre_n0=true`, plus explicit `rollback_privacy_mode` matching Sam's approved repository variable `TC959_ROLLBACK_PRIVACY_MODE` | Uses the fixed-path/hash rollback source and the selected logging policy | + +Missing quota authorization or unknown authority fails before compose, CVM or whitelist mutation. Sealed-runtime preflight remains mandatory on forward, recovery and rollback paths. Quota reconciliation follows the final environment operation and required version/ingress health, before ancillary Policy probes; attempted restart without verified reconciliation is fatal **`OVERRIDES UNVERIFIED`**. See the pinned canonical guide for the node-override/billing authority checks and operator fallback. + +#### Current-compose same-image promotion or recovery + +After the combined workflow is reviewed/landed, a named operator is approved and fresh quota-values authorization exists, the canonical command is: + +```sh +gh workflow run docker.yml -R TinyCloudLabs/tinycloud-node --ref main \ + -f deploy_phala=true \ + -f authorize_quota_values=true \ + -f image_version=1.20.6 \ + -f deploy_image_digest=sha256:4bdae4fc232d886bb56bfbce4ec62ed4b8fb4e1369a01f6afb73d06dd68c188f \ + -f rollback_image_version=1.20.6 \ + -f rollback_image_revision=e18578ff9162986ddd813259c60f73866e3e60d1 \ + -f sql_identity_fence=false +``` + +This is not a captured compose rollback and does not automatically install the sidecar: it uses the current main compose, whether approved pre-N0 or exact reviewed N0 bytes. Served/OCI identity remains **1.20.6-dstack / e18578ff9162986ddd813259c60f73866e3e60d1**; it is not an unrelated checkout crate version. + +#### Captured pre-N0 rollback: explicit privacy choice + +The reviewed repository source is `ops/rollback/pre-n0-compose.yaml`, byte-identical to the captured raw hash `df239749ca0a9c09893a855ae2a8abb94090b8556515ad002105c58ac91f4c91`. Fixed-path/hash validation rejects other paths, symlinks and source drift. Selecting the same node digest alone is **not** this compose rollback. + +**There is no automatic privacy choice.** `unselected` refuses rollback. Sam must explicitly select the policy; Amos records it in repository variable `TC959_ROLLBACK_PRIVACY_MODE`, and the dispatch's `rollback_privacy_mode` must match. Neither conditional command chooses or authorizes that policy. + +If Sam selects **`keep-json-file`**, retain the captured node/ingress 3×50 MB local logging policy: + +```sh +gh workflow run docker.yml -R TinyCloudLabs/tinycloud-node --ref main \ + -f deploy_phala=true \ + -f authorize_quota_values=true \ + -f rollback_pre_n0=true \ + -f rollback_privacy_mode=keep-json-file \ + -f image_version=1.20.6 \ + -f deploy_image_digest=sha256:4bdae4fc232d886bb56bfbce4ec62ed4b8fb4e1369a01f6afb73d06dd68c188f \ + -f rollback_image_version=1.20.6 \ + -f rollback_image_revision=e18578ff9162986ddd813259c60f73866e3e60d1 \ + -f sql_identity_fence=false +``` + +If Sam selects **`stop-future-local-logs`**, the reviewed derivative changes only the node and ingress logging drivers to `none`: + +```sh +gh workflow run docker.yml -R TinyCloudLabs/tinycloud-node --ref main \ + -f deploy_phala=true \ + -f authorize_quota_values=true \ + -f rollback_pre_n0=true \ + -f rollback_privacy_mode=stop-future-local-logs \ + -f image_version=1.20.6 \ + -f deploy_image_digest=sha256:4bdae4fc232d886bb56bfbce4ec62ed4b8fb4e1369a01f6afb73d06dd68c188f \ + -f rollback_image_version=1.20.6 \ + -f rollback_image_revision=e18578ff9162986ddd813259c60f73866e3e60d1 \ + -f sql_identity_fence=false +``` + +That derivative's raw SHA256 is `315ceca54bf8bfefe2b395b4097fe38ed8ec847fa0688bc873220bd65efc99ec`. **Stopping future logs does not delete existing files. There is no truncation/deletion path.** Any destructive action requires separate explicit authorization and a reviewed procedure. Keeping prior json-file logging may restore raw retention; never install a stealth fallback. + +Privacy inputs are rollback-only and mutually exclusive with ordinary current-compose promotion. Preserve the private logs/sysinfo settings and the previously recorded logs/sysinfo/tcbinfo flags **false/false/true**. Keep actual versions/revisions in main history; no bypass flags or retired refs. A binary rollback across a database schema migration still needs its separate DB-safety decision. + +Before any later authorized promotion, reconcile canonical/vendor activation, required exact-head CI/reviews, final artifact hash, the approved logging window and measured volume allowance, fresh quota authority/values and sealed-token presence without exposing it. Record source/sink arrival with positive leak controls. No production checks, Phala API calls, secret reads, merge, dispatch or deployment are authorized by this packet. diff --git a/log-shipper/budget.mjs b/log-shipper/budget.mjs new file mode 100644 index 00000000..fdd6fc27 --- /dev/null +++ b/log-shipper/budget.mjs @@ -0,0 +1,87 @@ +import { readFileSync } from 'node:fs'; +import { pathToFileURL } from 'node:url'; + +const schema = JSON.parse(readFileSync(new URL('./fields.json', import.meta.url), 'utf8')).services['tinycloud-node']; +const longest = values => values.reduce((chosen, value) => Buffer.byteLength(value) > Buffer.byteLength(chosen) ? value : chosen, ''); + +/** Thirty days, not a calendar-month or billing-period guarantee. */ +export const MINUTES_30_DAYS = 30 * 24 * 60; +/** Decimal 0.48 GB allocated to requests only; diagnostic reserve is additional. */ +export const REQUEST_ALLOCATION_BYTES = 480_000_000; + +const common = { level: 'info', ts: '9999-12-31T23:59:59.999Z' }; +const request = { + method: longest(schema.fields.method.values), route: longest(schema.fields.route.values), + status: schema.fields.status.max, +}; + +/** + * Representative worst-valid N0 wire records: longest schema strings, maximum + * integer widths, and a long round-trippable fractional ingress duration. + * N2 UUIDs/hashes are reserved by the canonical schema but are NOT emitted in N0. + * Bytes below are exact for these records, not a proven Vector float-serializer + * upper bound or a fixed event-size guard. Actual ingestion/billing can differ. + */ +export const representativeEvents = Object.freeze({ + node: Object.freeze({ ...common, event: 'node_request', svc: 'api', ...request, latency_us: schema.fields.latency_us.max }), + ingress: Object.freeze({ ...common, event: 'ingress_request', svc: 'ingress', ...request, request_time_seconds: 0.0000010000000000000002 }), + diagnostic: Object.freeze({ level: 'warn', ts: common.ts, event: 'node_warning', svc: 'api', event_code: longest(schema.fields.event_code.values), event_count: schema.fields.event_count.max }), + gate: Object.freeze({ level: 'warn', ts: common.ts, event: 'logship_gate_summary_total', svc: 'logship', reason: longest(schema.fields.reason.values), count: schema.fields.count.max }), +}); + +/** + * NDJSON charges one newline per event. json-array conservatively charges a + * singleton [event] per event (two brackets). A real N-event JSON array costs + * sum(object bytes) + N + 1 (commas and brackets), so batching saves N - 1 bytes + * versus this conservative singleton estimate. No HTTP/TLS headers, gzip savings, + * provider enrichment, retries, or billing-specific overhead are assumed. + */ +export function serializedEventBytes(event, framing = 'ndjson') { + if (framing !== 'ndjson' && framing !== 'json-array') throw new RangeError('unsupported framing'); + return Buffer.byteLength(JSON.stringify(event)) + (framing === 'ndjson' ? 1 : 2); +} + +/** + * Full individual-request retention: each request costs one node plus one ingress + * event. This is arithmetic only: no sampling, aggregation, throttle, or sink cap. + * Diagnostic and gate group-rate assumptions reserve additional bytes separately; + * defaults are conservative planning rates, NOT guaranteed emission ceilings. + * The shared Better Stack 3 GB free tier is shared with other sources and is NOT + * guaranteed. Traffic above the sustainable rate needs more allocation or spend, + * not hidden request dropping. UDP and bounded queues can still lose transport. + */ +export function calculateBudget({ + requestsPerMinute = 1, + diagnosticEventsPerMinute = schema.fields.event_code.values.length * 2, + gateEventsPerMinute = schema.fields.reason.values.length, + allocationBytes = REQUEST_ALLOCATION_BYTES, + framing = 'ndjson', +} = {}) { + for (const [name, value] of Object.entries({ requestsPerMinute, diagnosticEventsPerMinute, gateEventsPerMinute, allocationBytes })) { + if (typeof value !== 'number' || !Number.isFinite(value) || value < 0) throw new RangeError(`${name} must be finite non-negative`); + } + const eventBytes = Object.fromEntries(Object.entries(representativeEvents).map(([name, event]) => [name, serializedEventBytes(event, framing)])); + const requestPairBytes = eventBytes.node + eventBytes.ingress; + const requestBytes30Days = requestsPerMinute * requestPairBytes * MINUTES_30_DAYS; + const diagnosticReserveBytes30Days = (diagnosticEventsPerMinute * eventBytes.diagnostic + gateEventsPerMinute * eventBytes.gate) * MINUTES_30_DAYS; + const sustainableRequestsPerMinute = allocationBytes / (requestPairBytes * MINUTES_30_DAYS); + return { + sizeBasis: 'exact JSON bytes of representative worst-valid N0 events; not a hard serialized-size ceiling', + framing, eventBytes, requestPairBytes, requestsPerMinute, allocationBytes, + requestBytes30Days, diagnosticReserveBytes30Days, + totalBytes30Days: requestBytes30Days + diagnosticReserveBytes30Days, + sustainableRequestsPerMinute, + sustainableWholeRequestsPerMinute: Math.floor(sustainableRequestsPerMinute), + withinRequestAllocation: requestBytes30Days <= allocationBytes, + diagnosticEventsPerMinute, gateEventsPerMinute, + freeTierGuaranteed: false, + }; +} + +if (process.argv[1] && import.meta.url === pathToFileURL(process.argv[1]).href) { + const requestsPerMinute = process.argv[2] === undefined ? 1 : Number(process.argv[2]); + console.log(JSON.stringify({ + ndjson: calculateBudget({ requestsPerMinute }), + jsonArray: calculateBudget({ requestsPerMinute, framing: 'json-array' }), + }, null, 2)); +} diff --git a/log-shipper/budget.test.mjs b/log-shipper/budget.test.mjs new file mode 100644 index 00000000..c4fa4ebb --- /dev/null +++ b/log-shipper/budget.test.mjs @@ -0,0 +1,102 @@ +import assert from 'node:assert/strict'; +import { readFile } from 'node:fs/promises'; +import test from 'node:test'; +import { calculateBudget, representativeEvents, serializedEventBytes, MINUTES_30_DAYS, REQUEST_ALLOCATION_BYTES } from './budget.mjs'; + +const fields = JSON.parse(await readFile(new URL('./fields.json', import.meta.url), 'utf8')); +const nodeSchema = fields.services['tinycloud-node']; + +test('request representatives use the schema longest route and method, with no N2 identifiers', () => { + const routes = nodeSchema.fields.route.values; + const methods = nodeSchema.fields.method.values; + for (const row of [representativeEvents.node, representativeEvents.ingress]) { + assert.equal(row.route.length, Math.max(...routes.map(value => value.length))); + assert.equal(row.method.length, Math.max(...methods.map(value => value.length))); + assert.ok(routes.includes(row.route)); + assert.ok(methods.includes(row.method)); + assert.equal(row.ts.length, 24); + for (const key of ['request_id', 'account_hash', 'space_hash']) assert.equal(Object.hasOwn(row, key), false); + } + assert.equal(representativeEvents.node.event, 'node_request'); + assert.equal(representativeEvents.node.latency_us, Number.MAX_SAFE_INTEGER); + assert.equal(representativeEvents.ingress.event, 'ingress_request'); + assert.ok(representativeEvents.ingress.request_time_seconds >= 0 && representativeEvents.ingress.request_time_seconds <= 86400); +}); + +test('exact serialized bytes account for newlines or singleton JSON array overhead', () => { + for (const row of Object.values(representativeEvents)) { + assert.equal(serializedEventBytes(row, 'ndjson'), Buffer.byteLength(`${JSON.stringify(row)}\n`)); + assert.equal(serializedEventBytes(row, 'json-array'), Buffer.byteLength(JSON.stringify([row]))); + } + assert.equal(MINUTES_30_DAYS, 43200); + assert.equal(REQUEST_ALLOCATION_BYTES, 480_000_000); + assert.throws(() => serializedEventBytes({}, 'raw'), /framing/); +}); + +test('every request costs both full events; increasing traffic is linear without a sampler', () => { + const one = calculateBudget({ requestsPerMinute: 1, diagnosticEventsPerMinute: 0, gateEventsPerMinute: 0 }); + const many = calculateBudget({ requestsPerMinute: 10000, diagnosticEventsPerMinute: 0, gateEventsPerMinute: 0 }); + const pair = serializedEventBytes(representativeEvents.node, 'ndjson') + serializedEventBytes(representativeEvents.ingress, 'ndjson'); + assert.equal(one.requestPairBytes, pair); + assert.equal(one.requestBytes30Days, pair * 43200); + assert.equal(many.requestBytes30Days, one.requestBytes30Days * 10000); + assert.equal(many.totalBytes30Days, many.requestBytes30Days); + assert.equal(many.withinRequestAllocation, false); + assert.equal(one.freeTierGuaranteed, false); +}); + +test('allocation boundary is sustainable requests per minute, not a throttle', () => { + for (const framing of ['ndjson', 'json-array']) { + const base = calculateBudget({ requestsPerMinute: 0, framing, diagnosticEventsPerMinute: 0, gateEventsPerMinute: 0 }); + const rate = REQUEST_ALLOCATION_BYTES / (base.requestPairBytes * MINUTES_30_DAYS); + assert.equal(base.sustainableRequestsPerMinute, rate); + assert.equal(base.sustainableWholeRequestsPerMinute, Math.floor(rate)); + const fits = calculateBudget({ requestsPerMinute: Math.floor(rate), framing, diagnosticEventsPerMinute: 0, gateEventsPerMinute: 0 }); + const exceeds = calculateBudget({ requestsPerMinute: Math.floor(rate) + 1, framing, diagnosticEventsPerMinute: 0, gateEventsPerMinute: 0 }); + assert.equal(fits.withinRequestAllocation, true); + assert.equal(exceeds.withinRequestAllocation, false); + } +}); + +test('fixed diagnostic reserve is separate from the request allocation', () => { + const budget = calculateBudget({ requestsPerMinute: 1, diagnosticEventsPerMinute: 53, gateEventsPerMinute: 9 }); + assert.equal(budget.diagnosticReserveBytes30Days, + 43200 * (53 * serializedEventBytes(representativeEvents.diagnostic, 'ndjson') + 9 * serializedEventBytes(representativeEvents.gate, 'ndjson'))); + assert.equal(budget.totalBytes30Days, budget.requestBytes30Days + budget.diagnosticReserveBytes30Days); + assert.equal(budget.sustainableRequestsPerMinute, REQUEST_ALLOCATION_BYTES / (budget.requestPairBytes * 43200)); + const noTraffic = calculateBudget({ requestsPerMinute: 0 }); + assert.equal(noTraffic.requestBytes30Days, 0); + assert.ok(noTraffic.diagnosticReserveBytes30Days > 0); + assert.equal(noTraffic.totalBytes30Days, noTraffic.diagnosticReserveBytes30Days); +}); + +test('diagnostic storm reserve covers every code at both severity levels', () => { + const budget = calculateBudget({ requestsPerMinute: 0 }); + const maximumGroups = nodeSchema.fields.event_code.values.length * 2; + assert.ok(budget.diagnosticEventsPerMinute >= maximumGroups); + assert.ok(budget.diagnosticReserveBytes30Days >= maximumGroups * serializedEventBytes(representativeEvents.diagnostic) * MINUTES_30_DAYS); +}); + +test('invalid numeric budgets fail rather than hiding impossible volume', () => { + for (const field of ['requestsPerMinute', 'diagnosticEventsPerMinute', 'gateEventsPerMinute', 'allocationBytes']) { + for (const value of [-1, NaN, Infinity, '1']) assert.throws(() => calculateBudget({ [field]: value }), /finite non-negative/); + } + assert.throws(() => calculateBudget({ framing: 'raw' }), /framing/); + const zero = calculateBudget({ requestsPerMinute: 0, allocationBytes: 0 }); + assert.equal(zero.sustainableRequestsPerMinute, 0); + assert.equal(zero.withinRequestAllocation, true); +}); + +test('diagnostic mapping uses only closed schema codes and cannot assert a panic', async () => { + const diagnostics = JSON.parse(await readFile(new URL('./diagnostics.json', import.meta.url), 'utf8')); + const codes = nodeSchema.fields.event_code.values; + assert.equal(diagnostics.fallback, 'unclassified'); + for (const code of [...Object.values(diagnostics.exact), ...Object.values(diagnostics.prefix), diagnostics.fallback]) { + assert.ok(codes.includes(code)); + assert.equal(code.includes('panic'), false); + } + assert.equal(Object.hasOwn(diagnostics.exact, 'node fatal panic'), false); + assert.equal(diagnostics.exact['invalid link bind address; LAN listener not started'], 'link_bind_invalid'); + assert.ok(diagnostics.exact['network DID resolution enabled: did:web/did:tz fetches use the unhardened ssi client (TC-1080)']); + assert.ok(diagnostics.exact['link auto-renew succeeded but no state.json found; skipping cert hot-reload']); +}); diff --git a/log-shipper/canonical.json b/log-shipper/canonical.json new file mode 100644 index 00000000..afeb3816 --- /dev/null +++ b/log-shipper/canonical.json @@ -0,0 +1,6 @@ +{ + "repo": "samgbafa/tinycloud-dev", + "revision": "76bd10752a52f179ac2a49214f488236d02f8192", + "path": "ops/logging/fields.json", + "sha256": "95944326fb37a7e7d3cddae16b0d8a722076d7dd9e20700ee565a73a9a567e15" +} diff --git a/log-shipper/cases.mjs b/log-shipper/cases.mjs new file mode 100644 index 00000000..6b65d4c0 --- /dev/null +++ b/log-shipper/cases.mjs @@ -0,0 +1,94 @@ +// Synthetic inputs only. Native Vector evaluates every assertion after the full boundary. +export const canary = 'TC959_SYNTHETIC_Bearer_eyJhbGciOiJub25lIn0.email@example.test.did:pkh:0xdeadbeef'; +export const timestamp = '2026-10-16T12:00:00.000Z'; +export const nodeRequest = (fields = {}) => ({ timestamp, level: 'INFO', target: 'tinycloud::request', fields: { message: 'request', method: 'POST', route: '/invoke', status: 200, latency_us: 1234, ...fields } }); +export const ingressRequest = (fields = {}) => ({ time: timestamp, method: 'GET', route: '/healthz', status: 200, request_time: 0.012, bytes: 2, upstream_status: '200', ...fields }); +export const envelope = (value, label = 'tinycloud-node') => ({ message: typeof value === 'string' ? value : JSON.stringify(value), '_tc.logship': label, host: canary, full_message: canary, container_id: canary }); +const safe = '!contains(encode_json(.), "TC959_SYNTHETIC") && !exists(.message) && !exists(.target) && !exists(.host) && !exists(.request_id) && !exists(.request_id_replaced) && !exists(.account_hash) && !exists(.space_hash)'; +// Vector test log_fields keys are paths; quote the literal dotted GELF label. +const logFields = input => Object.fromEntries(Object.entries(input).map(([key, value]) => [key === '_tc.logship' ? '."_tc.logship"' : key, value])); +const check = (name, input, assertion, insertAt = 'logship_gate') => ({ name, inputs: [{ insert_at: insertAt, type: 'log', log_fields: logFields(input) }], outputs: [{ extract_from: 'allowlist', conditions: [{ type: 'vrl', source: `assert!(${assertion})\nassert!(${safe})` }] }] }); +const reject = (name, input, insertAt = 'logship_gate') => ({ name, inputs: [{ insert_at: insertAt, type: 'log', log_fields: logFields(input) }], no_outputs_from: ['allowlist'], outputs: [{ extract_from: 'gate_counts', conditions: [{ type: 'vrl', source: 'assert!(.count == 1)\nassert!(!contains(encode_json(.), "TC959_SYNTHETIC"))' }] }] }); +export const vectorTests = [ + check('INFO node request validates as a safe individual event', envelope(nodeRequest()), '.event == "node_request" && .svc == "api" && .method == "POST" && .route == "/invoke" && .status == 200 && .latency_us == 1234'), + check('unmatched request keeps fixed sentinel', envelope(nodeRequest({ route: '', status: 404, latency_us: 0 })), '.event == "node_request" && .route == "" && .status == 404 && .latency_us == 0'), + check('HEAD is not rewritten to GET', envelope(nodeRequest({ method: 'HEAD' })), '.method == "HEAD"'), + check('Rocket query template is normalized without values', envelope(nodeRequest({ route: '/attestation?' })), '.route == "/attestation"'), + check('ingress 3xx is a per-request event', envelope(ingressRequest({ status: 304 }), 'tinycloud-ingress'), '.event == "ingress_request" && .status == 304 && .request_time_seconds == 0.012'), + check('ingress other is a fixed sentinel', envelope(ingressRequest({ route: '', method: '' }), 'tinycloud-ingress'), '.route == "" && .method == ""'), + check('long latency is not dropped by byte budget', envelope(nodeRequest({ route: '/policy/v3/deliveries/authorize', latency_us: 9007199254740991 })), '.latency_us == 9007199254740991 && .event == "node_request"'), + ...['TRACE', 'CONNECT'].map(method => check(`${method} request uses the bounded other method`, envelope(nodeRequest({ method, route: '', status: 404 })), '.event == "node_request" && .method == "" && .status == 404')), + check('unknown extras and even valid N2 correlation fields are discarded', envelope({ ...nodeRequest({ authorization: canary, nested: { sql: canary }, request_id: 'a8098c1a-f86e-4b1f-92a7-4b50b53ec932', request_id_replaced: true, account_hash: 'a'.repeat(64), space_hash: '0'.repeat(64) }), span: { account: canary }, spans: [{ request_id: canary }] }), '.event == "node_request" && !exists(.authorization) && !exists(.nested) && !exists(.span)'), + check('known warning strips all free text', envelope({ timestamp, level: 'WARN', target: 'tinycloud::runtime', fields: { message: 'invalid link bind address; LAN listener not started', err: canary, bind: canary } }), '.event == "node_warning" && .event_code == "link_bind_invalid" && .event_count == 1'), + check('unmatched warning becomes typed unclassified', envelope({ timestamp, level: 'WARN', target: 'tinycloud::tunnel::connection', fields: { message: canary, remote: canary } }), '.event == "node_warning" && .event_code == "unclassified" && .event_count == 1'), + check('application error remains typed without error value', envelope({ timestamp, level: 'ERROR', target: 'tinycloud::share_email', fields: { message: 'native share KV put failed', failure: canary } }), '.event == "node_error" && .event_code == "share_native_kv_put_failed" && .event_count == 1'), + check('dependency warning is a fixed unclassified diagnostic', envelope({ timestamp, level: 'WARN', target: 'hyper::proto', fields: { message: canary, error: canary } }), '.event == "node_warning" && .event_code == "unclassified" && .event_count == 1'), + check('dependency error without a message still counts', envelope({ timestamp, level: 'ERROR', target: 'sqlx::pool', fields: { error: canary } }), '.event == "node_error" && .event_code == "unclassified" && .event_count == 1'), + check('warning without a target or fields still counts', envelope({ timestamp, level: 'WARN' }), '.event == "node_warning" && .event_code == "unclassified" && .event_count == 1'), + check('dependency cannot borrow an internal diagnostic code', envelope({ timestamp, level: 'ERROR', target: 'dependency', fields: { message: 'native share KV put failed' } }), '.event == "node_error" && .event_code == "unclassified" && .event_count == 1'), + check('request-target warning is not discarded as an INFO request', envelope({ timestamp, level: 'WARN', target: 'tinycloud::request', fields: { message: canary } }), '.event == "node_warning" && .event_code == "unclassified" && .event_count == 1'), + reject('raw URI in route is rejected', envelope(nodeRequest({ route: `/signed/kv/${canary}` }))), + reject('query value is not a template', envelope(nodeRequest({ route: `/attestation?nonce=${canary}` }))), + reject('forbidden method is rejected', envelope(nodeRequest({ method: canary }))), + ...[-1, 1.5, '200', 600].map(status => reject(`invalid status ${status}`, envelope(nodeRequest({ status })))), + ...[-1, 0.5, '1234', null].map(latency_us => reject(`invalid latency ${latency_us}`, envelope(nodeRequest({ latency_us })))), + reject('non-JSON panic is counted not claimed fatal', envelope(`thread main panicked: ${canary}`)), + reject('nested method cannot escape', envelope(nodeRequest({ method: { token: canary } }))), + reject('unlabelled line is rejected', { message: JSON.stringify(nodeRequest()) }), + reject('unexpected label is rejected', envelope(nodeRequest(), canary)), + ...['ptx-dev', 'ptx-dev-worker', 'ptx-batch'].map(label => reject(`${label} cannot enter the node pipeline`, envelope(nodeRequest(), label))), + reject('typed ptx JSON cannot enter through a node label', envelope({ event: 'ptx_realtime_request', level: 'info', stage: canary, request_id: 'a8098c1a-f86e-4b1f-92a7-4b50b53ec932' })), + reject('partial line is rejected', { ...envelope(nodeRequest()), partial_message: true }), + reject('oversized uncapped input is counted', envelope(JSON.stringify({ ...nodeRequest(), extra: canary.repeat(2000) }))), + reject('forged request target is rejected', envelope({ ...nodeRequest(), target: canary })), + reject('bad ingress timing is rejected', envelope(ingressRequest({ request_time: canary }), 'tinycloud-ingress')), + check('wire GELF metadata is discarded before inner request parsing', { message: JSON.stringify({ version: '1.1', host: canary, level: canary, full_message: canary, short_message: JSON.stringify(nodeRequest()), '_tc.logship': 'tinycloud-node' }) }, '.event == "node_request" && .latency_us == 1234', 'gelf_envelope'), + reject('malformed outer GELF JSON is counted without decoder free text', { message: `{"version":"1.1","short_message":"${canary}` }, 'gelf_envelope'), + reject('nested GELF short message cannot escape', { message: JSON.stringify({ version: '1.1', short_message: { token: canary }, '_tc.logship': 'tinycloud-node' }) }, 'gelf_envelope'), + { + name: 'warning reduction conserves both occurrences without relaying text', + inputs: [1, 2].map(() => ({ insert_at: 'diagnostic_reduce', type: 'log', log_fields: { ts: timestamp, level: 'warn', event: 'node_warning', svc: 'api', event_code: 'unclassified', event_count: 1 } })), + outputs: [{ extract_from: 'diagnostic_output', conditions: [{ type: 'vrl', source: 'assert!(.event_count == 2)\nassert!(.event_code == "unclassified")\nassert!(length(keys(.)) == 6)' }] }], + }, + { + name: 'gate reduction conserves rejected occurrences by fixed reason', + inputs: [1, 2].map(() => ({ insert_at: 'gate_reduce', type: 'log', log_fields: { reason: 'non_json', count: 1 } })), + outputs: [{ extract_from: 'gate_output', conditions: [{ type: 'vrl', source: 'assert!(.count == 2)\nassert!(.reason == "non_json")\nassert!(length(keys(.)) == 6)' }] }], + }, +]; + +/** Exercise the actual routed boundary, not just pre-profile sanitization. */ +export function requestProfileTests(profile) { + const requestCase = (name, payload, label, eligible) => { + const node = label === 'tinycloud-node'; + const status = node ? payload.fields.status : payload.status; + const timing = node ? `.latency_us == ${payload.fields.latency_us}` : `.request_time_seconds == ${payload.request_time}`; + const fixture = { name: `${profile}: ${name}`, inputs: [{ insert_at: 'logship_gate', type: 'log', log_fields: logFields(envelope(payload, label)) }] }; + return profile === 'all_requests' || eligible + ? { ...fixture, outputs: [{ extract_from: 'event_route.request', conditions: [{ type: 'vrl', source: `assert!(.status == ${status} && ${timing})\nassert!(${safe})` }] }] } + : { ...fixture, no_outputs_from: ['event_route.request'] }; + }; + return [ + ...[ + ['node fast success', 200, 999999, false], + ['node exact one second', 200, 1000000, false], + ['node above one second', 200, 1000001, true], + ['node status399 fast', 399, 0, false], + ['node status400 fast', 400, 0, true], + ['node error at one second', 503, 1000000, true], + ].map(([name, status, latency_us, eligible]) => requestCase(name, nodeRequest({ status, latency_us }), 'tinycloud-node', eligible)), + ...[ + ['ingress fast success', 200, 0.999999, false], + ['ingress exact one second', 200, 1.0, false], + ['ingress above one second', 200, 1.000001, true], + ['ingress status399 fast', 399, 0, false], + ['ingress status400 fast', 400, 0, true], + ['ingress error at one second', 503, 1.0, true], + ].map(([name, status, request_time, eligible]) => requestCase(name, ingressRequest({ status, request_time }), 'tinycloud-ingress', eligible)), + ...['WARN', 'ERROR'].map(level => ({ + name: `${profile}: dependency ${level} always eligible`, + inputs: [{ insert_at: 'logship_gate', type: 'log', log_fields: logFields(envelope({ timestamp, level, target: 'dependency', fields: { message: canary, status: 200, latency_us: 0 } })) }], + outputs: [{ extract_from: 'event_route.diagnostic', conditions: [{ type: 'vrl', source: `assert!(.event_count == 1 && .event_code == "unclassified")\nassert!(${safe})` }] }], + })), + ]; +} diff --git a/log-shipper/diagnostics.json b/log-shipper/diagnostics.json new file mode 100644 index 00000000..1c4cd00c --- /dev/null +++ b/log-shipper/diagnostics.json @@ -0,0 +1,59 @@ +{ + "exact": { + "invocation replay insert failed": "invocation_replay_insert_failed", + "invocation replay cleanup failed": "invocation_replay_cleanup_failed", + "share-v2 local-tee feature active: deriving a deterministic, non-attested TEE identity from node key material": "share_local_tee_identity", + "retention: delivered hook delivery prune failed": "retention_hook_delivery_prune_failed", + "retention: dead-letter hook delivery prune failed": "retention_dead_letter_prune_failed", + "retention: signed KV ticket prune failed": "retention_signed_ticket_prune_failed", + "failed to load tunnel state; tunnel not started": "tunnel_state_load_failed", + "invalid loopback API address; tunnel not started": "tunnel_address_invalid", + "failed to load link state; LAN listener not started": "link_state_load_failed", + "invalid link bind address; LAN listener not started": "link_bind_invalid", + "invalid loopback API address; LAN listener not started": "link_address_invalid", + "failed to bind link LAN listener; LAN listener not started": "link_bind_failed", + "failed to build TLS config; LAN listener not started": "link_tls_config_failed", + "link LAN listener exited with error": "link_listener_error", + "failed to record link listener bind state": "link_listener_state_write_failed", + "failed to record link listener bind failure": "link_bind_state_write_failed", + "failed to load config for auto-renew": "link_auto_renew_config_failed", + "link auto-renew failed": "link_auto_renew_failed", + "failed to hot-reload renewed link cert": "link_cert_reload_failed", + "link auto-renew succeeded but no state.json found; skipping cert hot-reload": "link_cert_state_missing", + "failed to reload TLS material after link auto-renew": "link_listener_cert_reload_failed", + "link disable: service delete failed; local state removed anyway": "link_disable_failed", + "link connection error": "link_connection_error", + "link listener accept error": "link_listener_accept_failed", + "webhook delivery attempt failed": "webhook_delivery_failed", + "webhook dispatcher loop failed": "webhook_dispatcher_failed", + "addressed delegation authorization failed": "share_authorization_failed", + "native share authorization denied": "share_native_authorization_denied", + "native share KV put failed": "share_native_kv_put_failed", + "share v2 readiness probe failed": "share_v2_readiness_failed", + "share v2 is enabled but shareEmail.invitationPublicKey is unset": "share_invitation_key_missing", + "configured share invitation key does not match the node's derived signing key": "share_invitation_key_mismatch", + "share/v2 policy challenge denied": "share_policy_denied", + "failed to read committed hook events": "hook_events_read_failed", + "failed to load kv write hook rows": "hook_rows_load_failed", + "failed to load kv delete hook rows": "hook_rows_load_failed", + "missing committed kv hook row for invocation": "missing_committed_hook_row", + "database write committed but webhook enqueue failed": "webhook_enqueue_failed", + "tunnel: failed to prepare connection attempt": "tunnel_connection_prepare_failed", + "tunnel: no frame within idle timeout; treating connection as dead": "tunnel_idle_timeout", + "tunnel: read error": "tunnel_read_failed", + "tunnel: dropping malformed frame": "tunnel_malformed_frame", + "tunnel: relay sent an error frame": "tunnel_relay_error", + "tunnel: failed to write frame": "tunnel_write_failed", + "tunnel: failed to record runtime state": "tunnel_state_record_failed", + "tunnel: failed to clear runtime state after disable": "tunnel_state_clear_failed", + "tunnel authentication rejected": "tunnel_auth_rejected", + "network DID resolution enabled: did:web/did:tz fetches use the unhardened ssi client (TC-1080)": "network_did_resolution_enabled" + }, + "prefix": { + "dstack socket available but get_info failed: ": "dstack_get_info_failed", + "quota service returned an invalid body: ": "quota_invalid_body", + "quota service returned ": "quota_fallback", + "Failed to get TDX quote: ": "attestation_quote_failed" + }, + "fallback": "unclassified" +} diff --git a/log-shipper/fields.json b/log-shipper/fields.json new file mode 100644 index 00000000..b56b6e1d --- /dev/null +++ b/log-shipper/fields.json @@ -0,0 +1,96 @@ +{ + "version": 1, + "common": { + "level": { "type": "enum", "values": ["debug", "info", "warn", "error"] }, + "ts": { "type": "string", "regex": "^\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}\\.\\d{3}Z$", "max_len": 24 }, + "event": { "type": "event" } + }, + "reader_output": { + "bucket": { "type": "string", "regex": "^\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}$", "max_len": 19 }, + "status_class": { "type": "enum", "values": ["1xx", "2xx", "3xx", "4xx", "5xx", "unknown"] }, + "count": { "type": "integer", "min": 0, "max": 1000000000 } + }, + "services": { + "ptx-batch": { + "events": [ + "batch_artifact_deletion_failed", + "batch_claim_recovered", + "batch_artifact_reappeared_after_verified_deletion", + "batch_transcription_create", + "batch_transcription_cancel", + "batch_transcription_delete", + "batch_retention_lag_exceeded", + "batch_request_failed", + "batch_admission_mode_changed", + "batch_admission_stopped_by_disk_high_water", + "batch_upload_refused_by_disk_high_water", + "batch_upload_accepted", + "batch_upload_rejected", + "batch_job_finished", + "batch_claim_fenced_out", + "batch_job_failed_unexpectedly", + "batch_vad_fell_back_to_the_floor_threshold", + "batch_vad_could_not_cover_the_recording", + "batch_diarization_failed", + "batch_provider_rejected_the_service_credential_or_model", + "batch_job_failed_at_dispatch", + "batch_worker_heartbeat_failed", + "batch_sweep_failed", + "batch_worker_iteration_failed", + "batch_worker_started", + "batch_worker_heartbeat" + ], + "fields": { + "svc": { "type": "enum", "values": ["api", "worker"] }, + "correlationId": { "type": "string", "regex": "^[0-9a-f]{8}-[0-9a-f]{4}-[1-8][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$", "max_len": 36 }, + "transcriptionId": { "type": "string", "regex": "^trn_[0-9A-HJKMNP-TV-Z]{26}$", "max_len": 30 }, + "job_id": { "type": "string", "regex": "^trn_[0-9A-HJKMNP-TV-Z]{26}$", "max_len": 30 }, + "stage": { "type": "enum", "values": ["create", "cancel", "delete", "health", "api_unhandled", "admission", "upload", "deletion", "claim_recovery", "reconcile", "vad", "diarize", "pipeline", "fence", "dispatch", "heartbeat", "sweep", "loop"] }, + "code": { "type": "enum", "values": ["invalid_request", "diarization_unavailable", "unauthorized", "insufficient_scope", "idempotency_conflict", "transcription_not_found", "active_transcription_exists", "recording_too_large", "quota_exceeded", "service_busy", "service_paused", "service_unavailable", "upload_capability_limit", "upload_capability_invalid", "upload_capability_expired", "upload_length_mismatch", "unsupported_media_type", "upload_in_progress", "upload_interrupted", "upload_rejected", "transcript_expired", "not_found", "internal_error", "upload_expired", "upload_integrity_failed", "invalid_audio", "recording_too_long", "unsupported_recording", "no_speech", "provider_unavailable", "provider_outcome_unknown", "processing_timeout", "processing_failed", "transcription_failed", "cancelled"], "nullable": true }, + "alert": { "type": "boolean" }, + "outcome": { "type": "enum", "values": ["completed", "failed", "no_speech"] }, + "duration_seconds": { "type": "number", "min": 0, "max": 86400 }, + "tinfoil_calls": { "type": "integer", "min": 0, "max": 100000, "nullable": true }, + "tinfoil_audio_seconds": { "type": "number", "min": 0, "max": 7200, "nullable": true }, + "voiced_seconds": { "type": "number", "min": 0, "max": 7200, "nullable": true }, + "dropped_above_floor_pct": { "type": "number", "min": 0, "max": 100, "nullable": true }, + "vad_fallback": { "type": "boolean", "nullable": true }, + "segments": { "type": "integer", "min": 0, "max": 100000, "nullable": true }, + "content_type": { "type": "enum", "values": ["audio/mpeg", "audio/wav", "audio/ogg", "audio/mp4", "audio/webm", "audio/flac"] }, + "retentionLagSeconds": { "type": "number", "min": 0, "max": 31536000 }, + "usedPercent": { "type": "number", "min": 0, "max": 100 }, + "mode": { "type": "enum", "values": ["open", "drain", "closed"] }, + "created": { "type": "boolean" } + } + }, + "tinycloud-node": { + "events": [ + "node_request", + "ingress_request", + "node_warning", + "node_error", + "logship_gate_summary_total" + ], + "fields": { + "svc": { "type": "enum", "values": ["api", "ingress", "logship"] }, + "method": { "type": "enum", "values": ["GET", "HEAD", "POST", "PUT", "PATCH", "DELETE", "OPTIONS", ""] }, + "route": { "type": "enum", "values": ["/healthz", "/info", "/version", "/invoke", "/delegate", "/revoke", "/attestation", "/signed/kv", "/signed/kv/", "/admin/quota", "/admin/quota/", "/admin/usage", "/hooks/events", "/hooks/tickets", "/hooks/webhooks", "/hooks/webhooks/", "/delegation/query", "/delegation/status", "/encryption/networks", "/encryption/networks/", "/encryption/networks//revoke", "/encryption/networks//decrypt", "/policy/v3/status", "/policy/v3/status/", "/policy/v3/policies", "/policy/v3/challenges", "/policy/v3/delegations", "/policy/v3/enforcer-bindings", "/policy/v3/deliveries/authorize", "/.well-known/tinycloud/node-keys", "/.well-known/encryption/network/", "/public//kv", "/public//kv/", "/peer/generate/", "/evidences/", "/share/v2/readiness", "/share/v2/policies", "/share/v2/policy/challenges", "/share/v2/policy/session", "/share/v2/invoke", "/share/v2/deliveries/authorize", "/<_s..>", "/public/<_space_id>/kv/<_key..>", ""] }, + "status": { "type": "integer", "min": 100, "max": 599 }, + "latency_us": { "type": "integer", "min": 0, "max": 9007199254740991 }, + "request_time_seconds": { "type": "number", "min": 0, "max": 86400 }, + "event_code": { "type": "enum", "values": ["invocation_replay_insert_failed", "invocation_replay_cleanup_failed", "dstack_get_info_failed", "share_local_tee_identity", "retention_hook_delivery_prune_failed", "retention_dead_letter_prune_failed", "retention_signed_ticket_prune_failed", "quota_invalid_body", "quota_fallback", "tunnel_state_load_failed", "tunnel_address_invalid", "link_state_load_failed", "link_bind_invalid", "link_address_invalid", "link_bind_failed", "link_bind_state_write_failed", "link_tls_config_failed", "link_listener_error", "link_listener_state_write_failed", "link_auto_renew_config_failed", "link_auto_renew_failed", "link_cert_reload_failed", "link_cert_state_missing", "link_listener_cert_reload_failed", "link_disable_failed", "link_connection_error", "link_listener_accept_failed", "webhook_delivery_failed", "webhook_dispatcher_failed", "share_authorization_failed", "share_native_authorization_denied", "share_native_kv_put_failed", "share_v2_readiness_failed", "share_invitation_key_missing", "share_invitation_key_mismatch", "share_policy_denied", "attestation_quote_failed", "hook_events_read_failed", "hook_rows_load_failed", "missing_committed_hook_row", "webhook_enqueue_failed", "tunnel_connection_prepare_failed", "tunnel_idle_timeout", "tunnel_read_failed", "tunnel_malformed_frame", "tunnel_relay_error", "tunnel_write_failed", "tunnel_state_record_failed", "tunnel_state_clear_failed", "tunnel_auth_rejected", "network_did_resolution_enabled", "unclassified"] }, + "event_count": { "type": "integer", "min": 1, "max": 9007199254740991 }, + "reason": { "type": "enum", "values": ["malformed_envelope", "unexpected_label", "unlabelled", "non_json", "oversized", "partial", "invalid_fields", "unknown_target", "filtered_level"] }, + "count": { "type": "integer", "min": 1, "max": 9007199254740991 }, + "request_id": { "type": "string", "regex": "^[0-9a-f]{8}-[0-9a-f]{4}-[1-8][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$", "max_len": 36 }, + "request_id_replaced": { "type": "boolean" }, + "account_hash": { "type": "string", "regex": "^[0-9a-f]{64}$", "max_len": 64 }, + "space_hash": { "type": "string", "regex": "^[0-9a-f]{64}$", "max_len": 64 } + } + }, + "tinychat-backend": { "events": [], "fields": {} }, + "tinycloud-mcp": { "events": [], "fields": {} }, + "ptx-dev": { "events": [], "fields": {} }, + "openkey-api": { "events": [], "fields": {} } + } +} diff --git a/log-shipper/fixtures/capture.json b/log-shipper/fixtures/capture.json new file mode 100644 index 00000000..78787d4b --- /dev/null +++ b/log-shipper/fixtures/capture.json @@ -0,0 +1,27 @@ +{ + "data_dir": "/tmp/vector-data", + "sources": { + "capture": { + "type": "http_server", + "address": "0.0.0.0:8080", + "framing": { "method": "newline_delimited" }, + "decoding": { "codec": "bytes" } + } + }, + "transforms": { + "wire_only": { + "type": "remap", + "inputs": ["capture"], + "source": ". = parse_json!(string!(.message))" + } + }, + "sinks": { + "capture_file": { + "type": "file", + "inputs": ["wire_only"], + "path": "/tmp/capture.ndjson", + "encoding": { "codec": "json" }, + "framing": { "method": "newline_delimited" } + } + } +} diff --git a/log-shipper/native-check.mjs b/log-shipper/native-check.mjs new file mode 100644 index 00000000..e5050346 --- /dev/null +++ b/log-shipper/native-check.mjs @@ -0,0 +1,106 @@ +import assert from 'node:assert/strict'; +import { spawn } from 'node:child_process'; +import { once } from 'node:events'; +import { createSocket } from 'node:dgram'; +import { createServer } from 'node:http'; +import { mkdtemp, readFile, rm, writeFile } from 'node:fs/promises'; +import { tmpdir } from 'node:os'; +import { join, resolve } from 'node:path'; +import { fileURLToPath } from 'node:url'; +import { gunzipSync } from 'node:zlib'; +import { buildConfig } from '../scripts/tc959-logship.mjs'; +import { assertCapture } from '../scripts/tc959-docker.mjs'; +import { hasUdpListener } from '../scripts/tc959-readiness.mjs'; +import { canary, nodeRequest, ingressRequest } from './cases.mjs'; + +const sleep = ms => new Promise(resolve => setTimeout(resolve, ms)); + +/** Real native Vector, UDP framing and HTTP capture; never production inputs. */ +export async function checkNativeVector(vector, baseline) { + const dir = await mkdtemp(join(tmpdir(), 'tc959-native-')); + const events = []; + let malformedHttp = false; + const server = createServer(async (request, response) => { + try { + const chunks = []; + for await (const chunk of request) chunks.push(chunk); + let body = Buffer.concat(chunks); + if (request.headers['content-encoding'] === 'gzip') body = gunzipSync(body); + for (const line of body.toString().split('\n').filter(Boolean)) events.push(JSON.parse(line)); + response.writeHead(200).end(); + } catch { malformedHttp = true; response.writeHead(400).end(); } + }); + let child; + let closed; + let consoleText = ''; + let overflow = false; + const udp = createSocket('udp4'); + try { + await new Promise(resolve => server.listen(0, '127.0.0.1', resolve)); + await new Promise(resolve => udp.bind(0, '127.0.0.1', resolve)); + const port = udp.address().port; + await new Promise(resolve => udp.close(resolve)); + const config = baseline ? structuredClone(baseline) : buildConfig({ profile: 'all_requests' }); + delete config.secret; + config.data_dir = dir; + config.sources.gelf_in.address = `127.0.0.1:${port}`; + config.sinks.betterstack.uri = `http://127.0.0.1:${server.address().port}/`; + config.sinks.betterstack.auth = { strategy: 'bearer', token: 'tc959-synthetic-only' }; + const path = join(dir, 'vector.json'); + await writeFile(path, JSON.stringify(config)); + child = spawn(vector, ['--config', path], { env: {}, stdio: ['ignore', 'pipe', 'pipe'] }); + closed = once(child, 'close'); + const collect = chunk => { + consoleText += chunk.toString(); + if (Buffer.byteLength(consoleText) > 524288) { overflow = true; consoleText = consoleText.slice(-524288); } + }; + child.stdout.on('data', collect); + child.stderr.on('data', collect); + let bound = false; + for (let attempt = 0; attempt < 250; attempt++) { + if (child.exitCode !== null) break; + bound = hasUdpListener(await readFile('/proc/net/udp', 'utf8'), port); + if (bound) break; + await sleep(20); + } + assert.equal(bound, true, 'native UDP listener did not become ready'); + const sender = createSocket('udp4'); + const send = packet => new Promise((resolve, reject) => sender.send(Buffer.from(packet), port, '127.0.0.1', error => error ? reject(error) : resolve())); + const frame = (value, label = 'tinycloud-node', extras = {}) => JSON.stringify({ version: '1.1', host: canary, timestamp: Date.now() / 1000, level: 6, short_message: JSON.stringify(value), '_tc.logship': label, ...extras }); + try { + for (const [route, method, status] of [['/healthz', 'GET', 200], ['/version', 'GET', 200], ['/invoke', 'POST', 401]]) { + await send(frame(nodeRequest({ route, method, status, authorization: canary }))); + } + await send(frame(ingressRequest(), 'tinycloud-ingress')); + // Native GELF JSON decoding used to quote this value in its own console. + await send(frame(nodeRequest({ route: '/healthz' }), 'tinycloud-node', { level: canary, full_message: canary })); + await send(`{"version":"1.1","short_message":"${canary}`); + } finally { sender.close(); } + for (let attempt = 0; attempt < 100; attempt++) { + if (events.filter(event => event.event === 'node_request' || event.event === 'ingress_request').length >= 5) break; + await sleep(30); + } + child.kill('SIGTERM'); + await closed; + child = undefined; + let wireSafe = true; + const schema = JSON.parse(await readFile(new URL('./fields.json', import.meta.url), 'utf8')); + try { assertCapture(events, schema.services['tinycloud-node'].fields); } catch { wireSafe = false; } + const requests = events.filter(event => event.event === 'node_request' || event.event === 'ingress_request').length; + const consoleHits = consoleText.split(canary).length - 1; + return { status: wireSafe && !malformedHttp && !overflow && requests === 5 && consoleHits === 0 ? 'passed' : 'failed', request_events: requests, console_canary_hits: consoleHits, wire_safe: wireSafe, positive_controls: 5, console_overflow: overflow }; + } finally { + if (child) { child.kill('SIGTERM'); await closed; } + server.closeAllConnections(); + await new Promise(resolve => server.close(resolve)); + await rm(dir, { recursive: true, force: true }); + } +} + +if (process.argv[1] && resolve(process.argv[1]) === fileURLToPath(import.meta.url)) { + if (!process.argv[2]) throw new Error('usage: native-check.mjs VECTOR_BINARY'); + checkNativeVector(resolve(process.argv[2])).then(result => { + console.log(JSON.stringify(result)); + if (result.status !== 'passed') process.exitCode = 1; + }).catch(() => { console.log(JSON.stringify({ status: 'failed', reason: 'native_runtime_check_failed' })); process.exitCode = 1; }); +} diff --git a/log-shipper/profile.test.mjs b/log-shipper/profile.test.mjs new file mode 100644 index 00000000..e38acfb6 --- /dev/null +++ b/log-shipper/profile.test.mjs @@ -0,0 +1,21 @@ +import test from 'node:test'; +import assert from 'node:assert/strict'; +import { buildConfig } from '../scripts/tc959-logship.mjs'; + +test('invalid profile selections fail startup rather than silently logging another set', () => { + for (const profile of [null, '', 'error_slow', 'WARN', true, 42, {}]) { + assert.throws(() => buildConfig({ profile })); + } +}); + +test('slow threshold requires a nonnegative safe integer in microseconds', () => { + for (const slowThresholdUs of ['1000000', null, -1, 0.5, Infinity, NaN, Number.MAX_SAFE_INTEGER + 1]) { + assert.throws(() => buildConfig({ slowThresholdUs })); + } +}); + +test('runtime profile interpolation is an explicit boolean compiler choice', () => { + for (const runtimeProfile of [null, 'true', 1, {}]) { + assert.throws(() => buildConfig({ runtimeProfile })); + } +}); diff --git a/log-shipper/sanitize.vrl b/log-shipper/sanitize.vrl new file mode 100644 index 00000000..c3c2761c --- /dev/null +++ b/log-shipper/sanitize.vrl @@ -0,0 +1,58 @@ +# Only this fresh object can leave the process boundary. No envelope, span, +# message, error, identity, URI or unknown key is copied into it. +j = .parsed +label = .label +out = {} +ts = "" +if label == "tinycloud-node" { + target = string(j.target) ?? "" + level = downcase(string!(j.level)) + f = object(j.fields) ?? {} + msg = string(f.message) ?? "" + ts = string!(j.timestamp) + if target == "tinycloud::request" && level == "info" && msg == "request" { + method = string!(f.method) + if includes(["TRACE", "CONNECT"], method) { method = "" } + route = string!(f.route) + # Literal Rocket template aliases only; never split an arbitrary URI. + aliases = __ROUTE_ALIASES__ + canonical_route = get(aliases, [route]) ?? null + if is_string(canonical_route) { route = canonical_route } + if !includes(__METHODS__, method) || !includes(__ROUTES__, route) { abort } + status = f.status + latency = f.latency_us + if !is_integer(status) || !is_integer(latency) { abort } + status = int!(status) + latency = int!(latency) + if status < 100 || status > 599 || latency < 0 || latency > 9007199254740991 { abort } + out = {"event": "node_request", "svc": "api", "level": "info", "method": method, "route": route, "status": status, "latency_us": latency} + } else { + if !includes(["warn", "error"], level) { abort } + code = "unclassified" + if target == "tinycloud" || starts_with(target, "tinycloud::") || target == "tinycloud_core" || starts_with(target, "tinycloud_core::") { + codes = __DIAGNOSTICS__ + known = get(codes, [msg]) ?? null + if is_string(known) { code = known } + __PREFIX_DIAGNOSTICS__ + } + event = if level == "warn" { "node_warning" } else { "node_error" } + out = {"event": event, "svc": "api", "level": level, "event_code": code, "event_count": 1} + } +} else { + ts = string!(j.time) + method = string!(j.method) + route = string!(j.route) + if route == "" { route = "" } + if !includes(__METHODS__, method) || !includes(__ROUTES__, route) { abort } + status = j.status + request_time = j.request_time + if !is_integer(status) || !(is_integer(request_time) || is_float(request_time)) { abort } + status = int!(status) + request_time = to_float!(request_time) + if status < 100 || status > 599 || request_time < 0 || request_time > 86400 { abort } + out = {"event": "ingress_request", "svc": "ingress", "level": "info", "method": method, "route": route, "status": status, "request_time_seconds": request_time} +} +if length(ts) > 64 { abort } +parsed_ts = parse_timestamp!(ts, format: "%+") +out.ts = format_timestamp!(parsed_ts, format: "%Y-%m-%dT%H:%M:%S%.3fZ") +. = out diff --git a/scripts/tc959-check.mjs b/scripts/tc959-check.mjs new file mode 100644 index 00000000..29729912 --- /dev/null +++ b/scripts/tc959-check.mjs @@ -0,0 +1,62 @@ +import assert from 'node:assert/strict'; +import { spawnSync } from 'node:child_process'; +import { createHash } from 'node:crypto'; +import { readFileSync } from 'node:fs'; +import { resolve } from 'node:path'; +import { fileURLToPath } from 'node:url'; +import { isDeepStrictEqual } from 'node:util'; +import { buildConfig, nodeImage, ingressImage, vectorImage } from './tc959-logship.mjs'; + +const root = fileURLToPath(new URL('../', import.meta.url)); +const args = process.argv.slice(2); +if (args.length && (args.length !== 2 || args[0] !== '--canonical')) throw new Error('usage: tc959-check.mjs [--canonical PATH_TO_CANONICAL_FIELDS]'); +const bytes = readFileSync(resolve(root, 'log-shipper/fields.json')); +const pin = JSON.parse(readFileSync(resolve(root, 'log-shipper/canonical.json'), 'utf8')); +assert.match(pin.revision, /^[0-9a-f]{40}$/); +assert.equal(createHash('sha256').update(bytes).digest('hex'), pin.sha256, 'vendored schema differs from reviewed canonical hash'); +if (args[1]) assert.deepEqual(bytes, readFileSync(args[1]), 'canonical/vendor schema bytes differ'); +const result = spawnSync('docker', ['compose', '--env-file', '/dev/null', '-f', resolve(root, 'docker-compose.dstack-postgres.yaml'), 'config', '--no-interpolate', '--no-env-resolution', '--format', 'json'], { encoding: 'utf8', maxBuffer: 4 * 1024 * 1024 }); +assert.equal(result.status, 0, 'compose structure cannot be parsed without env interpolation'); +const compose = JSON.parse(result.stdout); +const services = compose.services; +assert.equal(services.tinycloud.image, nodeImage, 'N0 must use unchanged production node digest'); +assert.equal(services['dstack-ingress'].image, ingressImage, 'N0 must use unchanged ingress digest'); +assert.equal(services.tinycloud.environment.TINYCLOUD_LOG__FORMAT, 'Json'); +assert.deepEqual(Object.keys(services.tinycloud.networks), ['default']); +assert.deepEqual(Object.keys(services['dstack-ingress'].networks), ['default']); +for (const [name, label] of [['tinycloud', 'tinycloud-node'], ['dstack-ingress', 'tinycloud-ingress']]) { + const service = services[name]; + assert.equal(service.labels['tc.logship'], label); + assert.equal(service.logging.driver, 'gelf'); + assert.equal(service.logging.options['gelf-address'], 'udp://127.0.0.1:12201'); + assert.equal(service.logging.options.labels, 'tc.logship'); + assert.equal(service.logging.options.mode, 'non-blocking'); + assert.equal(service.logging.options['cache-disabled'], 'true'); +} +const vector = services.vector; +assert.equal(vector.image, vectorImage); +assert.equal(vector.user, '10001:10001'); +assert.equal(vector.read_only, true); +assert.deepEqual(vector.cap_drop, ['ALL']); +assert.ok(vector.security_opt.includes('no-new-privileges:true')); +assert.ok(['64m', '67108864'].includes(String(vector.mem_limit))); +assert.ok(['64m', '67108864'].includes(String(vector.memswap_limit))); +assert.equal(Number(vector.cpus), 0.5); +assert.equal(vector.privileged ?? false, false); +assert.equal(vector.network_mode, undefined); +assert.deepEqual(Object.keys(vector.networks), ['logship']); +assert.equal(vector.volumes, undefined, 'Vector must not mount Docker, dstack, app data, or host files'); +assert.equal(vector.ports.length, 1); +assert.equal(vector.ports[0].host_ip, '127.0.0.1'); +assert.equal(vector.ports[0].target, 12201); +assert.equal(vector.ports[0].published, '12201'); +assert.equal(vector.ports[0].protocol, 'udp'); +assert.equal(vector.logging.driver, 'json-file'); +assert.equal(vector.environment.TINYCLOUD_LOGSHIP_PROFILE, '${TINYCLOUD_LOGSHIP_PROFILE:-errors_slow}'); +const embedded = vector.environment.VECTOR_CONFIG_JSON.replaceAll('$${TINYCLOUD_LOGSHIP_PROFILE}', '${TINYCLOUD_LOGSHIP_PROFILE}'); +assert.ok(isDeepStrictEqual(JSON.parse(embedded), buildConfig({ runtimeProfile: true })), 'embedded Vector config differs from schema/compiler sources'); +const schema = JSON.parse(bytes).services['tinycloud-node']; +assert.equal(schema.events.includes('node_fatal_panic'), false); +const diagnostics = JSON.parse(readFileSync(resolve(root, 'log-shipper/diagnostics.json'), 'utf8')); +for (const code of [...Object.values(diagnostics.exact), ...Object.values(diagnostics.prefix), diagnostics.fallback]) assert.ok(schema.fields.event_code.values.includes(code)); +console.log('TC-959 schema pin, compose isolation, image pins and embedded Vector parity passed'); diff --git a/scripts/tc959-compose-proof.mjs b/scripts/tc959-compose-proof.mjs new file mode 100644 index 00000000..7bd451ed --- /dev/null +++ b/scripts/tc959-compose-proof.mjs @@ -0,0 +1,159 @@ +import assert from 'node:assert/strict'; + +export const owner = 'tc959-n0'; + +/** Canonical `compose config` escapes dollars for reuse as Compose input. */ +export function composeRuntimeValues(value) { + if (typeof value === 'string') return value.replaceAll('$$', '$'); + if (Array.isArray(value)) return value.map(composeRuntimeValues); + if (value !== null && typeof value === 'object') return Object.fromEntries(Object.entries(value).map(([key, item]) => [key, composeRuntimeValues(item)])); + return value; +} + +/** Refuse local/self-hosted execution before touching the Docker daemon. */ +export function assertHostedRunner(env) { + if (env.GITHUB_ACTIONS !== 'true' || env.RUNNER_ENVIRONMENT !== 'github-hosted' || env.RUNNER_OS !== 'Linux' + || !/^\d+$/.test(env.GITHUB_RUN_ID ?? '') || !/^\d+$/.test(env.GITHUB_RUN_ATTEMPT ?? '') + || !/^\/home\/runner\/work\/_temp(?:\/|$)/.test(env.RUNNER_TEMP ?? '')) throw new Error('disposable_hosted_runner_required'); +} + +/** Validate the whole deletion set before the first mutation. Never accept images or foreign names. */ +export function cleanupOwnedResources(resources, remove, runId) { + assert.match(runId, /^[a-zA-Z0-9-]+$/); + for (const value of resources) { + assert.ok(['container', 'network', 'volume'].includes(value.kind)); + assert.ok(value.name.startsWith(`${owner}-${runId}-`)); + assert.equal(value.labels?.['tc959.owner'], owner); + assert.equal(value.labels?.[owner], runId); + } + const result = { containers: 0, networks: 0, volumes: 0 }; + for (const kind of ['container', 'network', 'volume']) for (const value of resources.filter(value => value.kind === kind)) { + remove(value); + result[`${kind}s`]++; + } + return result; +} + +/** Distinct existing safe timing values identify the complete controlled burst without new wire fields. */ +export function burstEvidence(events, first, count) { + const seen = new Map(); + for (const event of events) if (event?.event === 'node_request' && event.status === 503 + && Number.isSafeInteger(event.latency_us) && event.latency_us >= first && event.latency_us < first + count) { + seen.set(event.latency_us, (seen.get(event.latency_us) ?? 0) + 1); + } + return { expected: count, received: [...seen.values()].reduce((sum, value) => sum + value, 0), unique: seen.size, + missing: Array.from({ length: count }, (_, index) => first + index).filter(marker => !seen.has(marker)), + duplicates: [...seen].filter(([, total]) => total > 1).sort(([a], [b]) => a - b).map(([marker, total]) => ({ marker, count: total })) }; +} + +/** Healthy controlled bursts have no observed loss, compensating duplicate, or unconfirmed emission. */ +export function assertHealthyBurst(events, first, count, emitted) { + const evidence = burstEvidence(events, first, count); + assert.equal(emitted, count, 'burst_emission_unconfirmed'); + assert.equal(evidence.received, count, 'healthy_burst_loss_or_duplicate'); + assert.equal(evidence.unique, count, 'healthy_burst_missing'); + assert.equal(evidence.missing.length, 0); + assert.equal(evidence.duplicates.length, 0); + return evidence; +} + +/** An observed plateau requires three timed, fully known, identical hop samples. It is not a root cause. */ +export function progressEvidence(samples) { + const keys = ['source', 'gate', 'admitted', 'sink', 'capture']; + const first = samples[0]; + const latest = samples.at(-1); + const deltas = Object.fromEntries(keys.map(key => [key, Number.isFinite(first?.[key]) && Number.isFinite(latest?.[key]) ? latest[key] - first[key] : null])); + const isStatic = key => samples.length >= 3 && latest.elapsed_ms > samples.at(-3).elapsed_ms + && samples.slice(-3).every(sample => Number.isFinite(sample[key]) && sample[key] === latest[key]); + const plateaus = Object.fromEntries(keys.map(key => [key, isStatic(key)])); + return { samples, latest, deltas, plateau: keys.every(key => plateaus[key]), plateaus, burst_plateau: isStatic('burst_capture') }; +} + +const bytes = value => { + if (value === undefined) return 0; + const match = /^(\d+)([kmg])?b?$/i.exec(String(value)); + assert.ok(match, 'unsupported_compose_memory_unit'); + return Number(match[1]) * 1024 ** ({ k: 1, m: 2, g: 3 }[match[2]?.toLowerCase()] ?? 0); +}; + +/** Compare actual Docker settings to the rendered service, not to a second handwritten deployment. */ +export function assertServiceParity(service, value, { networks, portBindings, mounts = [] }) { + const host = value.HostConfig; + assert.equal(value.Config.Image, service.image); + if (service.user !== undefined) assert.equal(value.Config.User, service.user); + for (const [key, label] of Object.entries(service.labels ?? {})) assert.equal(value.Config.Labels[key], label); + assert.equal(host.ReadonlyRootfs, service.read_only ?? false); + assert.equal(host.Privileged, service.privileged ?? false); + assert.equal(Boolean(host.Init), service.init ?? false); + assert.deepEqual(host.CapDrop ?? [], service.cap_drop ?? []); + assert.deepEqual(host.SecurityOpt ?? [], service.security_opt ?? []); + assert.equal(host.Memory, bytes(service.mem_limit)); + assert.equal(host.MemorySwap, bytes(service.memswap_limit)); + assert.equal(host.NanoCpus, Math.round(Number(service.cpus ?? 0) * 1e9)); + assert.deepEqual(host.LogConfig, { Type: service.logging.driver, Config: service.logging.options ?? {} }); + assert.deepEqual(host.Tmpfs ?? {}, Object.fromEntries((service.tmpfs ?? []).map(item => { + const separator = item.indexOf(':'); + return [item.slice(0, separator), item.slice(separator + 1)]; + }))); + assert.deepEqual(Object.keys(value.NetworkSettings.Networks).sort(), [...networks].sort()); + assert.deepEqual(host.PortBindings ?? {}, portBindings); + assert.deepEqual(Object.fromEntries(Object.entries(value.NetworkSettings.Ports ?? {}).filter(([, bindings]) => bindings !== null)), portBindings); + assert.deepEqual((value.Mounts ?? []).filter(mount => mount.Type !== 'tmpfs').map(mount => ({ type: mount.Type, source: mount.Source, target: mount.Destination, read_only: !mount.RW })).sort((a, b) => a.target.localeCompare(b.target)), [...mounts].sort((a, b) => a.target.localeCompare(b.target))); + if (service.entrypoint) assert.deepEqual([...(value.Config.Entrypoint ?? []), ...(value.Config.Cmd ?? [])], [...service.entrypoint, ...(service.command ?? [])]); + else if (service.command) assert.deepEqual(value.Config.Cmd, service.command); + if (service.restart) assert.equal(host.RestartPolicy.Name, service.restart); + if (service.environment) for (const [key, expected] of Object.entries(service.environment)) assert.ok(value.Config.Env.includes(`${key}=${expected}`), 'rendered_environment_mismatch'); +} + +/** Validate network semantics, including explicit defaults emitted by Compose. */ +export function assertLogshipNetwork(value) { + assert.equal(value.driver, 'bridge'); + assert.equal(value.internal ?? false, false); + assert.equal(value.external ?? false, false); + assert.equal(value.attachable ?? false, false); + assert.equal(value.enable_ipv4 ?? true, true); + assert.equal(value.enable_ipv6 ?? false, false); + assert.deepEqual(value.driver_opts ?? {}, {}); + assert.deepEqual(value.labels ?? {}, {}); + const ipam = value.ipam ?? {}; + assert.equal(ipam.driver ?? 'default', 'default'); + assert.deepEqual(ipam.config ?? [], []); + assert.deepEqual(ipam.options ?? {}, {}); + assert.ok(Object.keys(ipam).every(key => ['driver', 'config', 'options'].includes(key))); + assert.ok(Object.keys(value).every(key => ['name', 'driver', 'internal', 'external', 'attachable', 'enable_ipv4', 'enable_ipv6', 'driver_opts', 'labels', 'ipam'].includes(key))); +} + +/** ss skmem rb is the effective SO_RCVBUF, which Linux may double and kernel-cap. */ +export function socketEvidence(text, rmemMax) { + const number = value => /^\d+$/.test(value ?? '') ? Number(value) : null; + return { requested_receive_buffer_bytes: 8388608, rmem_max: number(rmemMax.trim()), + effective_so_rcvbuf: number(/(?:\(|,)rb(\d+)(?:,|\))/.exec(text)?.[1]), + socket_drops: number(/(?:\(|,)d(\d+)\)/.exec(text)?.[1]) }; +} + +/** Numeric diagnostics only: raw Prometheus labels and text never leave this function. */ +export function numericMetrics(text) { + const names = ['buffer_events', 'buffer_byte_size', 'buffer_received_events_total', 'buffer_sent_events_total', 'buffer_discarded_events_total', 'buffer_discarded_bytes_total', 'buffer_send_duration_seconds_sum', 'buffer_send_duration_seconds_count', 'component_send_latency_seconds_sum', 'component_send_latency_seconds_count', 'component_errors_total', 'component_discarded_events_total', 'component_received_events_total', 'component_sent_events_total', 'component_received_event_bytes_total', 'component_sent_event_bytes_total', 'utilization']; + const result = Object.fromEntries(names.map(name => [name, null])); + for (const line of text.split('\n')) { + const match = /^(?:vector_)?([a-z_]+)(?:\{[^}]*\})?\s+([0-9.eE+-]+)(?:\s|$)/.exec(line); + if (!match || !Object.hasOwn(result, match[1])) continue; + const value = Number(match[2]); + if (Number.isFinite(value) && value >= 0) result[match[1]] = (result[match[1]] ?? 0) + value; + } + return result; +} + +/** Fixed-code control totals count occurrences, not reduced output rows. */ +export function diagnosticCounts(events) { + const result = { warn: 0, unclassified: 0, error: 0, dependency_error: 0, total: 0 }; + for (const event of events) { + if (!Number.isSafeInteger(event?.event_count) || event.event_count <= 0) continue; + if (event.event === 'node_warning' || event.event === 'node_error') result.total += event.event_count; + if (event.event === 'node_warning' && event.event_code === 'link_bind_invalid') result.warn += event.event_count; + if (event.event === 'node_warning' && event.event_code === 'unclassified') result.unclassified += event.event_count; + if (event.event === 'node_error' && event.event_code === 'share_native_kv_put_failed') result.error += event.event_count; + if (event.event === 'node_error' && event.event_code === 'unclassified') result.dependency_error += event.event_count; + } + return result; +} diff --git a/scripts/tc959-docker.mjs b/scripts/tc959-docker.mjs new file mode 100755 index 00000000..b17f904e --- /dev/null +++ b/scripts/tc959-docker.mjs @@ -0,0 +1,634 @@ +#!/usr/bin/env node +// Disposable hosted-runner proof. Never reads deployment credentials, .env files or GH secrets. +import assert from 'node:assert/strict'; +import { spawnSync } from 'node:child_process'; +import dgram from 'node:dgram'; +import { writeFileSync } from 'node:fs'; +import { mkdir, readFile, rm, writeFile } from 'node:fs/promises'; +import net from 'node:net'; +import { dirname, join, resolve } from 'node:path'; +import { fileURLToPath, pathToFileURL } from 'node:url'; +import { isDeepStrictEqual } from 'node:util'; +import { buildConfig, nodeImage, ingressImage, vectorImage } from './tc959-logship.mjs'; +import { canary, nodeRequest } from '../log-shipper/cases.mjs'; +import { awaitReadiness, classifyProbeError, classifyStartupOutput, hasUdpListener, componentCounters } from './tc959-readiness.mjs'; +import { owner, assertHostedRunner, cleanupOwnedResources, burstEvidence, assertHealthyBurst, progressEvidence, assertServiceParity, assertLogshipNetwork, composeRuntimeValues, socketEvidence, numericMetrics, diagnosticCounts } from './tc959-compose-proof.mjs'; + +const root = resolve(dirname(fileURLToPath(import.meta.url)), '..'); +const token = 'TC959_SYNTHETIC_HOSTED_SINK_BEARER'; +const burstFirst = 100000; // Fast errors: all 500 markers remain below the slow threshold. +const burstSize = 500; +const fastMarker = 800000; +const methods = new Set(['GET', 'HEAD', 'POST', 'PUT', 'PATCH', 'DELETE', 'OPTIONS', '']); +const routes = new Set(['/healthz', '/version', '/invoke', '']); +const sleep = ms => new Promise(resolve => setTimeout(resolve, ms)); +let phase = 'preflight'; + +export function parseArgs(args) { + const result = { go: false, ci: false, cleanupOnly: false, deadline: undefined }; + for (let index = 0; index < args.length; index++) { + if (args[index] === '--go') result.go = true; + else if (args[index] === '--ci') result.ci = true; + else if (args[index] === '--cleanup-only') result.cleanupOnly = true; + else if (args[index] === '--deadline' && args[index + 1]) result.deadline = args[++index]; + else throw new Error('invalid_arguments'); + } + if (!result.go) throw new Error('explicit_go_required'); + if (!result.ci) throw new Error('disposable_hosted_runner_required'); + if (result.deadline !== undefined && !Number.isFinite(Date.parse(result.deadline))) throw new Error('invalid_deadline'); + return result; +} + +export function resourceNames(id) { + return Object.fromEntries(['logship', 'sink', 'vector', 'node', 'ingress', 'emitter'].map(role => [role, `${owner}-${id}-${role}`])); +} + +/** Strict validation applies to every captured record, including a failing proof's partial capture. */ +export function assertCapture(events, fields) { + assert.ok(events.length > 0); + for (const event of events) { + const encoded = JSON.stringify(event); + for (const forbidden of [canary, 'TC959_SYNTHETIC', token, 'did:pkh:', 'email@example.test', 'Bearer ', 'eyJhbGci']) assert.ok(!encoded.includes(forbidden)); + assert.match(event.ts, /^\d{4}-\d\d-\d\dT\d\d:\d\d:\d\d\.\d{3}Z$/); + const base = ['ts', 'level', 'event', 'svc']; + let allowed; + if (event.event === 'node_request' || event.event === 'ingress_request') { + assert.equal(event.level, 'info'); + assert.equal(event.svc, event.event === 'node_request' ? 'api' : 'ingress'); + assert.ok(methods.has(event.method)); + assert.ok((fields?.route?.values ?? [...routes]).includes(event.route)); + assert.ok(Number.isInteger(event.status) && event.status >= 100 && event.status <= 599); + const timing = event.event === 'node_request' ? 'latency_us' : 'request_time_seconds'; + if (timing === 'latency_us') assert.ok(Number.isSafeInteger(event[timing]) && event[timing] >= 0); + else assert.ok(Number.isFinite(event[timing]) && event[timing] >= 0 && event[timing] <= 86400); + allowed = [...base, 'method', 'route', 'status', timing]; + } else if (event.event === 'node_warning' || event.event === 'node_error') { + assert.equal(event.svc, 'api'); + assert.equal(event.level, event.event === 'node_warning' ? 'warn' : 'error'); + assert.ok(fields?.event_code?.values.includes(event.event_code)); + assert.ok(Number.isSafeInteger(event.event_count) && event.event_count > 0); + allowed = [...base, 'event_code', 'event_count']; + } else { + assert.equal(event.event, 'logship_gate_summary_total'); + assert.equal(event.svc, 'logship'); + assert.equal(event.level, 'warn'); + assert.ok(fields?.reason?.values.includes(event.reason)); + assert.ok(Number.isSafeInteger(event.count) && event.count > 0); + allowed = [...base, 'reason', 'count']; + } + assert.deepEqual(Object.keys(event).sort(), allowed.sort()); + } +} + +async function freePort() { + const server = net.createServer(); + await new Promise((resolve, reject) => { server.once('error', reject); server.listen(0, '127.0.0.1', resolve); }); + const port = server.address().port; + await new Promise(resolve => server.close(resolve)); + return port; +} + +const substitutions = [ + 'node_static_keys_sqlite_local_blocks_tee_off_share_email_off', + 'node_dstack_socket_replaced_with_ephemeral_data_tmpfs', + 'ingress_local_nginx_bootstrap_no_dns_no_certbot_no_dstack_no_tls', + 'app_dynamic_loopback_http_ports_default_docker_bridge', + 'vector_synthetic_sink_uri_and_bearer_internal_metrics_only', + 'restart_policy_disabled_for_all_once_created_containers', +]; + +/** The only executable Docker entry point: guarded, bounded, no deployment inputs. */ +export async function main(args = process.argv.slice(2)) { + const options = parseArgs(args); + assertHostedRunner(process.env); + const id = `${process.env.GITHUB_RUN_ID}-${process.env.GITHUB_RUN_ATTEMPT}`; + const names = resourceNames(id); + const scratch = join(process.env.RUNNER_TEMP, `${owner}-${id}`); + const deadline = options.deadline ? Date.parse(options.deadline) : Date.now() + 420000; + const checkTime = () => { if (Date.now() >= deadline - 45000) throw new Error('deadline_cleanup_margin'); }; + const env = { + PATH: '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', HOME: scratch, LANG: 'C.UTF-8', DOCKER_CONFIG: join(scratch, 'docker-config'), COMPOSE_DISABLE_ENV_FILE: 'true', + DATABASE_URL: 'sqlite:/data/caps.db?mode=rwc', S3_BUCKET: 'tc959-synthetic', S3_ENDPOINT: 'http://127.0.0.1:9', AWS_KEY: 'TC959_SYNTHETIC_KEY', AWS_SECRET: 'TC959_SYNTHETIC_SECRET', AWS_REGION: 'us-east-1', + SQL_IDENTITY_FENCE: 'false', SHARE_TRUST_BUNDLE_BASE64: Buffer.from('{}').toString('base64'), TINYCLOUD_QUOTA_URL: '', TINYCLOUD_ADMIN_SECRET: 'TC959_SYNTHETIC_ADMIN', + CLOUDFLARE_API_TOKEN: 'TC959_SYNTHETIC_DNS', DSTACK_GATEWAY_DOMAIN: 'invalid.test', CERTBOT_EMAIL: 'email@example.test', BETTERSTACK_SOURCE_TOKEN: token, TINYCLOUD_LOGSHIP_PROFILE: 'errors_slow', + }; + const command = (binary, args, { final = false, optional = false, timeout = 15000 } = {}) => { + if (!final) checkTime(); + const docker = binary === 'docker'; + const child = spawnSync(docker ? 'sudo' : binary, docker ? ['-n', 'env', '-i', ...Object.entries(env).map(([key, value]) => `${key}=${value}`), 'docker', '--host', 'unix:///var/run/docker.sock', ...args] : args, + { encoding: 'utf8', timeout, maxBuffer: 16 * 1024 * 1024, env, cwd: root, stdio: ['ignore', 'pipe', 'pipe'] }); + if (!optional && (child.error || child.status !== 0)) throw Object.assign(new Error('proof_command_failed'), { operation: docker ? args[0] : 'diagnostic', timed_out: child.error?.code === 'ETIMEDOUT' }); + return child; + }; + const docker = (...args) => command('docker', args).stdout.trim(); + const inspect = (name, final = false) => { + // Actual environments are wholly synthetic. Never print this inspect result. + const result = command('docker', ['inspect', name], { final, optional: final }); + return result.status === 0 ? JSON.parse(result.stdout)[0] : null; + }; + const inventory = () => { + const resources = []; + for (const [kind, args] of [['container', ['ps', '--all', '--quiet']], ['network', ['network', 'ls', '--quiet']], ['volume', ['volume', 'ls', '--quiet']]]) { + const listed = command('docker', [...args, '--filter', `label=tc959.owner=${owner}`, '--filter', `label=${owner}=${id}`], { final: true }); + for (const resource of listed.stdout.trim().split(/\s+/).filter(Boolean)) { + const args = kind === 'container' ? ['inspect', resource] : [kind, 'inspect', resource]; + const value = JSON.parse(command('docker', args, { final: true }).stdout)[0]; + resources.push({ kind, name: (value.Name ?? resource).replace(/^\//, ''), labels: kind === 'container' ? value.Config.Labels : value.Labels }); + } + } + return resources; + }; + const capture = () => { + const result = command('docker', ['exec', names.sink, 'cat', '/tmp/capture.ndjson'], { final: true, optional: true }); + if (result.status !== 0) return { events: [], invalid: 0, incomplete: 0, canary_hits: 0, available: false }; + const lines = result.stdout.split('\n'); + const trailing = lines.pop(); + let invalid = 0; + const events = []; + let hits = 0; + // Scan even malformed/partial lines; never echo their contents or parser messages. + for (const line of [...lines, trailing].filter(Boolean)) { + if ([canary, 'TC959_SYNTHETIC', token, 'did:pkh:', 'email@example.test', 'Bearer ', 'eyJhbGci'].some(value => line.includes(value))) hits++; + try { events.push(JSON.parse(line)); } catch { invalid++; } + } + return { events, invalid, incomplete: trailing ? 1 : 0, canary_hits: hits, available: true }; + }; + const readMetrics = () => { + const result = command('docker', ['exec', names.vector, 'wget', '-q', '-O', '-', 'http://127.0.0.1:9598/metrics'], { final: true, optional: true }); + return result.status === 0 ? result.stdout : ''; + }; + const sockets = () => { + const state = inspect(names.vector, true); + let text = ''; + let rmem = ''; + if (state?.State.Running && state.State.Pid > 0) { + const prefix = ['-n', 'nsenter', '--target', String(state.State.Pid), '--net']; + text = command('sudo', [...prefix, 'ss', '-u', '-a', '-n', '-m', 'sport', '=', ':12201'], { final: true, optional: true }).stdout ?? ''; + rmem = command('sudo', [...prefix, 'cat', '/proc/sys/net/core/rmem_max'], { final: true, optional: true }).stdout ?? ''; + } + return socketEvidence(text, rmem); + }; + const cpu = () => { + const result = command('docker', ['exec', names.vector, 'cat', '/sys/fs/cgroup/cpu.stat'], { final: true, optional: true }); + const allowed = new Set(['usage_usec', 'user_usec', 'system_usec', 'nr_periods', 'nr_throttled', 'throttled_usec']); + return Object.fromEntries((result.stdout ?? '').split('\n').map(line => line.trim().split(/\s+/)).filter(([key, value]) => allowed.has(key) && /^\d+$/.test(value ?? '')).map(([key, value]) => [key, Number(value)])); + }; + const samples = []; + let startedAt = Date.now(); + let schema; + let burstSent = null; + let socketBefore = null; + let cpuBefore = null; + let socketAfterBurst = null; + let cpuAfterBurst = null; + let diagnosticBaseline = null; + let diagnosticInjected = null; + let schemaChecked = 0; + let schemaInvalid = 0; + const validateCapture = values => { + let bad = 0; + for (const event of values.events) { + try { assertCapture([event], schema.services['tinycloud-node'].fields); } catch { bad++; } + } + schemaChecked = values.events.length; + schemaInvalid = bad + values.invalid; + return { checked: schemaChecked, invalid: schemaInvalid, incomplete: values.incomplete, canary_hits: values.canary_hits, available: values.available }; + }; + const sample = () => { + const metrics = readMetrics(); + const hops = Object.fromEntries(['gelf_in', 'logship_gate', 'allowlist', 'request_profile', 'event_route', 'betterstack'].map(key => [key, componentCounters(metrics, key)])); + const values = capture(); + const point = { elapsed_ms: Date.now() - startedAt, source: hops.gelf_in.sent_events, gate: hops.logship_gate.sent_events, admitted: hops.request_profile.sent_events, sink: hops.betterstack.sent_events, capture: values.events.length, + burst_capture: burstEvidence(values.events, burstFirst, burstSize).received }; + samples.push(point); + // Only synthetic numeric evidence is persisted for an outer step timeout's always() diagnostic. + try { writeFileSync(join(scratch, 'evidence-state.json'), JSON.stringify({ startedAt, burstSent, socketBefore, cpuBefore, socketAfterBurst, cpuAfterBurst, diagnosticBaseline, diagnosticInjected, samples })); } catch { /* Live-resource diagnostics remain available if the snapshot write fails. */ } + return { point, hops, metrics: numericMetrics(metrics), values }; + }; + const diagnostics = async () => { + const last = sample(); + const emitted = command('docker', ['exec', names.emitter, 'cat', '/tmp/tc959-emitted-count'], { final: true, optional: true }); + const count = emitted.status === 0 && /^\d+\s*$/.test(emitted.stdout) ? Number(emitted.stdout.trim()) : burstSent; + const states = {}; + const startup = {}; + for (const role of ['sink', 'vector', 'node', 'ingress', 'emitter']) { + const value = inspect(names[role], true); + states[role] = value ? { running: value.State.Running, exit_code: value.State.ExitCode, oom_killed: value.State.OOMKilled, restart_count: value.RestartCount } : { state: 'not_created' }; + const output = command('docker', ['logs', '--tail', '80', names[role]], { final: true, optional: true }); + startup[role] = classifyStartupOutput(`${output.stdout ?? ''}\n${output.stderr ?? ''}`); + } + const burst = burstEvidence(last.values.events, burstFirst, burstSize); + const socketAfter = sockets(); + const cpuAfter = cpu(); + const delta = (before, after) => Number.isFinite(before) && Number.isFinite(after) ? after - before : null; + return { emitted_burst: count, burst: { ...burst, received_markers: Array.from({ length: burstSize }, (_, index) => burstFirst + index).filter(marker => !burst.missing.includes(marker)) }, capture: validateCapture(last.values), hops: last.hops, + diagnostic_controls: { baseline: diagnosticBaseline, injected: diagnosticInjected, observed: diagnosticCounts(last.values.events) }, + progress: progressEvidence(samples), socket_before: socketBefore, socket_after_healthy_burst: socketAfterBurst, socket_after_all_controls: socketAfter, + healthy_burst_socket_drops_delta: delta(socketBefore?.socket_drops, socketAfterBurst?.socket_drops), overall_socket_drops_delta: delta(socketBefore?.socket_drops, socketAfter.socket_drops), + cpu_before: cpuBefore, cpu_after_healthy_burst: cpuAfterBurst, cpu_after_all_controls: cpuAfter, + healthy_burst_cpu_throttled_periods_delta: delta(cpuBefore?.nr_throttled, cpuAfterBurst?.nr_throttled), overall_cpu_throttled_periods_delta: delta(cpuBefore?.nr_throttled, cpuAfter.nr_throttled), buffer_backpressure_errors: last.metrics, states, startup }; + }; + const cleanup = () => { + const owned = inventory(); + const counts = cleanupOwnedResources(owned, resource => { + if (resource.kind === 'container') { + const value = inspect(resource.name, true); + if (value?.State.Paused) command('docker', ['unpause', resource.name], { final: true }); + command('docker', ['rm', '--force', resource.name], { final: true }); + } else command('docker', [resource.kind, 'rm', resource.name], { final: true }); + }, id); + const remaining = inventory(); + assert.equal(remaining.length, 0, 'owned_cleanup_incomplete'); + const labelled = {}; + for (const [kind, args] of [['containers', ['ps', '--all', '--quiet']], ['networks', ['network', 'ls', '--quiet']], ['volumes', ['volume', 'ls', '--quiet']]]) { + const output = command('docker', [...args, '--filter', `label=tc959.owner=${owner}`], { final: true }).stdout.trim(); + labelled[kind] = output ? output.split(/\s+/).length : 0; + } + assert.equal(Object.values(labelled).reduce((sum, count) => sum + count, 0), 0, 'owned_cleanup_incomplete'); + return { removed: counts, remaining_labelled: labelled }; + }; + schema = JSON.parse(await readFile(join(root, 'log-shipper/fields.json'), 'utf8')); + if (options.cleanupOnly) { + // Workflow always() calls this even after the proof step's outer timeout. + let evidence; + let failure; + try { + const owned = inventory(); + if (owned.length) { + try { + const state = JSON.parse(await readFile(join(scratch, 'evidence-state.json'), 'utf8')); + const numeric = value => Number.isFinite(value) && value >= 0 ? value : null; + const pick = (value, keys) => Object.fromEntries(keys.map(key => [key, numeric(value?.[key])])); + startedAt = numeric(state.startedAt) ?? Date.now(); + burstSent = numeric(state.burstSent); + socketBefore = pick(state.socketBefore, ['requested_receive_buffer_bytes', 'rmem_max', 'effective_so_rcvbuf', 'socket_drops']); + cpuBefore = pick(state.cpuBefore, ['usage_usec', 'user_usec', 'system_usec', 'nr_periods', 'nr_throttled', 'throttled_usec']); + socketAfterBurst = pick(state.socketAfterBurst, ['requested_receive_buffer_bytes', 'rmem_max', 'effective_so_rcvbuf', 'socket_drops']); + cpuAfterBurst = pick(state.cpuAfterBurst, ['usage_usec', 'user_usec', 'system_usec', 'nr_periods', 'nr_throttled', 'throttled_usec']); + if (state.diagnosticBaseline) diagnosticBaseline = pick(state.diagnosticBaseline, ['warn', 'unclassified', 'error', 'dependency_error', 'total']); + if (state.diagnosticInjected) diagnosticInjected = pick(state.diagnosticInjected, ['warn', 'unclassified', 'error', 'dependency_error', 'total']); + if (Array.isArray(state.samples)) for (const point of state.samples.slice(-32)) samples.push(pick(point, ['elapsed_ms', 'source', 'gate', 'admitted', 'sink', 'capture', 'burst_capture'])); + } catch { /* An early timeout can precede the first synthetic numeric snapshot. */ } + for (const resource of owned.filter(value => value.kind === 'container')) { + const state = inspect(resource.name, true); + if (state?.State.Paused) command('docker', ['unpause', resource.name], { final: true, optional: true }); + } + if (!samples.length) startedAt = Date.now(); + sample(); await sleep(1000); sample(); await sleep(1000); + evidence = await diagnostics(); + if (evidence.capture.invalid || evidence.capture.canary_hits || evidence.capture.incomplete) failure = 'capture_boundary_failed'; + } + } finally { + const result = cleanup(); + await rm(scratch, { recursive: true, force: true }); + process.stdout.write(`${JSON.stringify({ status: failure ? 'failed' : 'cleaned', phase: 'always_cleanup', ...(evidence ? { evidence } : {}), cleanup: result })}\n`); + } + if (failure) throw new Error(failure); + return; + } + checkTime(); + await mkdir(scratch, { recursive: false }); + await mkdir(env.DOCKER_CONFIG); + let report = { status: 'failed', compose_proof: false, substitutions, dstack_tls_proof: false, udp_lossless: false }; + let failure; + const waitFor = async (predicate, attempts = 90) => { + for (let index = 0; index < attempts; index++) { checkTime(); if (await predicate()) return; await sleep(500); } + throw new Error('readiness_timeout'); + }; + const request = async (port, path, method = 'GET') => { + checkTime(); + const response = await fetch(`http://127.0.0.1:${port}${path}`, { method, headers: { authorization: `Bearer ${canary}`, 'x-request-id': canary, 'user-agent': canary }, signal: AbortSignal.timeout(3000), redirect: 'manual' }); + await response.arrayBuffer(); + return response.status; + }; + const labels = ['--label', `${owner}=${id}`, '--label', `tc959.owner=${owner}`]; + const create = (name, args) => docker('create', '--name', name, ...labels, ...args); + const loggingArgs = service => ['--log-driver', service.logging.driver, ...Object.entries(service.logging.options ?? {}).flatMap(([key, value]) => ['--log-opt', `${key}=${value}`])]; + const serviceArgs = (service, network) => { + const args = ['--network', network, '--restart', 'no', ...loggingArgs(service)]; + if (service.init) args.push('--init'); + if (service.user) args.push('--user', service.user); + if (service.read_only) args.push('--read-only'); + assert.equal(service.privileged ?? false, false); + for (const cap of service.cap_drop ?? []) args.push('--cap-drop', cap); + for (const option of service.security_opt ?? []) args.push('--security-opt', option); + if (service.mem_limit) args.push('--memory', String(service.mem_limit)); + if (service.memswap_limit) args.push('--memory-swap', String(service.memswap_limit)); + if (service.cpus) args.push('--cpus', String(service.cpus)); + for (const value of service.tmpfs ?? []) args.push('--tmpfs', value); + for (const [key, value] of Object.entries(service.labels ?? {})) args.push('--label', `${key}=${value}`); + for (const [key, value] of Object.entries(service.environment ?? {})) args.push('--env', `${key}=${value}`); + return args; + }; + const declaredVolumes = new Map(); + const disposableVolumeArgs = image => (declaredVolumes.get(image) ?? []).flatMap(path => ['--tmpfs', `${path}:rw,noexec,nosuid,size=8388608,mode=1777`]); + try { + phase = 'immutable_images'; + for (const image of [nodeImage, ingressImage, vectorImage]) { + assert.match(image, /@sha256:[a-f0-9]{64}$/); + command('docker', ['pull', image], { timeout: 150000 }); + const metadata = JSON.parse(docker('image', 'inspect', image))[0]; + assert.ok(metadata.RepoDigests.includes(image.replace(/:[^/:@]+@/, '@'))); + const volumes = Object.keys(metadata.Config.Volumes ?? {}); + assert.ok(volumes.every(path => ['/var/lib/vector', '/data', '/etc/letsencrypt'].includes(path)), 'unexpected_image_volume'); + declaredVolumes.set(image, volumes); + } + phase = 'compose_render'; + const composeArgs = ['compose', '--env-file', '/dev/null', '-f', join(root, 'docker-compose.dstack-postgres.yaml'), 'config']; + const unresolved = JSON.parse(docker(...composeArgs, '--no-interpolate', '--no-env-resolution', '--format', 'json')); + assert.equal(unresolved.secrets, undefined, 'deployment_secret_files_forbidden'); + assert.equal(unresolved.configs, undefined, 'deployment_config_files_forbidden'); + for (const service of Object.values(unresolved.services)) assert.equal(service.env_file, undefined, 'deployment_env_files_forbidden'); + const serialized = JSON.parse(docker(...composeArgs, '--format', 'json')); + const rendered = composeRuntimeValues(serialized); + const production = rendered.services; + phase = 'compose_images'; + assert.equal(production.tinycloud.image, nodeImage); + assert.equal(production['dstack-ingress'].image, ingressImage); + assert.equal(production.vector.image, vectorImage); + phase = 'compose_fields'; + // Refuse silently ignored compose fields: this is a projection with explicit substitutions, not a mirror. + const supported = new Set(['image', 'restart', 'labels', 'logging', 'ports', 'volumes', 'environment', 'networks', 'depends_on', 'entrypoint', 'command', 'init', 'user', 'read_only', 'cap_drop', 'security_opt', 'mem_limit', 'memswap_limit', 'cpus', 'tmpfs', 'privileged']); + for (const service of [production.tinycloud, production['dstack-ingress'], production.vector]) for (const key of Object.keys(service)) assert.ok(supported.has(key), 'unsupported_rendered_compose_field'); + phase = 'compose_ports'; + assert.equal(production.vector.volumes, undefined); + assert.equal(production.tinycloud.ports.length, 1); + assert.equal(production.tinycloud.ports[0].target, 8000); + assert.equal(production['dstack-ingress'].ports.length, 1); + assert.equal(production['dstack-ingress'].ports[0].target, 443); + for (const [service, port] of [[production.tinycloud, 8000], [production['dstack-ingress'], 443]]) { + assert.equal(service.ports[0].published, String(port)); + assert.equal(service.ports[0].protocol, 'tcp'); + assert.equal(service.ports[0].host_ip ?? '0.0.0.0', '0.0.0.0'); + } + phase = 'compose_mounts'; + assert.deepEqual(production.tinycloud.volumes.map(value => [value.type, value.source, value.target]), [['bind', '/var/run/dstack.sock', '/var/run/dstack.sock']]); + assert.deepEqual(production['dstack-ingress'].volumes.map(value => [value.type, value.source, value.target]).sort((a, b) => a[2].localeCompare(b[2])), [['volume', 'cert-data', '/etc/letsencrypt'], ['bind', '/var/run/dstack.sock', '/var/run/dstack.sock']]); + phase = 'compose_networks'; + assert.deepEqual(Object.keys(production.tinycloud.networks), ['default']); + assert.deepEqual(Object.keys(production['dstack-ingress'].networks), ['default']); + assert.deepEqual(Object.keys(production.vector.networks), ['logship']); + const networkFields = ['name', 'driver', 'internal', 'external', 'attachable', 'enable_ipv4', 'enable_ipv6', 'driver_opts', 'labels', 'ipam']; + report.compose_network_fields = Object.keys(rendered.networks.logship).map(key => networkFields.includes(key) ? key : 'unsupported').sort(); + assertLogshipNetwork(rendered.networks.logship); + phase = 'compose_compiler'; + const compiled = buildConfig({ runtimeProfile: true }); + report.compose_compiler_matches = { + serialized: isDeepStrictEqual(JSON.parse(serialized.services.vector.environment.VECTOR_CONFIG_JSON), compiled), + runtime: isDeepStrictEqual(JSON.parse(production.vector.environment.VECTOR_CONFIG_JSON), compiled), + }; + assert.deepEqual(JSON.parse(production.vector.environment.VECTOR_CONFIG_JSON), compiled, 'rendered_compose_compiler_mismatch'); + assert.equal(compiled.sources.gelf_in.receive_buffer_bytes, 8388608); + const [nodePort, ingressPort] = await Promise.all([freePort(), freePort()]); + const vectorService = structuredClone(production.vector); + vectorService.restart = 'no'; + const config = JSON.parse(vectorService.environment.VECTOR_CONFIG_JSON); + config.sinks.betterstack.uri = `http://${names.sink}:8080/`; + config.sources.acceptance_metrics = { type: 'internal_metrics', scrape_interval_secs: 1 }; + config.sinks.acceptance_metrics_out = { type: 'prometheus_exporter', inputs: ['acceptance_metrics'], address: '127.0.0.1:9598' }; + vectorService.environment = { ...vectorService.environment, BETTERSTACK_SOURCE_TOKEN: token, TINYCLOUD_LOGSHIP_PROFILE: 'errors_slow', VECTOR_CONFIG_JSON: JSON.stringify(config) }; + const nodeService = structuredClone(production.tinycloud); + nodeService.restart = 'no'; + nodeService.environment = { + TINYCLOUD_LOG__FORMAT: production.tinycloud.environment.TINYCLOUD_LOG__FORMAT, TINYCLOUD_LOG_LEVEL: 'normal', TINYCLOUD_KEYS__TYPE: 'Static', TINYCLOUD_KEYS__SECRET: Buffer.alloc(32, 9).toString('base64url'), + TINYCLOUD_TEE__MODE: 'Off', TINYCLOUD_TEE_MODE: 'off', TINYCLOUD_STORAGE__DATADIR: '/data', TINYCLOUD_STORAGE__DATABASE: 'sqlite:/data/caps.db?mode=rwc', TINYCLOUD_STORAGE__BLOCKS__TYPE: 'Local', TINYCLOUD_STORAGE__BLOCKS__PATH: '/data/blocks', ROCKET_ADDRESS: '0.0.0.0', TINYCLOUD_PORT: '8000', TINYCLOUD_SHARE_EMAIL__ENABLED: 'false', + }; + nodeService.tmpfs = ['/data:rw,nosuid,size=134217728,uid=1000,gid=1000,mode=0700']; + const ingressService = structuredClone(production['dstack-ingress']); + ingressService.restart = 'no'; + ingressService.environment = {}; + ingressService.entrypoint = ['nginx']; + ingressService.command = ['-g', 'daemon off;']; + if (declaredVolumes.get(ingressImage).length) ingressService.tmpfs = declaredVolumes.get(ingressImage).map(path => `${path}:rw,noexec,nosuid,size=8388608,mode=1777`); + for (const service of [vectorService, nodeService, ingressService]) for (const path of declaredVolumes.get(service.image)) assert.ok((service.tmpfs ?? []).some(value => value.startsWith(`${path}:`)), 'anonymous_image_volume_forbidden'); + // Logging options remain EXACTLY as rendered, including the real published UDP port 12201. + for (const service of [nodeService, ingressService]) assert.deepEqual(service.logging, production[service === nodeService ? 'tinycloud' : 'dstack-ingress'].logging); + const portMap = (target, published, protocol = 'tcp') => ({ [`${target}/${protocol}`]: [{ HostIp: '127.0.0.1', HostPort: String(published) }] }); + const vectorPorts = Object.fromEntries(production.vector.ports.map(port => [`${port.target}/${port.protocol}`, [{ HostIp: port.host_ip, HostPort: port.published }]])); + assert.deepEqual(vectorPorts, portMap(12201, 12201, 'udp')); + const vectorPublish = production.vector.ports.flatMap(port => ['--publish', `${port.host_ip}:${port.published}:${port.target}/${port.protocol}`]); + const nginxConfig = upstream => `worker_processes 1;\nerror_log /dev/stderr notice;\npid /tmp/nginx.pid;\nevents { worker_connections 1024; }\nhttp {\ninclude /etc/nginx/tc959-redacted.conf;\nserver { listen 80; location / { proxy_pass http://${upstream}; } }\n}\n`; + await writeFile(join(scratch, 'nginx.conf'), nginxConfig('127.0.0.1:1')); + phase = 'create_batch'; + docker('network', 'create', '--driver', rendered.networks.logship.driver, ...labels, names.logship); + const sinkArgs = ['--network', names.logship, '--read-only', '--cap-drop', 'ALL', '--security-opt', 'no-new-privileges:true', '--memory', '64m', '--memory-swap', '64m', '--cpus', '0.5', '--tmpfs', '/tmp:rw,noexec,nosuid,size=8388608,mode=1777', '--log-driver', 'none']; + create(names.sink, [...sinkArgs, ...disposableVolumeArgs(vectorImage), '--user', '10001:10001', '--mount', `type=bind,src=${join(root, 'log-shipper/fixtures/capture.json')},dst=/etc/vector/vector.json,readonly`, '--entrypoint', '/bin/sh', vectorImage, '-ec', 'mkdir -p /tmp/vector-data; exec vector --config /etc/vector/vector.json']); + create(names.vector, [...serviceArgs(vectorService, names.logship), ...vectorPublish, '--entrypoint', vectorService.entrypoint[0], vectorService.image, ...vectorService.entrypoint.slice(1)]); + create(names.node, [...serviceArgs(nodeService, 'bridge'), '--publish', `127.0.0.1:${nodePort}:8000`, nodeService.image]); + create(names.ingress, [...serviceArgs(ingressService, 'bridge'), '--publish', `127.0.0.1:${ingressPort}:80`, '--mount', `type=bind,src=${join(scratch, 'nginx.conf')},dst=/etc/nginx/nginx.conf,readonly`, '--mount', `type=bind,src=${join(root, 'deploy/ingress/redacted-logging.conf')},dst=/etc/nginx/tc959-redacted.conf,readonly`, '--entrypoint', ingressService.entrypoint[0], ingressService.image, ...ingressService.command]); + create(names.emitter, ['--network', 'bridge', '--label', 'tc.logship=tinycloud-node', ...loggingArgs(nodeService), ...disposableVolumeArgs(vectorImage), '--tmpfs', '/tmp:rw,noexec,nosuid,size=1048576,mode=1777', '--entrypoint', '/bin/sh', vectorImage, '-c', 'exec sleep 3600']); + // One batch is fully created before any start; no restart/recreate is allowed. + phase = 'start_batch'; + docker('start', names.sink, names.vector, names.node, names.emitter); + await waitFor(() => inspect(names.node).State.Running); + const nodeIP = inspect(names.node).NetworkSettings.Networks.bridge.IPAddress; + assert.ok(net.isIPv4(nodeIP)); + await writeFile(join(scratch, 'nginx.conf'), nginxConfig(`${nodeIP}:8000`)); + docker('start', names.ingress); + phase = 'listener_readiness'; + await awaitReadiness(async () => ({ + vector_udp_listener: hasUdpListener(command('docker', ['exec', names.vector, 'cat', '/proc/net/udp'], { optional: true }).stdout ?? '', 12201), + capture_tcp_listener: command('docker', ['exec', names.sink, 'nc', '-z', '-w', '1', '127.0.0.1', '8080'], { optional: true }).status === 0, + })); + phase = 'actual_compose_parity'; + const ingressMounts = [ + { type: 'bind', source: join(scratch, 'nginx.conf'), target: '/etc/nginx/nginx.conf', read_only: true }, + { type: 'bind', source: join(root, 'deploy/ingress/redacted-logging.conf'), target: '/etc/nginx/tc959-redacted.conf', read_only: true }, + ]; + for (const [service, name, networks, ports, mounts] of [[vectorService, names.vector, [names.logship], vectorPorts, []], [nodeService, names.node, ['bridge'], portMap(8000, nodePort), []], [ingressService, names.ingress, ['bridge'], portMap(80, ingressPort), ingressMounts]]) { + const actual = inspect(name); + assertServiceParity(service, actual, { networks, portBindings: ports, mounts }); + assert.equal(actual.Image, JSON.parse(docker('image', 'inspect', service.image))[0].Id); + assert.equal(actual.RestartCount, 0); + assert.equal(actual.Mounts.filter(mount => mount.Type === 'volume').length, 0, 'unlabelled_volume_forbidden'); + } + const actualVector = inspect(names.vector); + assert.equal(actualVector.Mounts.filter(mount => mount.Type !== 'tmpfs').length, 0); + const runtime = docker('exec', names.vector, 'cat', '/var/lib/vector/runtime.json'); + assert.deepEqual(JSON.parse(runtime), config, 'actual_runtime_config_mismatch'); + const network = JSON.parse(docker('network', 'inspect', names.logship))[0]; + assert.equal(network.Internal, false); + assert.equal(network.Driver, rendered.networks.logship.driver); + assert.deepEqual(network.Options, {}); + assert.equal(network.Attachable, false); + assert.equal(network.EnableIPv6, false); + assert.deepEqual(Object.values(network.Containers).map(value => value.Name).sort(), [names.sink, names.vector].sort()); + report.compose_proof = true; + phase = 'real_requests'; + await awaitReadiness(async () => { + const probe = async port => { try { return await request(port, '/healthz'); } catch (error) { return { state: classifyProbeError(error) }; } }; + return { node_healthz: await probe(nodePort), ingress_healthz: await probe(ingressPort), vector_running: inspect(names.vector).State.Running, sink_running: inspect(names.sink).State.Running }; + }); + const appReadyAt = Date.now(); + assert.equal(await request(nodePort, '/version'), 200); + assert.ok(await request(nodePort, '/invoke', 'POST') >= 400); + assert.equal(await request(ingressPort, '/version'), 200); + assert.ok(await request(ingressPort, '/invoke', 'POST') >= 400); + await request(ingressPort, `/TC959_SYNTHETIC_PATH?ticket=${encodeURIComponent(canary)}`); + await waitFor(() => { const events = capture().events; return events.some(e => e.event === 'node_request' && e.route === '/invoke' && e.status >= 400) && events.some(e => e.event === 'ingress_request' && e.status >= 400); }); + report.real_request_flow = true; + phase = 'isolation'; + const ingressIP = inspect(names.ingress).NetworkSettings.Networks.bridge.IPAddress; + const gateway = network.IPAM.Config[0].Gateway; + docker('exec', names.vector, '/bin/sh', '-c', 'command -v nc'); + docker('exec', names.vector, 'nc', '-z', '-w', '2', names.sink, '8080'); + let reverseReachable = 0; + for (const [address, port] of [[nodeIP, 8000], [ingressIP, 80], [gateway, nodePort], [gateway, ingressPort]]) { + const probe = command('docker', ['exec', names.vector, 'nc', '-z', '-w', '2', address, String(port)], { optional: true }); + assert.equal(probe.error, undefined); + if (probe.status === 0) reverseReachable++; + assert.equal(inspect(names.vector).State.Running, true); + } + const gelf = latency_us => JSON.stringify({ version: '1.1', host: 'synthetic', short_message: JSON.stringify(nodeRequest({ method: 'GET', route: '/healthz', status: 503, latency_us })), '_tc.logship': 'tinycloud-node', timestamp: Date.now() / 1000 }); + const hostControl = 7654322; + const peerControl = 7654323; + const injected = 7654321; + const udp = dgram.createSocket('udp4'); + try { + await new Promise((resolve, reject) => udp.send(Buffer.from(gelf(hostControl)), 12201, '127.0.0.1', error => error ? reject(error) : resolve())); + } finally { await new Promise(resolve => udp.close(resolve)); } + await waitFor(() => capture().events.some(event => event.latency_us === hostControl)); + const shipperIP = actualVector.NetworkSettings.Networks[names.logship].IPAddress; + docker('exec', names.sink, '/bin/sh', '-c', 'printf "%s" "$1" | nc -u -w 1 "$2" "$3"', 'probe', gelf(peerControl), shipperIP, '12201'); + await waitFor(() => capture().events.some(event => event.latency_us === peerControl)); + const appGateway = inspect(names.emitter).NetworkSettings.Networks.bridge.Gateway; + docker('exec', names.emitter, '/bin/sh', '-c', 'command -v nc'); + for (const [address, port] of [[shipperIP, 12201], [appGateway, 12201]]) { + const sent = command('docker', ['exec', names.emitter, '/bin/sh', '-c', 'printf "%s" "$1" | nc -u -w 1 "$2" "$3"', 'probe', gelf(injected), address, String(port)], { optional: true }); + assert.equal(sent.error, undefined); + if (sent.status !== 0 && !/unreachable|refused|timed out/i.test(sent.stderr)) throw new Error('isolation_sender_failed'); + } + await sleep(3000); + assert.equal(capture().events.filter(event => event.latency_us === injected).length, 0); + Object.assign(report, { blocked_injection_probes: 2, sender_positive_controls: 2, reverse_tcp_probes: 4, reverse_tcp_reachable: reverseReachable }); + const emit = payload => docker('exec', names.emitter, '/bin/sh', '-ec', 'printf "%s\\n" "$1" > /proc/1/fd/1', 'emit', payload); + phase = 'profile_controls'; + const beforeFast = componentCounters(readMetrics(), 'request_profile').received_events; + emit(JSON.stringify(nodeRequest({ route: '/healthz', status: 200, latency_us: fastMarker, authorization: canary, uri: canary, nested: { did: canary } }))); + // A subsequent eligible control confirms that the unpaced fast-success control traversed the driver. + const slowMarker = 1000001; + emit(JSON.stringify(nodeRequest({ route: '/healthz', status: 200, latency_us: slowMarker, authorization: canary }))); + await waitFor(() => capture().events.some(event => event.latency_us === slowMarker)); + await sleep(1500); + assert.equal(capture().events.filter(event => event.latency_us === fastMarker).length, 0); + const afterFast = componentCounters(readMetrics(), 'request_profile').received_events; + assert.ok(Number.isFinite(beforeFast) && Number.isFinite(afterFast) && afterFast >= beforeFast + 2); + report.fast_success_filtered = true; + phase = 'healthy_burst'; + socketBefore = sockets(); + cpuBefore = cpu(); + startedAt = Date.now(); + sample(); + const payload = JSON.stringify(nodeRequest({ route: '/healthz', status: 503, latency_us: '__MARKER__', authorization: canary, uri: canary })); + const [prefix, suffix] = payload.split('"__MARKER__"'); + // One exec; 500 distinct 503 lines, no sleeps, no pacing, no emission reduction. + const emitted = docker('exec', names.emitter, '/bin/sh', '-ec', 'i=0; while [ "$i" -lt 500 ]; do printf "%s%s%s\\n" "$1" "$(($3+i))" "$2" || exit 71; i=$((i+1)); done > /proc/1/fd/1; printf "%s\\n" "$i" > /tmp/tc959-emitted-count; printf "%s\\n" "$i"', 'burst', prefix, suffix, String(burstFirst)); + assert.match(emitted, /^500$/); + burstSent = Number(emitted); + // Fixed bounded sampling persists the exact subset even if loss is static; never retry the burst. + for (const offset of [0, 1000, 3000, 6000, 10000, 15000]) { + const delay = offset - (Date.now() - startedAt); + if (delay > 0) await sleep(delay); + sample(); + } + // Scope kernel/cgroup deltas to the healthy burst, before accepted outage-loss controls. + socketAfterBurst = sockets(); + cpuAfterBurst = cpu(); + sample(); + report.healthy_burst_progress = progressEvidence(samples.slice()); + phase = 'continuity'; + docker('pause', names.vector); + const continuityStart = Date.now(); + for (let index = 0; index < 30; index++) assert.equal(await request(nodePort, '/healthz'), 200); + assert.ok(Date.now() - continuityStart < 15000); + docker('unpause', names.vector); + const resumeMarker = 7654324; + emit(JSON.stringify(nodeRequest({ route: '/healthz', status: 503, latency_us: resumeMarker }))); + await waitFor(() => capture().events.some(event => event.latency_us === resumeMarker)); + report.continuity_requests = 30; + report.resumed_delivery = true; + phase = 'diagnostic_counts'; + const diagnostic = (level, message, target = 'tinycloud::runtime') => JSON.stringify({ timestamp: new Date().toISOString(), level, target, fields: { message, error: canary } }); + const total = (values, predicate, field) => values.filter(predicate).reduce((sum, value) => sum + value[field], 0); + // Baselines account for real app startup diagnostics: count occurrences, never aggregate rows. + // Drain startup's 60s/75s diagnostic reductions before measuring synthetic increments. + const startupDrain = 80000 - (Date.now() - appReadyAt); + if (startupDrain > 0) await sleep(startupDrain); + const baseline = diagnosticCounts(capture().events); + diagnosticBaseline = baseline; + diagnosticInjected = { warn: 0, unclassified: 0, error: 0, dependency_error: 0, total: 0 }; + const emitDiagnostic = (control, level, message, target) => { + emit(diagnostic(level, message, target)); + diagnosticInjected[control]++; + diagnosticInjected.total++; + }; + emitDiagnostic('warn', 'WARN', 'invalid link bind address; LAN listener not started'); + emitDiagnostic('warn', 'WARN', 'invalid link bind address; LAN listener not started'); + emitDiagnostic('unclassified', 'WARN', `raw tunnel close ${canary}`); + emitDiagnostic('error', 'ERROR', 'native share KV put failed'); + emitDiagnostic('unclassified', 'WARN', undefined, 'hyper::proto'); + emitDiagnostic('dependency_error', 'ERROR', undefined, 'sqlx::pool'); + emit(JSON.stringify(nodeRequest({ route: `/signed/kv/${canary}`, status: 503 }))); + emit(`raw panic ${canary}`); + sample(); + await waitFor(() => { + const values = capture().events; + const observed = diagnosticCounts(values); + return Object.keys(diagnosticInjected).every(key => observed[key] >= baseline[key] + diagnosticInjected[key]) + && total(values, e => e.event === 'logship_gate_summary_total' && e.reason === 'invalid_fields', 'count') >= 1 && total(values, e => e.event === 'logship_gate_summary_total' && e.reason === 'non_json', 'count') >= 1; + }, 180); + const events = capture().events; + const observed = diagnosticCounts(events); + for (const key of Object.keys(diagnosticInjected)) assert.equal(observed[key] - baseline[key], diagnosticInjected[key]); + Object.assign(report, { synthetic_warning_occurrences: diagnosticInjected.warn, unclassified_warning_occurrences: diagnosticInjected.unclassified, synthetic_error_occurrences: diagnosticInjected.error, dependency_error_occurrences: diagnosticInjected.dependency_error, synthetic_diagnostic_occurrences: diagnosticInjected.total }); + // Final gate is exact set equality. A duplicate cannot compensate for a missing marker. + assertHealthyBurst(events, burstFirst, burstSize, burstSent); + phase = 'completed'; + report.status = 'passed'; + } catch (error) { + failure = error; + report.failed_phase = phase; + report.code = error.code === 'ERR_ASSERTION' ? 'assertion_failed' : ['deadline_cleanup_margin', 'readiness_timeout', 'proof_command_failed', 'isolation_sender_failed'].includes(error.message) ? error.message : 'unexpected_failure'; + if (error.diagnostics) report.probes = error.diagnostics; + } finally { + // Bounded diagnostics ALWAYS precede cleanup, including failed assertions and readiness failures. + try { + const vector = inspect(names.vector, true); + if (vector?.State.Paused) command('docker', ['unpause', names.vector], { final: true, optional: true }); + if (samples.length < 3) { sample(); await sleep(1000); sample(); await sleep(1000); } + report.evidence = await diagnostics(); + const evidence = report.evidence; + if (evidence.capture.invalid || evidence.capture.canary_hits || evidence.capture.incomplete || (report.status === 'passed' && !evidence.capture.available)) { + report.status = 'failed'; report.code = 'capture_boundary_failed'; failure ??= new Error('capture_boundary_failed'); + } + if (report.status === 'passed') { + for (const field of ['rmem_max', 'effective_so_rcvbuf', 'socket_drops']) assert.ok(Number.isSafeInteger(evidence.socket_before?.[field])); + assert.ok(Object.hasOwn(evidence.cpu_before ?? {}, 'nr_throttled')); + for (const measurement of [evidence.socket_after_healthy_burst, evidence.socket_after_all_controls]) for (const field of ['rmem_max', 'effective_so_rcvbuf', 'socket_drops']) assert.ok(Number.isSafeInteger(measurement?.[field])); + assert.ok(Object.hasOwn(evidence.cpu_after_healthy_burst ?? {}, 'nr_throttled')); + assert.ok(Object.hasOwn(evidence.cpu_after_all_controls, 'nr_throttled')); + for (const key of ['source', 'gate', 'admitted', 'sink', 'capture']) assert.ok(Number.isFinite(evidence.progress.latest[key])); + for (const value of Object.values(evidence.states)) { + assert.equal(value.restart_count, 0); + assert.equal(value.running, true); + assert.equal(value.oom_killed, false); + } + } + } catch { + report.status = 'failed'; report.code = 'diagnostics_incomplete'; failure ??= new Error('diagnostics_incomplete'); + } finally { + try { report.cleanup = cleanup(); } catch { report.status = 'failed'; report.code = 'owned_cleanup_incomplete'; failure ??= new Error('owned_cleanup_incomplete'); } + await rm(scratch, { recursive: true, force: true }); + } + process.stdout.write(`${JSON.stringify(report)}\n`); + } + if (failure) process.exitCode = 1; +} + +if (process.argv[1] && import.meta.url === pathToFileURL(resolve(process.argv[1])).href) { + main().catch(error => { + const known = new Set(['invalid_arguments', 'explicit_go_required', 'invalid_deadline', 'disposable_hosted_runner_required', 'deadline_cleanup_margin', 'owned_cleanup_incomplete']); + process.stdout.write(`${JSON.stringify({ status: 'failed', phase, code: known.has(error.message) ? error.message : 'proof_failed' })}\n`); + process.exitCode = 1; + }); +} diff --git a/scripts/tc959-docker.test.mjs b/scripts/tc959-docker.test.mjs new file mode 100644 index 00000000..ac7f84ee --- /dev/null +++ b/scripts/tc959-docker.test.mjs @@ -0,0 +1,167 @@ +import test from 'node:test'; +import assert from 'node:assert/strict'; +import { spawnSync } from 'node:child_process'; +import { fileURLToPath } from 'node:url'; +import { parseArgs, assertCapture, resourceNames } from './tc959-docker.mjs'; +import { assertHostedRunner, cleanupOwnedResources, burstEvidence, assertHealthyBurst, progressEvidence, assertServiceParity, assertLogshipNetwork, composeRuntimeValues, socketEvidence, numericMetrics, diagnosticCounts } from './tc959-compose-proof.mjs'; + +const request = { ts: '2026-10-16T12:00:00.000Z', level: 'info', event: 'node_request', svc: 'api', method: 'GET', route: '/healthz', status: 200, latency_us: 12 }; +const ingress = { ...request, event: 'ingress_request', svc: 'ingress', request_time_seconds: 0.001 }; +delete ingress.latency_us; + +test('Docker requires an explicit disposable hosted CI opt in', () => { + assert.throws(() => parseArgs([])); + assert.throws(() => parseArgs(['--go', '--unknown'])); + assert.throws(() => parseArgs(['--go'])); + assert.equal(parseArgs(['--go', '--ci']).ci, true); +}); + +test('the executable CI entry point refuses local execution without invoking Docker or leaking environment', () => { + const child = spawnSync(process.execPath, [fileURLToPath(new URL('./tc959-docker.mjs', import.meta.url)), '--go', '--ci'], { encoding: 'utf8', timeout: 5000, env: { PATH: '/nonexistent', BETTERSTACK_SOURCE_TOKEN: 'TC959_SYNTHETIC_NOT_TO_PRINT' } }); + assert.equal(child.status, 1); + assert.deepEqual(JSON.parse(child.stdout), { status: 'failed', phase: 'preflight', code: 'disposable_hosted_runner_required' }); + assert.equal(child.stderr, ''); + assert.equal(child.stdout.includes('TC959_SYNTHETIC'), false); +}); + +test('all resource names carry the owner and unique run', () => { + const names = resourceNames('abc123'); + assert.equal(new Set(Object.values(names)).size, Object.keys(names).length); + assert.ok(Object.values(names).every(name => name.startsWith('tc959-n0-abc123-'))); +}); + +test('capture rejects unsafe values even when all request positive controls are present', () => { + const baseline = [request, { ...request, route: '/version' }, { ...request, method: 'POST', route: '/invoke', status: 401 }, ingress]; + assert.doesNotThrow(() => assertCapture(baseline)); + assert.doesNotThrow(() => assertCapture([request])); // errors_slow intentionally excludes fast healthy controls. + for (const poison of [{ authorization: 'synthetic-bearer' }, { route: '/raw-secret' }, { request_id: 'anything' }, { request_id_replaced: true }, { latency_us: -1 }, { status: 999 }, { extra: 'TC959_SYNTHETIC' }]) { + assert.throws(() => assertCapture([{ ...request, ...poison }, ...baseline.slice(1)])); + } +}); + +const hosted = { GITHUB_ACTIONS: 'true', RUNNER_ENVIRONMENT: 'github-hosted', RUNNER_OS: 'Linux', GITHUB_RUN_ID: '12345', GITHUB_RUN_ATTEMPT: '1', RUNNER_TEMP: '/home/runner/work/_temp' }; +test('CI guard rejects local and self-hosted Docker before any daemon operation', () => { + assert.doesNotThrow(() => assertHostedRunner(hosted)); + for (const patch of [{ GITHUB_ACTIONS: undefined }, { RUNNER_ENVIRONMENT: 'self-hosted' }, { RUNNER_OS: 'macOS' }, { GITHUB_RUN_ID: '' }, { GITHUB_RUN_ATTEMPT: '' }, { RUNNER_TEMP: '/tmp/local' }]) { + assert.throws(() => assertHostedRunner({ ...hosted, ...patch })); + } +}); + +test('cleanup validates the entire ownership boundary before deleting anything', () => { + const owned = (kind, name) => ({ kind, name, labels: { 'tc959.owner': 'tc959-n0', 'tc959-n0': 'run1' } }); + const resources = [owned('container', 'tc959-n0-run1-node'), owned('network', 'tc959-n0-run1-logship'), owned('volume', 'tc959-n0-run1-data')]; + const removed = []; + assert.deepEqual(cleanupOwnedResources(resources, value => removed.push(value.name), 'run1'), { containers: 1, networks: 1, volumes: 1 }); + assert.equal(removed.length, 3); + for (const poison of [ + { ...resources[0], labels: { 'tc959.owner': 'someone-else', 'tc959-n0': 'run1' } }, + { ...resources[0], labels: { 'tc959.owner': 'tc959-n0', 'tc959-n0': 'other-run' } }, + { ...resources[0], name: 'production-node' }, + { ...resources[0], kind: 'image' }, + ]) { + let calls = 0; + assert.throws(() => cleanupOwnedResources([...resources, poison], () => calls++, 'run1')); + assert.equal(calls, 0, 'foreign resources must never be deleted, even after an owned item'); + } +}); + +test('healthy burst requires its exact distinct set, not a compensating duplicate or a fast success', () => { + const events = Array.from({ length: 500 }, (_, index) => ({ ...request, status: 503, latency_us: 9000000 + index })); + assert.deepEqual(burstEvidence(events, 9000000, 500), { expected: 500, received: 500, unique: 500, missing: [], duplicates: [] }); + assert.doesNotThrow(() => assertHealthyBurst(events, 9000000, 500, 500)); + assert.throws(() => assertHealthyBurst(events, 9000000, 500, 499)); + const compensated = [...events.slice(1), events[1], { ...request, latency_us: 8000000 }]; + const evidence = burstEvidence(compensated, 9000000, 500); + assert.equal(evidence.received, 500); + assert.deepEqual(evidence.missing, [9000000]); + assert.deepEqual(evidence.duplicates, [{ marker: 9000001, count: 2 }]); + assert.throws(() => assertHealthyBurst(compensated, 9000000, 500, 500)); + assert.throws(() => assertHealthyBurst(events.slice(1), 9000000, 500, 500)); + assert.equal(burstEvidence([{ ...request, latency_us: 8000000 }], 9000000, 500).received, 0); +}); + +test('timed per-hop evidence distinguishes continued drainage from an observed plateau', () => { + const sample = (elapsed_ms, source, gate, admitted, sink, capture) => ({ elapsed_ms, source, gate, admitted, sink, capture }); + const first = sample(0, 500, 500, 500, 200, 200); + const later = sample(1000, 500, 500, 500, 300, 300); + const evidence = progressEvidence([first, later, sample(2000, 500, 500, 500, 300, 300)]); + assert.equal(evidence.plateau, false); + assert.equal(evidence.deltas.capture, 100); + assert.equal(evidence.latest.admitted, 500); + assert.equal(evidence.plateaus.source, true); + assert.equal(evidence.plateaus.capture, false); + const burstStatic = [first, later, sample(2000, 500, 500, 500, 400, 400)].map(point => ({ ...point, burst_capture: 200 })); + assert.equal(progressEvidence(burstStatic).burst_plateau, true, 'other captured controls must not hide a static burst subset'); + assert.equal(progressEvidence([later, sample(2000, 500, 500, 500, 300, 300), sample(3000, 500, 500, 500, 300, 300)]).plateau, true); + assert.equal(progressEvidence([first]).plateau, false); + assert.equal(progressEvidence([first, { ...later, sink: null }]).deltas.sink, null); +}); + +test('canonical Compose dollar escaping becomes runtime variables rather than shell PID expansion', () => { + const runtime = composeRuntimeValues({ + environment: { TC959_VALUE: 'TC959_SYNTHETIC_$$literal' }, + entrypoint: ['/bin/sh', '-ec', 'printf "%s" "$$TC959_VALUE"'], + config: JSON.stringify({ condition: '"$${TINYCLOUD_LOGSHIP_PROFILE}" == "all_requests"' }), + }); + const child = spawnSync(runtime.entrypoint[0], runtime.entrypoint.slice(1), { env: runtime.environment, encoding: 'utf8' }); + assert.equal(child.status, 0); + assert.equal(child.stdout, 'TC959_SYNTHETIC_$literal'); + assert.equal(JSON.parse(runtime.config).condition, '"${TINYCLOUD_LOGSHIP_PROFILE}" == "all_requests"'); +}); + +test('normal bridge defaults cannot hide external, routed or host-changing network options', () => { + assertLogshipNetwork({ name: 'synthetic_logship', driver: 'bridge' }); + assertLogshipNetwork({ name: 'synthetic_logship', driver: 'bridge', internal: false, external: false, attachable: false, enable_ipv4: true, enable_ipv6: false, driver_opts: {}, labels: {}, ipam: { driver: 'default', config: [], options: {} } }); + for (const poison of [{ driver: 'host' }, { internal: true }, { external: true }, { enable_ipv4: false }, { enable_ipv6: true }, { driver_opts: { 'com.docker.network.bridge.name': 'foreign' } }, { ipam: { config: [{ subnet: '10.0.0.0/8' }] } }, { unknown_option: true }]) { + assert.throws(() => assertLogshipNetwork({ driver: 'bridge', ...poison })); + } +}); + +test('actual container parity catches image, GELF option, isolation and resource drift', () => { + const service = { image: 'example@sha256:abc', user: '10001:10001', read_only: true, init: true, cap_drop: ['ALL'], security_opt: ['no-new-privileges:true'], mem_limit: '67108864', memswap_limit: '67108864', cpus: 0.5, tmpfs: ['/var/lib/vector:rw,noexec,nosuid,size=8m,uid=10001,gid=10001,mode=0700'], labels: { 'tc.logship': 'tinycloud-node' }, logging: { driver: 'gelf', options: { 'gelf-address': 'udp://127.0.0.1:12201', mode: 'non-blocking', 'max-buffer-size': '4m', 'cache-disabled': 'true' } } }; + const inspect = { Config: { Image: service.image, User: service.user, Labels: service.labels }, HostConfig: { ReadonlyRootfs: true, Init: true, Privileged: false, CapDrop: ['ALL'], SecurityOpt: ['no-new-privileges:true'], Memory: 67108864, MemorySwap: 67108864, NanoCpus: 500000000, Tmpfs: { '/var/lib/vector': service.tmpfs[0].split(':')[1] }, LogConfig: { Type: 'gelf', Config: service.logging.options }, PortBindings: { '12201/udp': [{ HostIp: '127.0.0.1', HostPort: '12201' }] } }, NetworkSettings: { Networks: { 'tc959-n0-run1-logship': {} }, Ports: { '12201/udp': [{ HostIp: '127.0.0.1', HostPort: '12201' }] } } }; + const boundary = { networks: ['tc959-n0-run1-logship'], portBindings: inspect.HostConfig.PortBindings }; + assert.doesNotThrow(() => assertServiceParity(service, inspect, boundary)); + for (const poison of [ + { ...inspect, Config: { ...inspect.Config, Image: 'mutable:latest' } }, + { ...inspect, HostConfig: { ...inspect.HostConfig, LogConfig: { Type: 'json-file', Config: {} } } }, + { ...inspect, HostConfig: { ...inspect.HostConfig, Memory: 134217728 } }, + { ...inspect, HostConfig: { ...inspect.HostConfig, SecurityOpt: [] } }, + { ...inspect, NetworkSettings: { ...inspect.NetworkSettings, Networks: { bridge: {} } } }, + { ...inspect, HostConfig: { ...inspect.HostConfig, Tmpfs: {} } }, + { ...inspect, Mounts: [{ Type: 'bind', Source: '/var/run/docker.sock', Destination: '/var/run/docker.sock', RW: true }] }, + { ...inspect, Config: { ...inspect.Config, User: 'root' } }, + ...[{}, { '12201/udp': null }, { '12201/udp': [] }, { '12201/udp': [{ HostIp: '0.0.0.0', HostPort: '12201' }] }, { '12201/udp': [{ HostIp: '127.0.0.1', HostPort: '12202' }] }].map(Ports => ({ ...inspect, NetworkSettings: { ...inspect.NetworkSettings, Ports } })), + ]) assert.throws(() => assertServiceParity(service, poison, boundary)); +}); + +test('socket evidence measures effective receive buffer and drops rather than assuming requested bytes', () => { + const observed = socketEvidence('UNCONN 0 0 0.0.0.0:12201 0.0.0.0:*\n skmem:(r0,rb425984,t0,tb212992,f0,w0,o0,bl0,d7)', '212992'); + assert.deepEqual(observed, { requested_receive_buffer_bytes: 8388608, rmem_max: 212992, effective_so_rcvbuf: 425984, socket_drops: 7 }); + assert.equal(socketEvidence('UNCONN 0 0 0.0.0.0:12201', 'private').effective_so_rcvbuf, null); + assert.equal(socketEvidence('', '212992').socket_drops, null); +}); + +test('buffer and error diagnostics never expose raw metric labels or invent absent counters', () => { + const observed = numericMetrics('vector_buffer_events{component_id="betterstack",secret="TC959_SYNTHETIC"} 17\nvector_component_errors_total{component_id="betterstack"} 2\nvector_component_discarded_events_total{component_id="betterstack"} 3\nvector_component_received_events_total{component_id="betterstack"} 500\nvector_buffer_byte_size{component_id="betterstack"} 1024'); + assert.equal(observed.buffer_events, 17); + assert.equal(observed.component_errors_total, 2); + assert.equal(observed.component_discarded_events_total, 3); + assert.equal(observed.buffer_byte_size, 1024); + assert.equal(JSON.stringify(observed).includes('TC959_SYNTHETIC'), false); + assert.equal(numericMetrics('').buffer_events, null); +}); + +test('diagnostic acceptance sums aggregated occurrences instead of counting output rows', () => { + const observed = diagnosticCounts([ + { event: 'node_warning', event_code: 'link_bind_invalid', event_count: 2 }, + { event: 'node_warning', event_code: 'unclassified', event_count: 1 }, + { event: 'node_error', event_code: 'share_native_kv_put_failed', event_count: 1 }, + { event: 'node_error', event_code: 'unclassified', event_count: 3 }, + { event: 'node_error', event_code: 'link_bind_invalid', event_count: 100 }, + { event: 'node_warning', event_code: 'unclassified', event_count: 'TC959_SYNTHETIC' }, + null, + ]); + assert.deepEqual(observed, { warn: 2, unclassified: 1, error: 1, dependency_error: 3, total: 107 }); + assert.equal(JSON.stringify(observed).includes('TC959_SYNTHETIC'), false); +}); diff --git a/scripts/tc959-logship.mjs b/scripts/tc959-logship.mjs new file mode 100644 index 00000000..5ee841d0 --- /dev/null +++ b/scripts/tc959-logship.mjs @@ -0,0 +1,122 @@ +import { readFileSync, writeFileSync } from 'node:fs'; +import { fileURLToPath } from 'node:url'; +import { resolve } from 'node:path'; +import { vectorTests, requestProfileTests } from '../log-shipper/cases.mjs'; + +const root = fileURLToPath(new URL('../', import.meta.url)); +const load = name => JSON.parse(readFileSync(resolve(root, 'log-shipper', name), 'utf8')); +export const nodeImage = 'ghcr.io/tinycloudlabs/tinycloud-node@sha256:4bdae4fc232d886bb56bfbce4ec62ed4b8fb4e1369a01f6afb73d06dd68c188f'; +export const ingressImage = 'ghcr.io/tinycloudlabs/tinycloud-node-ingress@sha256:63c1c44e2ded5b73a5f174807b91ca677826974df0f9ab3045f6ec87865a5744'; +export const vectorImage = 'timberio/vector:0.59.0-alpine@sha256:0e36bc2a290039e9b6a5e92f04bd2f133223506f72d09682c1df16c015172b7a'; +const remap = (inputs, source, options = {}) => ({ type: 'remap', inputs, source, drop_on_error: true, drop_on_abort: true, ...options }); +const aliases = { + '/attestation?': '/attestation', + '/.well-known/encryption/network/?': '/.well-known/encryption/network/', + '/hooks/events?': '/hooks/events', + '/hooks/webhooks?': '/hooks/webhooks', + '/public//kv?': '/public//kv', +}; + +/** Compile one boundary for native tests, hosted Docker proof, and compose. */ +export function buildConfig({ sinkUri = 'https://s2795437.us-west-2a.betterstackdata.com/', dataDir = '/var/lib/vector', sourceAddress = '0.0.0.0:12201', token, profile = 'errors_slow', slowThresholdUs = 1000000, runtimeProfile = false } = {}) { + if (!['errors_slow', 'all_requests'].includes(profile)) throw new TypeError('invalid logship profile'); + if (!Number.isSafeInteger(slowThresholdUs) || slowThresholdUs < 0) throw new TypeError('invalid logship slow threshold'); + if (typeof runtimeProfile !== 'boolean') throw new TypeError('invalid runtime profile choice'); + const profileExpression = runtimeProfile ? '"${TINYCLOUD_LOGSHIP_PROFILE}"' : JSON.stringify(profile); + const schema = load('fields.json').services['tinycloud-node']; + const diagnostics = load('diagnostics.json'); + let sanitize = readFileSync(resolve(root, 'log-shipper/sanitize.vrl'), 'utf8') + .replaceAll('__METHODS__', JSON.stringify(schema.fields.method.values)) + .replaceAll('__ROUTES__', JSON.stringify(schema.fields.route.values)) + .replace('__ROUTE_ALIASES__', JSON.stringify(aliases)) + .replace('__DIAGNOSTICS__', JSON.stringify(diagnostics.exact)) + .replace('__PREFIX_DIAGNOSTICS__', Object.entries(diagnostics.prefix).sort(([a], [b]) => a.length - b.length).map(([prefix, code]) => `if starts_with(msg, ${JSON.stringify(prefix)}) { code = ${JSON.stringify(code)} }`).join('\n')); + const config = { + data_dir: dataDir, + sources: { gelf_in: { + type: 'socket', mode: 'udp', address: sourceAddress, max_length: 262144, receive_buffer_bytes: 8388608, + framing: { method: 'chunked_gelf', chunked_gelf: { decompression: 'Auto' } }, decoding: { codec: 'bytes' }, + } }, + transforms: { + // Parse GELF ourselves: native decoder errors can echo malformed values. + gelf_envelope: remap(['gelf_in'], `packet = string(.message) ?? "" +if length(packet) > 262144 { + . = {"reason": "oversized"} +} else { + outer, err = parse_json(packet) + if err != null || !is_object(outer) || (outer.version != "1.1" && outer.version != "1.0") { + . = {"reason": "malformed_envelope"} + } else if exists(outer.partial_message) || exists(outer._partial_message) { + . = {"reason": "partial"} + } else { + label = get(outer, ["_tc.logship"]) ?? null + . = {"_tc.logship": label, "message": outer.short_message} + } +}`), + logship_gate: remap(['gelf_envelope'], `if exists(.reason) { + . = {"reason": .reason} +} else { +label = string(get(., ["_tc.logship"]) ?? null) ?? "" +raw = .message +reason = "" +if label == "" { reason = "unlabelled" } +else if !includes(["tinycloud-node", "tinycloud-ingress"], label) { reason = "unexpected_label" } +else if exists(.partial_message) { reason = "partial" } +else if !is_string(raw) { reason = "malformed_envelope" } +else if length(string!(raw)) > 65536 { reason = "oversized" } +if reason != "" { + . = {"reason": reason} +} else { + parsed, err = parse_json(string!(raw)) + if err != null || !is_object(parsed) { . = {"reason": "non_json"} } + else if exists(parsed.partial_message) { . = {"reason": "partial"} } + else { + target = string(parsed.target) ?? "" + level = downcase(string(parsed.level) ?? "") + if label == "tinycloud-node" && !includes(["warn", "error"], level) && target != "tinycloud" && !starts_with(target, "tinycloud::") && target != "tinycloud_core" && !starts_with(target, "tinycloud_core::") { + . = {"reason": "unknown_target"} + } else if label == "tinycloud-node" && !includes(["warn", "error"], level) && (target != "tinycloud::request" || level != "info") { + . = {"reason": "filtered_level"} + } else { . = {"label": label, "parsed": parsed} } + } +} +}`), + gate_route: { type: 'route', inputs: ['logship_gate'], route: { candidate: 'exists(.parsed)', rejected: 'exists(.reason)' } }, + allowlist: remap(['gate_route.candidate'], sanitize, { reroute_dropped: true }), + gate_counts: remap(['gate_route.rejected', 'gate_route._unmatched', 'allowlist.dropped', 'event_route._unmatched'], `reason = .reason +if !includes(${JSON.stringify(schema.fields.reason.values)}, reason) { reason = "invalid_fields" } +. = {"reason": reason, "count": 1}`), + gate_reduce: { type: 'reduce', inputs: ['gate_counts'], group_by: ['reason'], end_every_period_ms: 60000, expire_after_ms: 75000, flush_period_ms: 1000, merge_strategies: { count: 'sum' } }, + gate_output: remap(['gate_reduce'], `. = {"ts": format_timestamp!(now(), format: "%Y-%m-%dT%H:%M:%S%.3fZ"), "level": "warn", "event": "logship_gate_summary_total", "svc": "logship", "reason": .reason, "count": .count}`), + request_profile: { type: 'filter', inputs: ['allowlist'], condition: `${profileExpression} == "all_requests" || includes(["node_warning", "node_error"], .event) || (int(.status) ?? 0) >= 400 || (.event == "node_request" && (int(.latency_us) ?? 0) > ${slowThresholdUs}) || (.event == "ingress_request" && (to_float(.request_time_seconds) ?? 0.0) > ${(slowThresholdUs / 1000000).toFixed(6)})` }, + event_route: { type: 'route', inputs: ['request_profile'], route: { request: '.event == "node_request" || .event == "ingress_request"', diagnostic: '.event == "node_warning" || .event == "node_error"' } }, + diagnostic_reduce: { type: 'reduce', inputs: ['event_route.diagnostic'], group_by: ['event', 'event_code', 'level', 'svc'], end_every_period_ms: 60000, expire_after_ms: 75000, flush_period_ms: 1000, merge_strategies: { event_count: 'sum', ts: 'discard' } }, + diagnostic_output: remap(['diagnostic_reduce'], `. = {"ts": format_timestamp!(now(), format: "%Y-%m-%dT%H:%M:%S%.3fZ"), "level": .level, "event": .event, "svc": "api", "event_code": .event_code, "event_count": .event_count}`), + }, + sinks: { betterstack: { + type: 'http', inputs: ['event_route.request', 'diagnostic_output', 'gate_output'], method: 'post', uri: sinkUri, + encoding: { codec: 'json' }, framing: { method: 'newline_delimited' }, compression: 'gzip', + auth: { strategy: 'bearer', token: token ?? 'SECRET[bs.bs_token]' }, + batch: { max_bytes: 262144, timeout_secs: 1 }, + buffer: { type: 'memory', max_events: 1000, when_full: 'block' }, + request: { timeout_secs: 10, retry_max_duration_secs: 300 }, + healthcheck: { enabled: false }, + } }, + }; + if (token === undefined) config.secret = { bs: { type: 'directory', path: `${dataDir}/secrets`, remove_trailing_whitespace: true } }; + return config; +} + +if (process.argv[1] && resolve(process.argv[1]) === fileURLToPath(import.meta.url)) { + const [command, output, option, profileOption] = process.argv.slice(2); + if (!['render-vector', 'render-tests'].includes(command) || !output) throw new Error('usage: tc959-logship.mjs render-tests OUTPUT [PROFILE] | render-vector OUTPUT [LOCAL_SINK_URI] [PROFILE]'); + const profile = (command === 'render-tests' ? option : profileOption) ?? 'errors_slow'; + const sinkUri = command === 'render-vector' ? option : undefined; + const config = buildConfig({ profile, ...(sinkUri ? { sinkUri, token: 'tc959-synthetic-only' } : {}) }); + if (command === 'render-tests') { + delete config.secret; + config.sinks = { discard: { type: 'blackhole', inputs: ['event_route.request', 'diagnostic_output', 'gate_output'] } }; + config.tests = [...vectorTests, ...requestProfileTests(profile)]; + } + writeFileSync(output, JSON.stringify(config, null, 2) + '\n'); +} diff --git a/scripts/tc959-readiness.mjs b/scripts/tc959-readiness.mjs new file mode 100644 index 00000000..df5209e3 --- /dev/null +++ b/scripts/tc959-readiness.mjs @@ -0,0 +1,68 @@ +const states = new Set(['connection_refused', 'connection_reset', 'timeout', 'dns', 'network', 'not_running']); + +/** Classify an exception without copying its message, URL, headers or cause. */ +export function classifyProbeError(error) { + const code = error?.cause?.code ?? error?.code; + if (error?.name === 'TimeoutError' || error?.name === 'AbortError' || code === 'ETIMEDOUT' || code === 'UND_ERR_CONNECT_TIMEOUT') return 'timeout'; + if (code === 'ECONNREFUSED') return 'connection_refused'; + if (code === 'ECONNRESET' || code === 'UND_ERR_SOCKET') return 'connection_reset'; + if (code === 'ENOTFOUND' || code === 'EAI_AGAIN') return 'dns'; + return 'network'; +} + +function sanitize(value) { + if (Number.isInteger(value) && value >= 100 && value <= 599) return { state: 'http', status: value }; + if (value === true) return { state: 'ready' }; + if (value && states.has(value.state)) return { state: value.state }; + return { state: 'not_running' }; +} + +/** Keep only per-probe typed state. A failed probe never masks a passing one. */ +export async function awaitReadiness(probe, { attempts = 90, intervalMs = 500 } = {}) { + let diagnostics = {}; + for (let index = 0; index < attempts; index++) { + const observed = await probe(); + diagnostics = Object.fromEntries(Object.entries(observed).map(([name, value]) => [name, sanitize(value)])); + if (Object.values(diagnostics).every(value => value.state === 'ready' || (value.state === 'http' && value.status === 200))) return diagnostics; + if (index + 1 < attempts && intervalMs > 0) await new Promise(resolve => setTimeout(resolve, intervalMs)); + } + const error = new Error('readiness_timeout'); + error.diagnostics = diagnostics; + throw error; +} + +/** Synthetic fixture diagnostics only; never return a line or matched value. */ +export function classifyStartupOutput(text) { + const output = []; + if (/failed to start tinycloud-node|panicked/i.test(text)) output.push('application_startup_failed'); + if (/invalid value|unknown variant|missing field|configuration error/i.test(text)) output.push('invalid_configuration'); + if (/permission denied|operation not permitted/i.test(text)) output.push('permission_denied'); + if (/nginx: \[emerg\]|configuration file.*test failed/i.test(text)) output.push('nginx_startup_failed'); + if (/connect\(\) failed.*upstream|connection refused/i.test(text)) output.push('upstream_connection_refused'); + if (/address already in use/i.test(text)) output.push('address_in_use'); + return output; +} + +/** Linux socket-table readiness; a running process alone can still lose UDP. */ +export function hasUdpListener(table, port) { + const suffix = `:${port.toString(16).padStart(4, '0')}`.toUpperCase(); + return table.split('\n').some(line => { + const fields = line.trim().split(/\s+/); + return /^\d+:$/.test(fields[0]) && /^[0-9A-F]{8}:[0-9A-F]{4}$/i.test(fields[1] ?? '') && fields[1].toUpperCase().endsWith(suffix); + }); +} + +/** Missing metrics stay unknown (null), never fabricated as zero. */ +export function componentCounters(text, component) { + const names = { component_received_events_total: 'received_events', component_sent_events_total: 'sent_events', component_errors_total: 'errors', component_discarded_events_total: 'discarded_events' }; + const counts = { received_events: null, sent_events: null, errors: null, discarded_events: null }; + for (const line of text.split('\n')) { + const match = /^(?:vector_)?([a-z_]+)\{([^}]*)\}\s+([0-9.eE+-]+)(?:\s|$)/.exec(line); + if (!match || !Object.hasOwn(names, match[1]) || !match[2].split(',').includes(`component_id="${component}"`)) continue; + const value = Number(match[3]); + if (!Number.isSafeInteger(value) || value < 0) continue; + const name = names[match[1]]; + counts[name] = (counts[name] ?? 0) + value; + } + return counts; +} diff --git a/scripts/tc959-readiness.test.mjs b/scripts/tc959-readiness.test.mjs new file mode 100644 index 00000000..3adb3c59 --- /dev/null +++ b/scripts/tc959-readiness.test.mjs @@ -0,0 +1,81 @@ +import assert from 'node:assert/strict'; +import { createServer } from 'node:http'; +import test from 'node:test'; +import { awaitReadiness, classifyProbeError, classifyStartupOutput, hasUdpListener, componentCounters } from './tc959-readiness.mjs'; + +async function fixture(t, handler) { + const server = createServer(handler); + await new Promise(resolve => server.listen(0, '127.0.0.1', resolve)); + t.after(() => server.close()); + return `http://127.0.0.1:${server.address().port}/healthz`; +} + +test('readiness distinguishes an available node from an ingress 502 without logging payload', async t => { + const node = await fixture(t, (_req, res) => res.end('ok')); + const ingress = await fixture(t, (_req, res) => { res.statusCode = 502; res.end('Bearer TC959_SYNTHETIC private header'); }); + const probe = async () => { + const read = async url => { const response = await fetch(url); await response.arrayBuffer(); return response.status; }; + return { node_healthz: await read(node), ingress_healthz: await read(ingress) }; + }; + await assert.rejects(awaitReadiness(probe, { attempts: 2, intervalMs: 0 }), error => { + assert.deepEqual(error.diagnostics, { node_healthz: { state: 'http', status: 200 }, ingress_healthz: { state: 'http', status: 502 } }); + assert.equal(JSON.stringify(error.diagnostics).includes('TC959_SYNTHETIC'), false); + assert.equal(error.message, 'readiness_timeout'); + return true; + }); +}); + +test('readiness observes each probe transition instead of treating one pass as permanent', async () => { + const results = [ { node_healthz: 200, ingress_healthz: 503 }, { node_healthz: 503, ingress_healthz: 200 }, { node_healthz: 200, ingress_healthz: 200 } ]; + let attempts = 0; + const diagnostics = await awaitReadiness(async () => results[attempts++], { attempts: 3, intervalMs: 0 }); + assert.equal(attempts, 3); + assert.deepEqual(diagnostics, { node_healthz: { state: 'http', status: 200 }, ingress_healthz: { state: 'http', status: 200 } }); +}); + +test('network exceptions expose only fixed classes, not the message, URL, or nested cause', () => { + for (const [code, expected] of [['ECONNREFUSED', 'connection_refused'], ['ECONNRESET', 'connection_reset'], ['ETIMEDOUT', 'timeout'], ['ENOTFOUND', 'dns'], ['PRIVATE_SECRET', 'network']]) { + const error = new Error('Bearer TC959_SYNTHETIC https://private.invalid/secret'); + error.cause = { code, secret: 'TC959_SYNTHETIC' }; + assert.equal(classifyProbeError(error), expected); + } + assert.equal(classifyProbeError({ name: 'TimeoutError' }), 'timeout'); +}); + +test('a failed connection remains distinguishable from an HTTP failure', async () => { + await assert.rejects(awaitReadiness(async () => ({ node_healthz: { state: 'connection_refused' }, ingress_healthz: 503 }), { attempts: 1, intervalMs: 0 }), error => { + assert.deepEqual(error.diagnostics, { node_healthz: { state: 'connection_refused' }, ingress_healthz: { state: 'http', status: 503 } }); + return true; + }); +}); + +test('startup output is classified without forwarding text or fixture credentials', () => { + const raw = 'TC959_SYNTHETIC Bearer private\nFailed to start tinycloud-node:\ninvalid value unknown variant\npermission denied\nnginx: [emerg] configuration file test failed'; + assert.deepEqual(classifyStartupOutput(raw), ['application_startup_failed', 'invalid_configuration', 'permission_denied', 'nginx_startup_failed']); + assert.deepEqual(classifyStartupOutput('TC959_SYNTHETIC unrelated private text'), []); + assert.equal(JSON.stringify(classifyStartupOutput(raw)).includes('TC959_SYNTHETIC'), false); +}); + +test('process running is not UDP readiness and a remote port does not count as a listener', async () => { + const header = 'sl local_address rem_address st tx_queue rx_queue'; + const wrong = `${header}\n0: 00000000:0035 0100007F:2FA9 07 0:0 00:0 0 0 0`; + const right = `${header}\n0: 00000000:2FA9 00000000:0000 07 0:0 00:0 0 0 0`; + assert.equal(hasUdpListener(wrong, 12201), false); + assert.equal(hasUdpListener(right, 12201), true); + let attempt = 0; + await awaitReadiness(async () => ({ node_healthz: 200, vector_running: true, vector_udp_listener: hasUdpListener(attempt++ === 0 ? wrong : right, 12201) }), { attempts: 2, intervalMs: 0 }); + assert.equal(attempt, 2); +}); + +test('component metrics preserve numeric hop counts without returning labels or text', () => { + const metrics = `# private TC959_SYNTHETIC +vector_component_received_events_total{component_id=\"gelf_in\",host=\"TC959_SYNTHETIC\"} 3 +component_received_events_total{component_id=\"gelf_in\",output=\"x\"} 2 +vector_component_sent_events_total{component_id=\"gelf_in\"} 5 +vector_component_errors_total{component_id=\"gelf_in\"} 1 +vector_component_discarded_events_total{component_id=\"gelf_in\"} 0 +vector_component_received_events_total{component_id=\"gelf_in_other\"} 999 +vector_component_received_events_total{component_id=\"other\"} 999`; + assert.deepEqual(componentCounters(metrics, 'gelf_in'), { received_events: 5, sent_events: 5, errors: 1, discarded_events: 0 }); + assert.equal(JSON.stringify(componentCounters(metrics, 'gelf_in')).includes('TC959_SYNTHETIC'), false); +});