From 2eb7f71458e680b7813e9cff6c80fe1b3aa0d8b3 Mon Sep 17 00:00:00 2001 From: Sam Gbafa Date: Sat, 17 Oct 2026 04:37:25 +0000 Subject: [PATCH 1/2] TC-959 ship typed TC-1274 SQL contention diagnostics per occurrence Admit the seven F6 messages only from their exact target and level, with only their declared fields: bounded integers, fixed enums and keyed space_hash/db_hash of exactly 64 lowercase hex. Any invalid field rejects the whole record into the invalid_fields gate count; raw db names, the pool operation label, error text and nested values are never copied. Typed records bypass the diagnostic reduce. Regenerates the embedded Vector config; fields.json still needs the canonical schema re-pin. --- CHANGELOG.md | 1 + docker-compose.dstack-postgres.yaml | 2 +- docs/runbooks/tc-959-n0-log-shipping.md | 11 +++- log-shipper/cases.mjs | 80 +++++++++++++++++++++++++ log-shipper/diagnostics.json | 9 +++ log-shipper/fields.json | 21 ++++++- log-shipper/native-check.mjs | 13 +++- log-shipper/sanitize.vrl | 24 +++++--- scripts/tc959-docker.mjs | 23 ++++++- scripts/tc959-docker.test.mjs | 14 +++++ scripts/tc959-logship.mjs | 49 ++++++++++++++- 11 files changed, 225 insertions(+), 22 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 60da09a0..c5b0d288 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,6 +15,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). +- The N0 log sidecar ships the seven TC-1274 SQL contention diagnostics (`sql_operation_lock_wait`, `sql_operation_lock_still_waiting`, `sql_operation_lock_held`, `sql_operation_still_running`, `sql_actor_message_slow`, `db_pool_acquire_timeout`, `db_connect_failed`) one record per occurrence, matched by exact target, message and level. Each record carries only its declared typed fields: bounded integer timings and counts, fixed `op`/`phase`/`kind`/`outcome`/`class` values, and keyed `space_hash`/`db_hash` of exactly 64 lowercase hex. Any invalid field rejects the whole record into the content-free gate count; raw database names, the pool operation label, error text and nested values are never copied. Other diagnostics keep their count aggregation (TC-959, TC-1274). ## [1.20.7] - 2026-10-14 diff --git a/docker-compose.dstack-postgres.yaml b/docker-compose.dstack-postgres.yaml index d661d530..0832b100 100644 --- a/docker-compose.dstack-postgres.yaml +++ b/docker-compose.dstack-postgres.yaml @@ -158,7 +158,7 @@ services: 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}}}" + 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 event = if level == \\\"warn\\\" { \\\"node_warning\\\" } else { \\\"node_error\\\" }\\n # Typed diagnostics: an exact (target, message) match ships one record per\\n # occurrence with only its declared fields. A wrong level, a missing field\\n # or any value outside its type, range, enum or hash pattern aborts the\\n # whole record; undeclared fields are never copied.\\n typed = false\\n if target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_lock_wait\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_lock_wait\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"waited_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.waited_ms = n\\n v = get(f, [\\\"ahead_approx\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 1000000 { abort }\\n out.ahead_approx = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_lock_still_waiting\\\" {\\n typed = true\\n if level != \\\"error\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_lock_still_waiting\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"waited_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.waited_ms = n\\n v = get(f, [\\\"ahead_approx\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 1000000 { abort }\\n out.ahead_approx = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_lock_held\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_lock_held\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"held_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.held_ms = n\\n v = get(f, [\\\"hydrate_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.hydrate_ms = n\\n v = get(f, [\\\"execute_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.execute_ms = n\\n v = get(f, [\\\"persist_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.persist_ms = n\\n v = get(f, [\\\"outcome\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"ok\\\",\\\"incomplete\\\",\\\"sqlite\\\",\\\"permission_denied\\\",\\\"database_not_found\\\",\\\"response_too_large\\\",\\\"quota_exceeded\\\",\\\"storage_would_grow\\\",\\\"invalid_statement\\\",\\\"schema_error\\\",\\\"read_only_violation\\\",\\\"parse_error\\\",\\\"internal\\\",\\\"unavailable\\\",\\\"outcome_unknown\\\"], v) { abort }\\n out.outcome = string!(v)\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_still_running\\\" {\\n typed = true\\n if level != \\\"error\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_still_running\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"phase\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"hydrate\\\",\\\"execute\\\",\\\"persist\\\"], v) { abort }\\n out.phase = string!(v)\\n v = get(f, [\\\"held_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.held_ms = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::database\\\" && msg == \\\"sql_actor_message_slow\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_actor_message_slow\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"kind\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"query\\\",\\\"execute\\\",\\\"batch\\\",\\\"execute_statement\\\",\\\"export\\\",\\\"publication\\\",\\\"checkpoint\\\",\\\"wal\\\",\\\"shutdown\\\"], v) { abort }\\n out.kind = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"elapsed_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.elapsed_ms = n\\n v = get(f, [\\\"outcome\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"ok\\\",\\\"incomplete\\\",\\\"sqlite\\\",\\\"permission_denied\\\",\\\"database_not_found\\\",\\\"response_too_large\\\",\\\"quota_exceeded\\\",\\\"storage_would_grow\\\",\\\"invalid_statement\\\",\\\"schema_error\\\",\\\"read_only_violation\\\",\\\"parse_error\\\",\\\"internal\\\",\\\"unavailable\\\",\\\"outcome_unknown\\\"], v) { abort }\\n out.outcome = string!(v)\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::db_pool\\\" && msg == \\\"db_pool_acquire_timeout\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"db_pool_acquire_timeout\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"elapsed_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.elapsed_ms = n\\n v = get(f, [\\\"pool_size\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 100000 { abort }\\n out.pool_size = n\\n v = get(f, [\\\"pool_idle\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 100000 { abort }\\n out.pool_idle = n\\n v = get(f, [\\\"pool_max\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 100000 { abort }\\n out.pool_max = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::db_pool\\\" && msg == \\\"db_connect_failed\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"db_connect_failed\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"class\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"refused\\\",\\\"io\\\",\\\"tls\\\",\\\"database_transient\\\",\\\"database\\\",\\\"after_connect\\\",\\\"timed_out\\\",\\\"other\\\"], v) { abort }\\n out.class = string!(v)\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\n if !typed {\\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 out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": code, \\\"event_count\\\": 1}\\n }\\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\\\") && !includes([\\\"sql_operation_lock_wait\\\",\\\"sql_operation_lock_still_waiting\\\",\\\"sql_operation_lock_held\\\",\\\"sql_operation_still_running\\\",\\\"sql_actor_message_slow\\\",\\\"db_pool_acquire_timeout\\\",\\\"db_connect_failed\\\"], .event_code)\",\"typed_diagnostic\":\"(.event == \\\"node_warning\\\" || .event == \\\"node_error\\\") && includes([\\\"sql_operation_lock_wait\\\",\\\"sql_operation_lock_still_waiting\\\",\\\"sql_operation_lock_held\\\",\\\"sql_operation_still_running\\\",\\\"sql_actor_message_slow\\\",\\\"db_pool_acquire_timeout\\\",\\\"db_connect_failed\\\"], .event_code)\"}},\"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\",\"event_route.typed_diagnostic\",\"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 diff --git a/docs/runbooks/tc-959-n0-log-shipping.md b/docs/runbooks/tc-959-n0-log-shipping.md index 45314668..10d8873c 100644 --- a/docs/runbooks/tc-959-n0-log-shipping.md +++ b/docs/runbooks/tc-959-n0-log-shipping.md @@ -31,6 +31,7 @@ Parsing failures become fixed counters; no log-level suppression is used. | `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 | +| `node_warning` / `node_error`, `svc=api`, TC-1274 SQL contention `event_code` | `event_count=1` plus only that code's declared fields (`log-shipper/diagnostics.json` `typed`): integer `*_ms`, `ahead_approx`, `suppressed_count`, `pool_size`/`pool_idle`/`pool_max`; fixed `op`/`phase`/`kind`/`outcome`/`class`; keyed `space_hash`/`db_hash`, each exactly 64 lowercase hex | Individually, one record per occurrence, under either profile; never reduced | | `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 @@ -41,13 +42,17 @@ Sam approved **`errors_slow` as the deployment default**. Compose exposes `TINYC - 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. +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. Untyped codes retain their fixed-code count aggregation; the seven TC-1274 SQL contention codes are shipped per occurrence instead (next section). 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. + +### TC-1274 SQL contention diagnostics + +`sql_operation_lock_wait`, `sql_operation_lock_still_waiting`, `sql_operation_lock_held` and `sql_operation_still_running` from `tinycloud_core::sql::service`, `sql_actor_message_slow` from `tinycloud_core::sql::database`, and `db_pool_acquire_timeout` and `db_connect_failed` from `tinycloud_core::db_pool` are matched by exact (target, message) and fixed level. Each record carries only the fields `diagnostics.json` declares for its code, each checked against its closed schema type. A missing field, a wrong type, an out-of-range integer, a value outside its enum, a hash that is not exactly 64 lowercase hex, or a wrong level rejects the whole record into the `invalid_fields` gate count; no partial record is shipped. Undeclared fields, including a raw `db` name, the pool `operation` label, error text and nested values, are never copied. The same message from any other target stays `unclassified`. The field sets and enums must match the emitted F6 PR before promotion. 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`. +**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 HMACs, per-request DB timings and trace propagation require N2. N0 ignores and omits them, including forged input values; the only hashes it ships are the SQL contention diagnostics' `space_hash`/`db_hash`. 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 @@ -65,7 +70,7 @@ Under `errors_slow`, node and ingress eligibility are evaluated independently: a 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. +Diagnostics are **additional**, not secretly subtracted, sampled or dropped. The continuous storm model covers all 59 codes at both severities (118 groups/minute) plus nine rejection groups/minute: **912,340,800 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 2,003,572,800 bytes. The SQL contention diagnostics are per occurrence and are NOT in that model: a maximum-width record is at most 475 bytes with its newline, the shipper applies no cap, and their rate is bounded only by the node's own per-(space, database, event) limiter, so it scales with the number of contended databases. Measure it separately. [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 diff --git a/log-shipper/cases.mjs b/log-shipper/cases.mjs index 6b65d4c0..fffceff1 100644 --- a/log-shipper/cases.mjs +++ b/log-shipper/cases.mjs @@ -9,6 +9,79 @@ const safe = '!contains(encode_json(.), "TC959_SYNTHETIC") && !exists(.message) 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"))' }] }] }); + +// TC-1274 F6 contention diagnostics, per Naomi's ruling: only these typed +// fields per event; space_hash/db_hash are keyed 64-lowercase-hex digests and +// no raw db, pool operation label, error or message text ever leaves. +export const spaceHash = '0123456789abcdef'.repeat(4); +export const dbHash = 'fedcba9876543210'.repeat(4); +export const f6Events = { + sql_operation_lock_wait: { target: 'tinycloud_core::sql::service', level: 'WARN', fields: { op: 'execute', space_hash: spaceHash, db_hash: dbHash, waited_ms: 61000, ahead_approx: 2, suppressed_count: 0 } }, + sql_operation_lock_still_waiting: { target: 'tinycloud_core::sql::service', level: 'ERROR', fields: { op: 'execute_no_growth', space_hash: spaceHash, db_hash: dbHash, waited_ms: 30000, ahead_approx: 1, suppressed_count: 1 } }, + sql_operation_lock_held: { target: 'tinycloud_core::sql::service', level: 'WARN', fields: { op: 'publication', space_hash: spaceHash, db_hash: dbHash, held_ms: 61000, hydrate_ms: 10, execute_ms: 990, persist_ms: 60000, outcome: 'ok', suppressed_count: 0 } }, + sql_operation_still_running: { target: 'tinycloud_core::sql::service', level: 'ERROR', fields: { op: 'export', space_hash: spaceHash, db_hash: dbHash, phase: 'persist', held_ms: 30000, suppressed_count: 0 } }, + sql_actor_message_slow: { target: 'tinycloud_core::sql::database', level: 'WARN', fields: { kind: 'query', space_hash: spaceHash, db_hash: dbHash, elapsed_ms: 8000, outcome: 'parse_error', suppressed_count: 3 } }, + db_pool_acquire_timeout: { target: 'tinycloud_core::db_pool', level: 'WARN', fields: { elapsed_ms: 200, pool_size: 1, pool_idle: 0, pool_max: 1, suppressed_count: 0 } }, + db_connect_failed: { target: 'tinycloud_core::db_pool', level: 'WARN', fields: { class: 'refused', suppressed_count: 0 } }, +}; +/** A raw F6 tracing line; an override of `undefined` removes that field. */ +export const f6Line = (name, overrides = {}, { target = f6Events[name].target, level = f6Events[name].level } = {}) => ({ timestamp, level, target, fields: { message: name, ...f6Events[name].fields, ...overrides } }); +const vrl = value => JSON.stringify(value); +const f6Safe = '!contains(encode_json(.), "TC959_SYNTHETIC") && !exists(.message) && !exists(.target) && !exists(.host) && !exists(.db) && !exists(.operation) && !exists(.error) && !exists(.err) && !exists(.sql) && !exists(.nested) && !exists(.request_id) && !exists(.account_hash)'; +/** The exact wire record for an admitted F6 occurrence: fixed envelope plus its typed fields, nothing else. */ +export const f6Expected = name => { + const { level, fields } = f6Events[name]; + const lower = level.toLowerCase(); + const event = lower === 'warn' ? 'node_warning' : 'node_error'; + const typed = Object.entries(fields).map(([key, value]) => `.${key} == ${vrl(value)}`); + return [`.event == "${event}"`, '.svc == "api"', `.level == "${lower}"`, `.event_code == "${name}"`, '.event_count == 1', ...typed, `length(keys(.)) == ${6 + Object.keys(fields).length}`].join(' && '); +}; +const f6Check = (name, input, assertion, extract = 'allowlist') => ({ name, inputs: [{ insert_at: 'logship_gate', type: 'log', log_fields: logFields(envelope(input)) }], outputs: [{ extract_from: extract, conditions: [{ type: 'vrl', source: `assert!(${assertion})\nassert!(${f6Safe})` }] }] }); +const f6Reject = (name, input) => ({ name, inputs: [{ insert_at: 'logship_gate', type: 'log', log_fields: logFields(envelope(input)) }], no_outputs_from: ['allowlist'], outputs: [{ extract_from: 'gate_counts', conditions: [{ type: 'vrl', source: 'assert!(.count == 1 && .reason == "invalid_fields")\nassert!(!contains(encode_json(.), "TC959_SYNTHETIC"))' }] }] }); +const hostileExtras = { db: 'v2n', operation: 'begin', error: canary, err: canary, sql: `SELECT '${canary}'`, nested: { space: canary }, space: canary, did: canary }; +const integerFields = { waited_ms: 86_400_000, held_ms: 86_400_000, hydrate_ms: 86_400_000, execute_ms: 86_400_000, persist_ms: 86_400_000, elapsed_ms: 86_400_000, ahead_approx: 1_000_000, suppressed_count: 9_007_199_254_740_991, pool_size: 100_000, pool_idle: 100_000, pool_max: 100_000 }; +const f6Tests = [ + ...Object.keys(f6Events).map(name => f6Check(`F6 ${name} keeps exactly its typed fields`, f6Line(name), f6Expected(name))), + ...Object.keys(f6Events).map(name => f6Check(`F6 ${name} drops raw db, pool operation, error text and nested extras`, f6Line(name, hostileExtras), f6Expected(name))), + f6Check('F6 field belonging to another event is not copied', f6Line('sql_operation_lock_wait', { phase: 'persist', kind: 'query', class: 'io', held_ms: 1 }), f6Expected('sql_operation_lock_wait')), + ...Object.entries(f6Events).flatMap(([name, { fields }]) => Object.keys(fields).map(key => f6Reject(`F6 ${name} without ${key} is rejected`, f6Line(name, { [key]: undefined })))), + ...Object.entries(f6Events).flatMap(([name, { fields }]) => Object.keys(fields).filter(key => key in integerFields).flatMap(key => [ + f6Check(`F6 ${name} ${key} accepts its bounds`, f6Line(name, { [key]: integerFields[key] }), `.${key} == ${integerFields[key]}`), + ...[-1, integerFields[key] + 1, 1.5, '5000', true, null, { ms: 5000 }, [5000]].map(value => f6Reject(`F6 ${name} ${key}=${JSON.stringify(value)} is rejected`, f6Line(name, { [key]: value }))), + ])), + f6Reject('F6 float-overflowed counter is rejected', f6Line('sql_operation_lock_wait', { suppressed_count: 1e30 })), + ...['space_hash', 'db_hash'].flatMap(key => [ + ['stale 16-hex shape', '0123456789abcdef'], ['uppercase', 'ABCDEF0123456789'.repeat(4)], ['63 hex', 'a'.repeat(63)], ['65 hex', 'a'.repeat(65)], + ['non-hex', 'g'.repeat(64)], ['v2n', 'v2n'], ['v2d plus hex', `v2d${'a'.repeat(16)}`], ['legacy', `legacy-${'a'.repeat(16)}`], + ['free text', canary], ['nested', { hash: spaceHash }], ['number', 1], ['padded', ` ${spaceHash}`], + ].map(([label, value]) => f6Reject(`F6 ${key} ${label} is rejected`, f6Line('sql_operation_lock_held', { [key]: value })))), + ...[ + ['op', ['EXECUTE', 'execute ', 'lock', canary, { op: 'execute' }, ['execute'], 1]], + ['outcome', ['Sqlite', `sqlite error: ${canary}`, 'incomplete_', '', null]], + ].flatMap(([key, values]) => values.map(value => f6Reject(`F6 lock_held ${key}=${JSON.stringify(value)} is rejected`, f6Line('sql_operation_lock_held', { [key]: value })))), + ...['lock', 'Persist', canary].map(phase => f6Reject(`F6 still_running phase=${phase} is rejected`, f6Line('sql_operation_still_running', { phase }))), + ...['drop', 'Query', canary, 1].map(kind => f6Reject(`F6 actor kind=${kind} is rejected`, f6Line('sql_actor_message_slow', { kind }))), + ...['protocol', 'Refused', `connection refused: ${canary}`, { class: 'io' }].map(value => f6Reject(`F6 connect class=${JSON.stringify(value)} is rejected`, f6Line('db_connect_failed', { class: value }))), + ...['ok', 'incomplete', 'sqlite', 'permission_denied', 'database_not_found', 'response_too_large', 'quota_exceeded', 'storage_would_grow', 'invalid_statement', 'schema_error', 'read_only_violation', 'parse_error', 'internal', 'unavailable', 'outcome_unknown'].map(outcome => f6Check(`F6 lock_held outcome ${outcome} is admitted`, f6Line('sql_operation_lock_held', { outcome }), `.outcome == "${outcome}"`)), + ...['execute', 'execute_no_growth', 'publication', 'export'].map(op => f6Check(`F6 op ${op} is admitted`, f6Line('sql_operation_lock_wait', { op }), `.op == "${op}"`)), + ...['hydrate', 'execute', 'persist'].map(phase => f6Check(`F6 phase ${phase} is admitted`, f6Line('sql_operation_still_running', { phase }), `.phase == "${phase}"`)), + ...['query', 'execute', 'batch', 'execute_statement', 'export', 'publication', 'checkpoint', 'wal', 'shutdown'].map(kind => f6Check(`F6 kind ${kind} is admitted`, f6Line('sql_actor_message_slow', { kind }), `.kind == "${kind}"`)), + ...['refused', 'io', 'tls', 'database_transient', 'database', 'after_connect', 'timed_out', 'other'].map(value => f6Check(`F6 class ${value} is admitted`, f6Line('db_connect_failed', { class: value }), `.class == "${value}"`)), + ...Object.keys(f6Events).map(name => f6Reject(`F6 ${name} at the wrong level is rejected`, f6Line(name, {}, { level: f6Events[name].level === 'WARN' ? 'ERROR' : 'WARN' }))), + ...[ + ['another F6 target', 'tinycloud_core::sql::database', 'sql_operation_lock_wait'], + ['a child of the F6 target', 'tinycloud_core::sql::service::inner', 'sql_operation_lock_held'], + ['a dependency', 'sqlx::pool', 'db_connect_failed'], + ['an application target', 'tinycloud::request', 'db_pool_acquire_timeout'], + ].map(([label, target, name]) => check(`F6 message from ${label} stays unclassified without fields`, envelope(f6Line(name, {}, { target })), `.event_code == "unclassified" && .event_count == 1 && length(keys(.)) == 6`)), + f6Check('F6 occurrences bypass the diagnostic reduce', f6Line('sql_operation_lock_wait'), f6Expected('sql_operation_lock_wait'), 'event_route.typed_diagnostic'), + { + name: 'F6 occurrences are shipped one per line, never merged', + inputs: [61000, 62000].map(waited_ms => ({ insert_at: 'logship_gate', type: 'log', log_fields: logFields(envelope(f6Line('sql_operation_lock_wait', { waited_ms }))) })), + no_outputs_from: ['diagnostic_output'], + outputs: [{ extract_from: 'event_route.typed_diagnostic', conditions: [{ type: 'vrl', source: `assert!(.event_count == 1 && (.waited_ms == 61000 || .waited_ms == 62000))\nassert!(${f6Safe})` }] }], + }, +]; 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'), @@ -55,6 +128,7 @@ export const vectorTests = [ 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)' }] }], }, + ...f6Tests, ]; /** Exercise the actual routed boundary, not just pre-profile sanitization. */ @@ -90,5 +164,11 @@ export function requestProfileTests(profile) { 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})` }] }], })), + ...Object.keys(f6Events).map(name => ({ + name: `${profile}: F6 ${name} always eligible and never reduced`, + inputs: [{ insert_at: 'logship_gate', type: 'log', log_fields: logFields(envelope(f6Line(name))) }], + no_outputs_from: ['event_route.diagnostic', 'event_route.request'], + outputs: [{ extract_from: 'event_route.typed_diagnostic', conditions: [{ type: 'vrl', source: `assert!(${f6Expected(name)})\nassert!(${f6Safe})` }] }], + })), ]; } diff --git a/log-shipper/diagnostics.json b/log-shipper/diagnostics.json index 1c4cd00c..34d3dcea 100644 --- a/log-shipper/diagnostics.json +++ b/log-shipper/diagnostics.json @@ -55,5 +55,14 @@ "quota service returned ": "quota_fallback", "Failed to get TDX quote: ": "attestation_quote_failed" }, + "typed": { + "sql_operation_lock_wait": { "target": "tinycloud_core::sql::service", "level": "warn", "fields": ["op", "space_hash", "db_hash", "waited_ms", "ahead_approx", "suppressed_count"] }, + "sql_operation_lock_still_waiting": { "target": "tinycloud_core::sql::service", "level": "error", "fields": ["op", "space_hash", "db_hash", "waited_ms", "ahead_approx", "suppressed_count"] }, + "sql_operation_lock_held": { "target": "tinycloud_core::sql::service", "level": "warn", "fields": ["op", "space_hash", "db_hash", "held_ms", "hydrate_ms", "execute_ms", "persist_ms", "outcome", "suppressed_count"] }, + "sql_operation_still_running": { "target": "tinycloud_core::sql::service", "level": "error", "fields": ["op", "space_hash", "db_hash", "phase", "held_ms", "suppressed_count"] }, + "sql_actor_message_slow": { "target": "tinycloud_core::sql::database", "level": "warn", "fields": ["kind", "space_hash", "db_hash", "elapsed_ms", "outcome", "suppressed_count"] }, + "db_pool_acquire_timeout": { "target": "tinycloud_core::db_pool", "level": "warn", "fields": ["elapsed_ms", "pool_size", "pool_idle", "pool_max", "suppressed_count"] }, + "db_connect_failed": { "target": "tinycloud_core::db_pool", "level": "warn", "fields": ["class", "suppressed_count"] } + }, "fallback": "unclassified" } diff --git a/log-shipper/fields.json b/log-shipper/fields.json index b56b6e1d..66f5ac93 100644 --- a/log-shipper/fields.json +++ b/log-shipper/fields.json @@ -78,14 +78,31 @@ "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_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", "sql_operation_lock_wait", "sql_operation_lock_still_waiting", "sql_operation_lock_held", "sql_operation_still_running", "sql_actor_message_slow", "db_pool_acquire_timeout", "db_connect_failed", "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 } + "space_hash": { "type": "string", "regex": "^[0-9a-f]{64}$", "max_len": 64 }, + "db_hash": { "type": "string", "regex": "^[0-9a-f]{64}$", "max_len": 64 }, + "op": { "type": "enum", "values": ["execute", "execute_no_growth", "publication", "export"] }, + "phase": { "type": "enum", "values": ["hydrate", "execute", "persist"] }, + "kind": { "type": "enum", "values": ["query", "execute", "batch", "execute_statement", "export", "publication", "checkpoint", "wal", "shutdown"] }, + "outcome": { "type": "enum", "values": ["ok", "incomplete", "sqlite", "permission_denied", "database_not_found", "response_too_large", "quota_exceeded", "storage_would_grow", "invalid_statement", "schema_error", "read_only_violation", "parse_error", "internal", "unavailable", "outcome_unknown"] }, + "class": { "type": "enum", "values": ["refused", "io", "tls", "database_transient", "database", "after_connect", "timed_out", "other"] }, + "waited_ms": { "type": "integer", "min": 0, "max": 86400000 }, + "held_ms": { "type": "integer", "min": 0, "max": 86400000 }, + "hydrate_ms": { "type": "integer", "min": 0, "max": 86400000 }, + "execute_ms": { "type": "integer", "min": 0, "max": 86400000 }, + "persist_ms": { "type": "integer", "min": 0, "max": 86400000 }, + "elapsed_ms": { "type": "integer", "min": 0, "max": 86400000 }, + "ahead_approx": { "type": "integer", "min": 0, "max": 1000000 }, + "suppressed_count": { "type": "integer", "min": 0, "max": 9007199254740991 }, + "pool_size": { "type": "integer", "min": 0, "max": 100000 }, + "pool_idle": { "type": "integer", "min": 0, "max": 100000 }, + "pool_max": { "type": "integer", "min": 0, "max": 100000 } } }, "tinychat-backend": { "events": [], "fields": {} }, diff --git a/log-shipper/native-check.mjs b/log-shipper/native-check.mjs index e5050346..037a72e1 100644 --- a/log-shipper/native-check.mjs +++ b/log-shipper/native-check.mjs @@ -11,7 +11,7 @@ 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'; +import { canary, nodeRequest, ingressRequest, f6Line, f6Events } from './cases.mjs'; const sleep = ms => new Promise(resolve => setTimeout(resolve, ms)); @@ -75,9 +75,13 @@ export async function checkNativeVector(vector, baseline) { // 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}`); + // F6: one valid occurrence with hostile extras is shipped typed; the stale 16-hex shape is not. + await send(frame(f6Line('sql_operation_lock_wait', { db: canary, operation: 'begin', error: canary }))); + await send(frame(f6Line('sql_operation_lock_wait', { space_hash: '0123456789abcdef', db: 'v2n', db_hash: undefined }))); } finally { sender.close(); } + const typed = () => events.filter(event => event.event_code === 'sql_operation_lock_wait'); for (let attempt = 0; attempt < 100; attempt++) { - if (events.filter(event => event.event === 'node_request' || event.event === 'ingress_request').length >= 5) break; + if (events.filter(event => event.event === 'node_request' || event.event === 'ingress_request').length >= 5 && typed().length >= 1) break; await sleep(30); } child.kill('SIGTERM'); @@ -87,8 +91,11 @@ export async function checkNativeVector(vector, baseline) { 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 f6 = typed(); + const expected = { level: 'warn', event: 'node_warning', svc: 'api', event_code: 'sql_operation_lock_wait', event_count: 1, ...f6Events.sql_operation_lock_wait.fields }; + const f6Exact = f6.length === 1 && Object.entries(expected).every(([key, value]) => f6[0][key] === value) && Object.keys(f6[0]).length === Object.keys(expected).length + 1; 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 }; + return { status: wireSafe && !malformedHttp && !overflow && requests === 5 && f6Exact && consoleHits === 0 ? 'passed' : 'failed', request_events: requests, f6_typed_events: f6.length, f6_exact: f6Exact, console_canary_hits: consoleHits, wire_safe: wireSafe, positive_controls: 6, console_overflow: overflow }; } finally { if (child) { child.kill('SIGTERM'); await closed; } server.closeAllConnections(); diff --git a/log-shipper/sanitize.vrl b/log-shipper/sanitize.vrl index c3c2761c..0ae04f83 100644 --- a/log-shipper/sanitize.vrl +++ b/log-shipper/sanitize.vrl @@ -28,15 +28,23 @@ if label == "tinycloud-node" { 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} + # Typed diagnostics: an exact (target, message) match ships one record per + # occurrence with only its declared fields. A wrong level, a missing field + # or any value outside its type, range, enum or hash pattern aborts the + # whole record; undeclared fields are never copied. + typed = false + __TYPED_DIAGNOSTICS__ + if !typed { + 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__ + } + out = {"event": event, "svc": "api", "level": level, "event_code": code, "event_count": 1} + } } } else { ts = string!(j.time) diff --git a/scripts/tc959-docker.mjs b/scripts/tc959-docker.mjs index b17f904e..c9f8ebc5 100755 --- a/scripts/tc959-docker.mjs +++ b/scripts/tc959-docker.mjs @@ -3,7 +3,7 @@ import assert from 'node:assert/strict'; import { spawnSync } from 'node:child_process'; import dgram from 'node:dgram'; -import { writeFileSync } from 'node:fs'; +import { readFileSync, 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'; @@ -43,6 +43,16 @@ export function resourceNames(id) { return Object.fromEntries(['logship', 'sink', 'vector', 'node', 'ingress', 'emitter'].map(role => [role, `${owner}-${id}-${role}`])); } +const typedDiagnostics = JSON.parse(readFileSync(new URL('../log-shipper/diagnostics.json', import.meta.url), 'utf8')).typed; +/** One typed diagnostic field against its closed schema type. */ +function assertTypedField(value, spec) { + assert.ok(spec); + if (spec.type === 'integer') assert.ok(Number.isSafeInteger(value) && value >= spec.min && value <= spec.max); + else if (spec.type === 'enum') assert.ok(spec.values.includes(value)); + else if (spec.type === 'string') assert.ok(typeof value === 'string' && value.length <= spec.max_len && new RegExp(spec.regex).test(value)); + else assert.fail('typed diagnostic field has no closed type'); +} + /** Strict validation applies to every captured record, including a failing proof's partial capture. */ export function assertCapture(events, fields) { assert.ok(events.length > 0); @@ -66,8 +76,17 @@ export function assertCapture(events, fields) { 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']; + const typed = Object.hasOwn(typedDiagnostics, event.event_code) ? typedDiagnostics[event.event_code] : undefined; + if (typed) { + // Typed diagnostics are never reduced: one record per occurrence. + assert.equal(event.event_count, 1); + assert.equal(event.level, typed.level); + for (const name of typed.fields) assertTypedField(event[name], fields[name]); + allowed.push(...typed.fields); + } else { + assert.ok(Number.isSafeInteger(event.event_count) && event.event_count > 0); + } } else { assert.equal(event.event, 'logship_gate_summary_total'); assert.equal(event.svc, 'logship'); diff --git a/scripts/tc959-docker.test.mjs b/scripts/tc959-docker.test.mjs index ac7f84ee..d839fb34 100644 --- a/scripts/tc959-docker.test.mjs +++ b/scripts/tc959-docker.test.mjs @@ -1,9 +1,11 @@ import test from 'node:test'; import assert from 'node:assert/strict'; import { spawnSync } from 'node:child_process'; +import { readFileSync } from 'node:fs'; 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'; +import { f6Events, spaceHash } from '../log-shipper/cases.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 }; @@ -39,6 +41,18 @@ test('capture rejects unsafe values even when all request positive controls are } }); +test('capture admits an F6 diagnostic only with its exact typed fields and 64-hex keyed hashes', () => { + const fields = JSON.parse(readFileSync(new URL('../log-shipper/fields.json', import.meta.url), 'utf8')).services['tinycloud-node'].fields; + const wire = { ts: '2026-10-16T12:00:00.000Z', level: 'warn', event: 'node_warning', svc: 'api', event_code: 'sql_operation_lock_wait', event_count: 1, ...f6Events.sql_operation_lock_wait.fields }; + assert.doesNotThrow(() => assertCapture([wire], fields)); + const connect = { ts: wire.ts, level: 'warn', event: 'node_warning', svc: 'api', event_code: 'db_connect_failed', event_count: 1, ...f6Events.db_connect_failed.fields }; + assert.doesNotThrow(() => assertCapture([connect], fields)); + for (const poison of [{ db: 'v2n' }, { operation: 'begin' }, { space_hash: '0123456789abcdef' }, { db_hash: 'A'.repeat(64) }, { op: 'lock' }, { waited_ms: -1 }, { waited_ms: 1.5 }, { waited_ms: undefined }, { phase: 'persist' }, { event_count: 2 }, { level: 'error', event: 'node_error' }]) { + assert.throws(() => assertCapture([JSON.parse(JSON.stringify({ ...wire, ...poison }))], fields)); + } + assert.throws(() => assertCapture([{ ts: wire.ts, level: 'warn', event: 'node_warning', svc: 'api', event_code: 'unclassified', event_count: 1, space_hash: spaceHash }], fields)); +}); + 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)); diff --git a/scripts/tc959-logship.mjs b/scripts/tc959-logship.mjs index 5ee841d0..e358f4ca 100644 --- a/scripts/tc959-logship.mjs +++ b/scripts/tc959-logship.mjs @@ -17,6 +17,44 @@ const aliases = { '/public//kv?': '/public//kv', }; +/** + * Compile each typed diagnostic into straight-line VRL: an exact (target, + * message) match, its fixed level, then one check per declared field taken + * from the schema. Any failure aborts the record; nothing undeclared is copied. + */ +function typedDiagnostics(diagnostics, fields) { + const codes = fields.event_code.values; + const untyped = new Set([...Object.keys(diagnostics.exact), ...Object.values(diagnostics.exact), ...Object.values(diagnostics.prefix)]); + return Object.entries(diagnostics.typed).map(([message, { target, level, fields: names }]) => { + if (!/^[a-z_]+$/.test(message) || !codes.includes(message) || untyped.has(message)) throw new TypeError(`typed diagnostic ${message} must be a distinct schema event code`); + if (!/^tinycloud(_core)?(::[a-z_]+)*$/.test(target) || !['warn', 'error'].includes(level)) throw new TypeError(`typed diagnostic ${message} has an invalid target or level`); + if (new Set(names).size !== names.length) throw new TypeError(`typed diagnostic ${message} repeats a field`); + const checks = names.map(name => { + const spec = fields[name]; + if (!/^[a-z_]+$/.test(name) || !spec) throw new TypeError(`typed diagnostic field ${name} is not in the schema`); + const read = `v = get(f, [${JSON.stringify(name)}]) ?? null`; + if (spec.type === 'integer' && Number.isSafeInteger(spec.min) && Number.isSafeInteger(spec.max)) { + return `${read}\nif !is_integer(v) { abort }\nn = int!(v)\nif n < ${spec.min} || n > ${spec.max} { abort }\nout.${name} = n`; + } + if (spec.type === 'enum' && spec.values.every(value => /^[a-z_]+$/.test(value))) { + return `${read}\nif !is_string(v) || !includes(${JSON.stringify(spec.values)}, v) { abort }\nout.${name} = string!(v)`; + } + if (spec.type === 'string' && /^\^[^'\\]*\$$/.test(spec.regex) && Number.isSafeInteger(spec.max_len)) { + return `${read}\nif !is_string(v) { abort }\ns = string!(v)\nif length(s) > ${spec.max_len} || !match(s, r'${spec.regex}') { abort }\nout.${name} = s`; + } + throw new TypeError(`typed diagnostic field ${name} has no closed type`); + }); + return [ + `if target == ${JSON.stringify(target)} && msg == ${JSON.stringify(message)} {`, + ' typed = true', + ` if level != ${JSON.stringify(level)} { abort }`, + ` out = {"event": event, "svc": "api", "level": level, "event_code": ${JSON.stringify(message)}, "event_count": 1}`, + ...checks.join('\n').split('\n').map(line => ` ${line}`), + '}', + ].join('\n'); + }).join('\n'); +} + /** 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'); @@ -25,10 +63,14 @@ export function buildConfig({ sinkUri = 'https://s2795437.us-west-2a.betterstack const profileExpression = runtimeProfile ? '"${TINYCLOUD_LOGSHIP_PROFILE}"' : JSON.stringify(profile); const schema = load('fields.json').services['tinycloud-node']; const diagnostics = load('diagnostics.json'); + const typedCodes = JSON.stringify(Object.keys(diagnostics.typed)); + const typedSource = typedDiagnostics(diagnostics, schema.fields); + // Function replacements: VRL regex literals contain `$'`, a replacement pattern. 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('__TYPED_DIAGNOSTICS__', () => typedSource) .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 = { @@ -89,12 +131,13 @@ if !includes(${JSON.stringify(schema.fields.reason.values)}, reason) { reason = 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"' } }, + // Typed diagnostics keep their per-occurrence fields; only untyped codes are counted by reduction. + event_route: { type: 'route', inputs: ['request_profile'], route: { request: '.event == "node_request" || .event == "ingress_request"', diagnostic: `(.event == "node_warning" || .event == "node_error") && !includes(${typedCodes}, .event_code)`, typed_diagnostic: `(.event == "node_warning" || .event == "node_error") && includes(${typedCodes}, .event_code)` } }, 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, + type: 'http', inputs: ['event_route.request', 'event_route.typed_diagnostic', '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 }, @@ -115,7 +158,7 @@ if (process.argv[1] && resolve(process.argv[1]) === fileURLToPath(import.meta.ur 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.sinks = { discard: { type: 'blackhole', inputs: config.sinks.betterstack.inputs } }; config.tests = [...vectorTests, ...requestProfileTests(profile)]; } writeFileSync(output, JSON.stringify(config, null, 2) + '\n'); From c5f1e7ada5fd519c41186fc32f38947c9909612b Mon Sep 17 00:00:00 2001 From: Sam Gbafa Date: Sat, 17 Oct 2026 13:07:35 +0000 Subject: [PATCH 2/2] TC-959 cap typed SQL contention records at 10 per code per minute Sam's decision (tc-959-f6-log-cap): the shipper admits at most 10 records per typed code per fixed 60 s window, each of the seven codes counted separately, as defence in depth over the node's per-key limiter. A Lua counter keyed only by the fixed codes enforces it. Excess records are dropped and only their count leaves, as the new typed_throttled gate reason. budget.mjs reserves the cap at each code's widest valid record: 70 records/min, 1,433,376,000 bytes per 30 sustained days. --- CHANGELOG.md | 2 +- docker-compose.dstack-postgres.yaml | 2 +- docs/runbooks/tc-959-n0-log-shipping.md | 8 +++-- log-shipper/budget.mjs | 24 ++++++++++++-- log-shipper/budget.test.mjs | 36 ++++++++++++++++++--- log-shipper/cases.mjs | 31 ++++++++++++++++++ log-shipper/diagnostics.json | 1 + log-shipper/fields.json | 2 +- scripts/tc959-logship.mjs | 42 +++++++++++++++++++++++-- 9 files changed, 131 insertions(+), 17 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index c5b0d288..9150e109 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,7 +15,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). -- The N0 log sidecar ships the seven TC-1274 SQL contention diagnostics (`sql_operation_lock_wait`, `sql_operation_lock_still_waiting`, `sql_operation_lock_held`, `sql_operation_still_running`, `sql_actor_message_slow`, `db_pool_acquire_timeout`, `db_connect_failed`) one record per occurrence, matched by exact target, message and level. Each record carries only its declared typed fields: bounded integer timings and counts, fixed `op`/`phase`/`kind`/`outcome`/`class` values, and keyed `space_hash`/`db_hash` of exactly 64 lowercase hex. Any invalid field rejects the whole record into the content-free gate count; raw database names, the pool operation label, error text and nested values are never copied. Other diagnostics keep their count aggregation (TC-959, TC-1274). +- The N0 log sidecar ships the seven TC-1274 SQL contention diagnostics (`sql_operation_lock_wait`, `sql_operation_lock_still_waiting`, `sql_operation_lock_held`, `sql_operation_still_running`, `sql_actor_message_slow`, `db_pool_acquire_timeout`, `db_connect_failed`) one record per occurrence, matched by exact target, message and level. Each record carries only its declared typed fields: bounded integer timings and counts, fixed `op`/`phase`/`kind`/`outcome`/`class` values, and keyed `space_hash`/`db_hash` of exactly 64 lowercase hex. Any invalid field rejects the whole record into the content-free gate count; raw database names, the pool operation label, error text and nested values are never copied. Per Sam's decision, the shipper caps them at 10 records per code per 60-second window, each code counted separately, and reports drops as the `typed_throttled` gate count; `budget.mjs` reserves that cap. Other diagnostics keep their count aggregation (TC-959, TC-1274). ## [1.20.7] - 2026-10-14 diff --git a/docker-compose.dstack-postgres.yaml b/docker-compose.dstack-postgres.yaml index 0832b100..623d4bb2 100644 --- a/docker-compose.dstack-postgres.yaml +++ b/docker-compose.dstack-postgres.yaml @@ -158,7 +158,7 @@ services: 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 event = if level == \\\"warn\\\" { \\\"node_warning\\\" } else { \\\"node_error\\\" }\\n # Typed diagnostics: an exact (target, message) match ships one record per\\n # occurrence with only its declared fields. A wrong level, a missing field\\n # or any value outside its type, range, enum or hash pattern aborts the\\n # whole record; undeclared fields are never copied.\\n typed = false\\n if target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_lock_wait\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_lock_wait\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"waited_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.waited_ms = n\\n v = get(f, [\\\"ahead_approx\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 1000000 { abort }\\n out.ahead_approx = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_lock_still_waiting\\\" {\\n typed = true\\n if level != \\\"error\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_lock_still_waiting\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"waited_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.waited_ms = n\\n v = get(f, [\\\"ahead_approx\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 1000000 { abort }\\n out.ahead_approx = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_lock_held\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_lock_held\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"held_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.held_ms = n\\n v = get(f, [\\\"hydrate_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.hydrate_ms = n\\n v = get(f, [\\\"execute_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.execute_ms = n\\n v = get(f, [\\\"persist_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.persist_ms = n\\n v = get(f, [\\\"outcome\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"ok\\\",\\\"incomplete\\\",\\\"sqlite\\\",\\\"permission_denied\\\",\\\"database_not_found\\\",\\\"response_too_large\\\",\\\"quota_exceeded\\\",\\\"storage_would_grow\\\",\\\"invalid_statement\\\",\\\"schema_error\\\",\\\"read_only_violation\\\",\\\"parse_error\\\",\\\"internal\\\",\\\"unavailable\\\",\\\"outcome_unknown\\\"], v) { abort }\\n out.outcome = string!(v)\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_still_running\\\" {\\n typed = true\\n if level != \\\"error\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_still_running\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"phase\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"hydrate\\\",\\\"execute\\\",\\\"persist\\\"], v) { abort }\\n out.phase = string!(v)\\n v = get(f, [\\\"held_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.held_ms = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::database\\\" && msg == \\\"sql_actor_message_slow\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_actor_message_slow\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"kind\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"query\\\",\\\"execute\\\",\\\"batch\\\",\\\"execute_statement\\\",\\\"export\\\",\\\"publication\\\",\\\"checkpoint\\\",\\\"wal\\\",\\\"shutdown\\\"], v) { abort }\\n out.kind = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"elapsed_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.elapsed_ms = n\\n v = get(f, [\\\"outcome\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"ok\\\",\\\"incomplete\\\",\\\"sqlite\\\",\\\"permission_denied\\\",\\\"database_not_found\\\",\\\"response_too_large\\\",\\\"quota_exceeded\\\",\\\"storage_would_grow\\\",\\\"invalid_statement\\\",\\\"schema_error\\\",\\\"read_only_violation\\\",\\\"parse_error\\\",\\\"internal\\\",\\\"unavailable\\\",\\\"outcome_unknown\\\"], v) { abort }\\n out.outcome = string!(v)\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::db_pool\\\" && msg == \\\"db_pool_acquire_timeout\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"db_pool_acquire_timeout\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"elapsed_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.elapsed_ms = n\\n v = get(f, [\\\"pool_size\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 100000 { abort }\\n out.pool_size = n\\n v = get(f, [\\\"pool_idle\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 100000 { abort }\\n out.pool_idle = n\\n v = get(f, [\\\"pool_max\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 100000 { abort }\\n out.pool_max = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::db_pool\\\" && msg == \\\"db_connect_failed\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"db_connect_failed\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"class\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"refused\\\",\\\"io\\\",\\\"tls\\\",\\\"database_transient\\\",\\\"database\\\",\\\"after_connect\\\",\\\"timed_out\\\",\\\"other\\\"], v) { abort }\\n out.class = string!(v)\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\n if !typed {\\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 out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": code, \\\"event_count\\\": 1}\\n }\\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\\\") && !includes([\\\"sql_operation_lock_wait\\\",\\\"sql_operation_lock_still_waiting\\\",\\\"sql_operation_lock_held\\\",\\\"sql_operation_still_running\\\",\\\"sql_actor_message_slow\\\",\\\"db_pool_acquire_timeout\\\",\\\"db_connect_failed\\\"], .event_code)\",\"typed_diagnostic\":\"(.event == \\\"node_warning\\\" || .event == \\\"node_error\\\") && includes([\\\"sql_operation_lock_wait\\\",\\\"sql_operation_lock_still_waiting\\\",\\\"sql_operation_lock_held\\\",\\\"sql_operation_still_running\\\",\\\"sql_actor_message_slow\\\",\\\"db_pool_acquire_timeout\\\",\\\"db_connect_failed\\\"], .event_code)\"}},\"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\",\"event_route.typed_diagnostic\",\"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}}}" + 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 event = if level == \\\"warn\\\" { \\\"node_warning\\\" } else { \\\"node_error\\\" }\\n # Typed diagnostics: an exact (target, message) match ships one record per\\n # occurrence with only its declared fields. A wrong level, a missing field\\n # or any value outside its type, range, enum or hash pattern aborts the\\n # whole record; undeclared fields are never copied.\\n typed = false\\n if target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_lock_wait\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_lock_wait\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"waited_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.waited_ms = n\\n v = get(f, [\\\"ahead_approx\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 1000000 { abort }\\n out.ahead_approx = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_lock_still_waiting\\\" {\\n typed = true\\n if level != \\\"error\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_lock_still_waiting\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"waited_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.waited_ms = n\\n v = get(f, [\\\"ahead_approx\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 1000000 { abort }\\n out.ahead_approx = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_lock_held\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_lock_held\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"held_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.held_ms = n\\n v = get(f, [\\\"hydrate_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.hydrate_ms = n\\n v = get(f, [\\\"execute_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.execute_ms = n\\n v = get(f, [\\\"persist_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.persist_ms = n\\n v = get(f, [\\\"outcome\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"ok\\\",\\\"incomplete\\\",\\\"sqlite\\\",\\\"permission_denied\\\",\\\"database_not_found\\\",\\\"response_too_large\\\",\\\"quota_exceeded\\\",\\\"storage_would_grow\\\",\\\"invalid_statement\\\",\\\"schema_error\\\",\\\"read_only_violation\\\",\\\"parse_error\\\",\\\"internal\\\",\\\"unavailable\\\",\\\"outcome_unknown\\\"], v) { abort }\\n out.outcome = string!(v)\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::service\\\" && msg == \\\"sql_operation_still_running\\\" {\\n typed = true\\n if level != \\\"error\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_operation_still_running\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"op\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"execute\\\",\\\"execute_no_growth\\\",\\\"publication\\\",\\\"export\\\"], v) { abort }\\n out.op = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"phase\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"hydrate\\\",\\\"execute\\\",\\\"persist\\\"], v) { abort }\\n out.phase = string!(v)\\n v = get(f, [\\\"held_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.held_ms = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::sql::database\\\" && msg == \\\"sql_actor_message_slow\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"sql_actor_message_slow\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"kind\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"query\\\",\\\"execute\\\",\\\"batch\\\",\\\"execute_statement\\\",\\\"export\\\",\\\"publication\\\",\\\"checkpoint\\\",\\\"wal\\\",\\\"shutdown\\\"], v) { abort }\\n out.kind = string!(v)\\n v = get(f, [\\\"space_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.space_hash = s\\n v = get(f, [\\\"db_hash\\\"]) ?? null\\n if !is_string(v) { abort }\\n s = string!(v)\\n if length(s) > 64 || !match(s, r'^[0-9a-f]{64}$') { abort }\\n out.db_hash = s\\n v = get(f, [\\\"elapsed_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.elapsed_ms = n\\n v = get(f, [\\\"outcome\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"ok\\\",\\\"incomplete\\\",\\\"sqlite\\\",\\\"permission_denied\\\",\\\"database_not_found\\\",\\\"response_too_large\\\",\\\"quota_exceeded\\\",\\\"storage_would_grow\\\",\\\"invalid_statement\\\",\\\"schema_error\\\",\\\"read_only_violation\\\",\\\"parse_error\\\",\\\"internal\\\",\\\"unavailable\\\",\\\"outcome_unknown\\\"], v) { abort }\\n out.outcome = string!(v)\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::db_pool\\\" && msg == \\\"db_pool_acquire_timeout\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"db_pool_acquire_timeout\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"elapsed_ms\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 86400000 { abort }\\n out.elapsed_ms = n\\n v = get(f, [\\\"pool_size\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 100000 { abort }\\n out.pool_size = n\\n v = get(f, [\\\"pool_idle\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 100000 { abort }\\n out.pool_idle = n\\n v = get(f, [\\\"pool_max\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 100000 { abort }\\n out.pool_max = n\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\nif target == \\\"tinycloud_core::db_pool\\\" && msg == \\\"db_connect_failed\\\" {\\n typed = true\\n if level != \\\"warn\\\" { abort }\\n out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": \\\"db_connect_failed\\\", \\\"event_count\\\": 1}\\n v = get(f, [\\\"class\\\"]) ?? null\\n if !is_string(v) || !includes([\\\"refused\\\",\\\"io\\\",\\\"tls\\\",\\\"database_transient\\\",\\\"database\\\",\\\"after_connect\\\",\\\"timed_out\\\",\\\"other\\\"], v) { abort }\\n out.class = string!(v)\\n v = get(f, [\\\"suppressed_count\\\"]) ?? null\\n if !is_integer(v) { abort }\\n n = int!(v)\\n if n < 0 || n > 9007199254740991 { abort }\\n out.suppressed_count = n\\n}\\n if !typed {\\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 out = {\\\"event\\\": event, \\\"svc\\\": \\\"api\\\", \\\"level\\\": level, \\\"event_code\\\": code, \\\"event_count\\\": 1}\\n }\\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\",\"typed_limit_route._unmatched\"],\"source\":\"reason = .reason\\nif !includes([\\\"malformed_envelope\\\",\\\"unexpected_label\\\",\\\"unlabelled\\\",\\\"non_json\\\",\\\"oversized\\\",\\\"partial\\\",\\\"invalid_fields\\\",\\\"unknown_target\\\",\\\"filtered_level\\\",\\\"typed_throttled\\\"], reason) { reason = \\\"invalid_fields\\\" }\\n. = {\\\"reason\\\": reason, \\\"count\\\": 1}\",\"drop_on_error\":true,\"drop_on_abort\":true},\"gate_reduce\":{\"type\":\"reduce\",\"inputs\":[\"gate_counts\",\"typed_limit_route.throttled\"],\"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\\\") && !includes([\\\"sql_operation_lock_wait\\\",\\\"sql_operation_lock_still_waiting\\\",\\\"sql_operation_lock_held\\\",\\\"sql_operation_still_running\\\",\\\"sql_actor_message_slow\\\",\\\"db_pool_acquire_timeout\\\",\\\"db_connect_failed\\\"], .event_code)\",\"typed_diagnostic\":\"(.event == \\\"node_warning\\\" || .event == \\\"node_error\\\") && includes([\\\"sql_operation_lock_wait\\\",\\\"sql_operation_lock_still_waiting\\\",\\\"sql_operation_lock_held\\\",\\\"sql_operation_still_running\\\",\\\"sql_actor_message_slow\\\",\\\"db_pool_acquire_timeout\\\",\\\"db_connect_failed\\\"], .event_code)\"}},\"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},\"typed_limit\":{\"type\":\"lua\",\"version\":\"2\",\"inputs\":[\"event_route.typed_diagnostic\"],\"source\":\"local limit = 10\\nlocal window = 60\\nlocal started = 0\\nlocal seen = {}\\nlocal dropped = 0\\nfunction init(emit)\\n started = os.time()\\nend\\nfunction process(event, emit)\\n local now = os.time()\\n if now - started >= window then\\n seen = {}\\n started = now\\n end\\n local code = event.log.event_code\\n local n = (seen[code] or 0) + 1\\n seen[code] = n\\n if n <= limit then\\n emit(event)\\n else\\n dropped = dropped + 1\\n end\\nend\\nfunction flush(emit)\\n if dropped > 0 then\\n emit({ log = { reason = \\\"typed_throttled\\\", count = dropped } })\\n dropped = 0\\n end\\nend\",\"hooks\":{\"init\":\"init\",\"process\":\"process\",\"shutdown\":\"flush\"},\"timers\":[{\"interval_seconds\":1,\"handler\":\"flush\"}]},\"typed_limit_route\":{\"type\":\"route\",\"inputs\":[\"typed_limit\"],\"route\":{\"record\":\"!exists(.reason)\",\"throttled\":\"exists(.reason)\"}}},\"sinks\":{\"betterstack\":{\"type\":\"http\",\"inputs\":[\"event_route.request\",\"typed_limit_route.record\",\"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 diff --git a/docs/runbooks/tc-959-n0-log-shipping.md b/docs/runbooks/tc-959-n0-log-shipping.md index 10d8873c..d2e7e2c0 100644 --- a/docs/runbooks/tc-959-n0-log-shipping.md +++ b/docs/runbooks/tc-959-n0-log-shipping.md @@ -31,7 +31,7 @@ Parsing failures become fixed counters; no log-level suppression is used. | `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 | -| `node_warning` / `node_error`, `svc=api`, TC-1274 SQL contention `event_code` | `event_count=1` plus only that code's declared fields (`log-shipper/diagnostics.json` `typed`): integer `*_ms`, `ahead_approx`, `suppressed_count`, `pool_size`/`pool_idle`/`pool_max`; fixed `op`/`phase`/`kind`/`outcome`/`class`; keyed `space_hash`/`db_hash`, each exactly 64 lowercase hex | Individually, one record per occurrence, under either profile; never reduced | +| `node_warning` / `node_error`, `svc=api`, TC-1274 SQL contention `event_code` | `event_count=1` plus only that code's declared fields (`log-shipper/diagnostics.json` `typed`): integer `*_ms`, `ahead_approx`, `suppressed_count`, `pool_size`/`pool_idle`/`pool_max`; fixed `op`/`phase`/`kind`/`outcome`/`class`; keyed `space_hash`/`db_hash`, each exactly 64 lowercase hex | Individually, one record per occurrence, under either profile; never reduced; at most 10 per code per 60-second window, excess counted as `typed_throttled` | | `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 @@ -42,12 +42,14 @@ Sam approved **`errors_slow` as the deployment default**. Compose exposes `TINYC - 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. Untyped codes retain their fixed-code count aggregation; the seven TC-1274 SQL contention codes are shipped per occurrence instead (next section). 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. +Both request profiles are unsampled: there is no sampler, random selection, throttle or byte-budget drop for requests. All accepted typed WARN/ERROR diagnostics bypass request-profile filtering. Untyped codes retain their fixed-code count aggregation; the seven TC-1274 SQL contention codes are shipped per occurrence instead, under the explicit per-code cap Sam chose (next section). 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. ### TC-1274 SQL contention diagnostics `sql_operation_lock_wait`, `sql_operation_lock_still_waiting`, `sql_operation_lock_held` and `sql_operation_still_running` from `tinycloud_core::sql::service`, `sql_actor_message_slow` from `tinycloud_core::sql::database`, and `db_pool_acquire_timeout` and `db_connect_failed` from `tinycloud_core::db_pool` are matched by exact (target, message) and fixed level. Each record carries only the fields `diagnostics.json` declares for its code, each checked against its closed schema type. A missing field, a wrong type, an out-of-range integer, a value outside its enum, a hash that is not exactly 64 lowercase hex, or a wrong level rejects the whole record into the `invalid_fields` gate count; no partial record is shipped. Undeclared fields, including a raw `db` name, the pool `operation` label, error text and nested values, are never copied. The same message from any other target stays `unclassified`. The field sets and enums must match the emitted F6 PR before promotion. +The shipper caps these records as defence in depth over the node's own per-(space, database, event) limiter, which cannot bound the total when many databases contend. Sam chose the value (decision `tc-959-f6-log-cap`): `diagnostics.json` `typed_limit` allows at most `records` (10) per code, counted separately for each of the seven codes, in each fixed `window_secs` (60 s) window of the Vector process clock. A window boundary can admit up to twice that within one minute, never more per window. This is a deliberate trade-off: during a storm each code yields 10 per-occurrence samples per minute, enough to tell one long actor message from a sustained queue, and the exact `typed_throttled` count shows the true volume. Excess records are dropped, and only their number leaves, as the `typed_throttled` gate reason, so throttling is visible and never silent; any non-zero `typed_throttled` should alert once the Better Stack alerting slice lands. The counter is a Lua transform keyed only by the seven fixed codes. It restarts empty with the process. + 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. @@ -70,7 +72,7 @@ Under `errors_slow`, node and ingress eligibility are evaluated independently: a 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 59 codes at both severities (118 groups/minute) plus nine rejection groups/minute: **912,340,800 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 2,003,572,800 bytes. The SQL contention diagnostics are per occurrence and are NOT in that model: a maximum-width record is at most 475 bytes with its newline, the shipper applies no cap, and their rate is bounded only by the node's own per-(space, database, event) limiter, so it scales with the number of contended databases. Measure it separately. [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. +Diagnostics are **additional**, not secretly subtracted from the request allocation; only the SQL contention records are sampled, at the explicit cap above. The continuous storm model covers all 59 codes at both severities (118 groups/minute) plus ten rejection groups/minute: **919,123,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. The SQL contention records are reserved separately at the shipper cap, 7 codes × 10 = 70 records/minute of at most 474 bytes each with the newline: **1,990,800 bytes per storm hour** and **1,433,376,000 bytes/30 days** if sustained for the whole month. At 60 **eligible pairs/minute** plus both storms sustained, the model totals 3,443,731,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 diff --git a/log-shipper/budget.mjs b/log-shipper/budget.mjs index fdd6fc27..30754d85 100644 --- a/log-shipper/budget.mjs +++ b/log-shipper/budget.mjs @@ -3,6 +3,20 @@ 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, ''); +const diagnostics = JSON.parse(readFileSync(new URL('./diagnostics.json', import.meta.url), 'utf8')); +/** The widest valid wire record of one typed diagnostic: maximum integers, longest enum values, full-length hashes. */ +const widestTyped = code => { + const { level, fields } = diagnostics.typed[code]; + const record = { level, ts: '9999-12-31T23:59:59.999Z', event: level === 'warn' ? 'node_warning' : 'node_error', svc: 'api', event_code: code, event_count: 1 }; + for (const name of fields) { + const spec = schema.fields[name]; + record[name] = spec.type === 'integer' ? spec.max : spec.type === 'enum' ? longest(spec.values) : 'f'.repeat(spec.max_len); + } + return record; +}; +const typedWidest = Object.keys(diagnostics.typed).map(widestTyped).reduce((chosen, record) => Buffer.byteLength(JSON.stringify(record)) > Buffer.byteLength(JSON.stringify(chosen)) ? record : chosen); +/** The shipper cap: per typed code, at most `records` per `window_secs`, so this many records per minute in total. */ +const typedCapPerMinute = Object.keys(diagnostics.typed).length * diagnostics.typed_limit.records * 60 / diagnostics.typed_limit.window_secs; /** Thirty days, not a calendar-month or billing-period guarantee. */ export const MINUTES_30_DAYS = 30 * 24 * 60; @@ -27,6 +41,7 @@ export const representativeEvents = Object.freeze({ 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 }), + typed: Object.freeze(typedWidest), }); /** @@ -54,22 +69,25 @@ export function calculateBudget({ requestsPerMinute = 1, diagnosticEventsPerMinute = schema.fields.event_code.values.length * 2, gateEventsPerMinute = schema.fields.reason.values.length, + typedEventsPerMinute = typedCapPerMinute, allocationBytes = REQUEST_ALLOCATION_BYTES, framing = 'ndjson', } = {}) { - for (const [name, value] of Object.entries({ requestsPerMinute, diagnosticEventsPerMinute, gateEventsPerMinute, allocationBytes })) { + for (const [name, value] of Object.entries({ requestsPerMinute, diagnosticEventsPerMinute, gateEventsPerMinute, typedEventsPerMinute, 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; + // Per-occurrence typed records, by default at the shipper cap sustained for 30 days. + const typedReserveBytes30Days = typedEventsPerMinute * eventBytes.typed * 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, + requestBytes30Days, diagnosticReserveBytes30Days, typedEventsPerMinute, typedReserveBytes30Days, + totalBytes30Days: requestBytes30Days + diagnosticReserveBytes30Days + typedReserveBytes30Days, sustainableRequestsPerMinute, sustainableWholeRequestsPerMinute: Math.floor(sustainableRequestsPerMinute), withinRequestAllocation: requestBytes30Days <= allocationBytes, diff --git a/log-shipper/budget.test.mjs b/log-shipper/budget.test.mjs index c4fa4ebb..46fc89e7 100644 --- a/log-shipper/budget.test.mjs +++ b/log-shipper/budget.test.mjs @@ -2,6 +2,7 @@ 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'; +import { assertCapture } from '../scripts/tc959-docker.mjs'; const fields = JSON.parse(await readFile(new URL('./fields.json', import.meta.url), 'utf8')); const nodeSchema = fields.services['tinycloud-node']; @@ -34,8 +35,8 @@ test('exact serialized bytes account for newlines or singleton JSON array overhe }); 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 one = calculateBudget({ requestsPerMinute: 1, diagnosticEventsPerMinute: 0, gateEventsPerMinute: 0, typedEventsPerMinute: 0 }); + const many = calculateBudget({ requestsPerMinute: 10000, diagnosticEventsPerMinute: 0, gateEventsPerMinute: 0, typedEventsPerMinute: 0 }); const pair = serializedEventBytes(representativeEvents.node, 'ndjson') + serializedEventBytes(representativeEvents.ingress, 'ndjson'); assert.equal(one.requestPairBytes, pair); assert.equal(one.requestBytes30Days, pair * 43200); @@ -59,7 +60,7 @@ test('allocation boundary is sustainable requests per minute, not a throttle', ( }); test('fixed diagnostic reserve is separate from the request allocation', () => { - const budget = calculateBudget({ requestsPerMinute: 1, diagnosticEventsPerMinute: 53, gateEventsPerMinute: 9 }); + const budget = calculateBudget({ requestsPerMinute: 1, diagnosticEventsPerMinute: 53, gateEventsPerMinute: 9, typedEventsPerMinute: 0 }); assert.equal(budget.diagnosticReserveBytes30Days, 43200 * (53 * serializedEventBytes(representativeEvents.diagnostic, 'ndjson') + 9 * serializedEventBytes(representativeEvents.gate, 'ndjson'))); assert.equal(budget.totalBytes30Days, budget.requestBytes30Days + budget.diagnosticReserveBytes30Days); @@ -67,7 +68,32 @@ test('fixed diagnostic reserve is separate from the request allocation', () => { const noTraffic = calculateBudget({ requestsPerMinute: 0 }); assert.equal(noTraffic.requestBytes30Days, 0); assert.ok(noTraffic.diagnosticReserveBytes30Days > 0); - assert.equal(noTraffic.totalBytes30Days, noTraffic.diagnosticReserveBytes30Days); + assert.equal(noTraffic.totalBytes30Days, noTraffic.diagnosticReserveBytes30Days + noTraffic.typedReserveBytes30Days); +}); + +test('typed per-occurrence diagnostics are reserved at the shipper cap with each code\'s widest valid record', async () => { + const diagnostics = JSON.parse(await readFile(new URL('./diagnostics.json', import.meta.url), 'utf8')); + const codes = Object.keys(diagnostics.typed); + const { records, window_secs } = diagnostics.typed_limit; + // Sam's decision (tc-959-f6-log-cap): 10 records per typed code per minute, each code counted separately. + assert.deepEqual(diagnostics.typed_limit, { records: 10, window_secs: 60 }); + // Every code's widest record is valid on the wire and no wider than the budgeted representative. + for (const code of codes) { + const { level, fields } = diagnostics.typed[code]; + const widest = { ts: '9999-12-31T23:59:59.999Z', level, event: level === 'warn' ? 'node_warning' : 'node_error', svc: 'api', event_code: code, event_count: 1 }; + for (const name of fields) { + const spec = nodeSchema.fields[name]; + widest[name] = spec.type === 'integer' ? spec.max : spec.type === 'enum' ? spec.values.reduce((a, b) => (b.length > a.length ? b : a)) : 'f'.repeat(spec.max_len); + } + assert.doesNotThrow(() => assertCapture([widest], nodeSchema.fields)); + assert.ok(serializedEventBytes(widest) <= serializedEventBytes(representativeEvents.typed), code); + } + const budget = calculateBudget({ requestsPerMinute: 0, diagnosticEventsPerMinute: 0, gateEventsPerMinute: 0 }); + assert.equal(budget.typedEventsPerMinute, codes.length * records * 60 / window_secs); + assert.equal(budget.typedEventsPerMinute, 70); + assert.equal(budget.typedReserveBytes30Days, budget.typedEventsPerMinute * serializedEventBytes(representativeEvents.typed) * MINUTES_30_DAYS); + assert.equal(budget.totalBytes30Days, budget.typedReserveBytes30Days); + assert.equal(calculateBudget({ requestsPerMinute: 0, typedEventsPerMinute: 0 }).typedReserveBytes30Days, 0); }); test('diagnostic storm reserve covers every code at both severity levels', () => { @@ -78,7 +104,7 @@ test('diagnostic storm reserve covers every code at both severity levels', () => }); test('invalid numeric budgets fail rather than hiding impossible volume', () => { - for (const field of ['requestsPerMinute', 'diagnosticEventsPerMinute', 'gateEventsPerMinute', 'allocationBytes']) { + for (const field of ['requestsPerMinute', 'diagnosticEventsPerMinute', 'gateEventsPerMinute', 'typedEventsPerMinute', 'allocationBytes']) { for (const value of [-1, NaN, Infinity, '1']) assert.throws(() => calculateBudget({ [field]: value }), /finite non-negative/); } assert.throws(() => calculateBudget({ framing: 'raw' }), /framing/); diff --git a/log-shipper/cases.mjs b/log-shipper/cases.mjs index fffceff1..538aa855 100644 --- a/log-shipper/cases.mjs +++ b/log-shipper/cases.mjs @@ -1,6 +1,9 @@ +import { readFileSync } from 'node:fs'; // 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'; +// The shipper cap per typed code per window (Sam, tc-959-f6-log-cap); fixtures derive from it. +const typedCap = JSON.parse(readFileSync(new URL('./diagnostics.json', import.meta.url), 'utf8')).typed_limit.records; 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 }); @@ -40,6 +43,12 @@ const f6Check = (name, input, assertion, extract = 'allowlist') => ({ name, inpu const f6Reject = (name, input) => ({ name, inputs: [{ insert_at: 'logship_gate', type: 'log', log_fields: logFields(envelope(input)) }], no_outputs_from: ['allowlist'], outputs: [{ extract_from: 'gate_counts', conditions: [{ type: 'vrl', source: 'assert!(.count == 1 && .reason == "invalid_fields")\nassert!(!contains(encode_json(.), "TC959_SYNTHETIC"))' }] }] }); const hostileExtras = { db: 'v2n', operation: 'begin', error: canary, err: canary, sql: `SELECT '${canary}'`, nested: { space: canary }, space: canary, did: canary }; const integerFields = { waited_ms: 86_400_000, held_ms: 86_400_000, hydrate_ms: 86_400_000, execute_ms: 86_400_000, persist_ms: 86_400_000, elapsed_ms: 86_400_000, ahead_approx: 1_000_000, suppressed_count: 9_007_199_254_740_991, pool_size: 100_000, pool_idle: 100_000, pool_max: 100_000 }; +/** An admitted F6 wire record, as the allowlist emits it. */ +const f6Wire = name => { + const { level, fields } = f6Events[name]; + const lower = level.toLowerCase(); + return { ts: timestamp, level: lower, event: lower === 'warn' ? 'node_warning' : 'node_error', svc: 'api', event_code: name, event_count: 1, ...fields }; +}; const f6Tests = [ ...Object.keys(f6Events).map(name => f6Check(`F6 ${name} keeps exactly its typed fields`, f6Line(name), f6Expected(name))), ...Object.keys(f6Events).map(name => f6Check(`F6 ${name} drops raw db, pool operation, error text and nested extras`, f6Line(name, hostileExtras), f6Expected(name))), @@ -81,6 +90,28 @@ const f6Tests = [ no_outputs_from: ['diagnostic_output'], outputs: [{ extract_from: 'event_route.typed_diagnostic', conditions: [{ type: 'vrl', source: `assert!(.event_count == 1 && (.waited_ms == 61000 || .waited_ms == 62000))\nassert!(${f6Safe})` }] }], }, + // Shipper-side cap (defence in depth over the node limiter): at most `typedCap` records per code per window. + { + name: 'typed cap passes up to its limit for each code unchanged and counts nothing', + inputs: [...Array(typedCap).fill('sql_operation_lock_wait'), ...Array(typedCap).fill('db_connect_failed')].map(name => ({ insert_at: 'logship_gate', type: 'log', log_fields: logFields(envelope(f6Line(name))) })), + no_outputs_from: ['typed_limit_route.throttled'], + outputs: [{ extract_from: 'typed_limit_route.record', conditions: [{ type: 'vrl', source: `assert!(.event_count == 1 && ((.event_code == "sql_operation_lock_wait" && is_integer(.waited_ms) && .waited_ms == 61000 && length(keys(.)) == 12) || (.event_code == "db_connect_failed" && .class == "refused" && length(keys(.)) == 8)))\nassert!(${f6Safe})` }] }], + }, + { + name: 'typed cap drops the record past its limit and counts it without content', + inputs: Array(typedCap + 1).fill('sql_operation_lock_wait').map(name => ({ insert_at: 'typed_limit', type: 'log', log_fields: f6Wire(name) })), + outputs: [{ extract_from: 'typed_limit_route.throttled', conditions: [{ type: 'vrl', source: 'assert!(.reason == "typed_throttled" && .count == 1 && length(keys(.)) == 2)' }] }], + }, + { + name: 'typed cap drops surface in the gate summary as an exact count', + inputs: Array(typedCap + 65).fill('sql_actor_message_slow').map(name => ({ insert_at: 'typed_limit', type: 'log', log_fields: f6Wire(name) })), + outputs: [{ extract_from: 'gate_output', conditions: [{ type: 'vrl', source: 'assert!(.reason == "typed_throttled" && .count == 65 && .event == "logship_gate_summary_total" && length(keys(.)) == 6)' }] }], + }, + { + name: 'typed cap applies to raw node lines end to end', + inputs: Array(typedCap + 1).fill('db_pool_acquire_timeout').map(name => ({ insert_at: 'logship_gate', type: 'log', log_fields: logFields(envelope(f6Line(name, { error: canary }))) })), + outputs: [{ extract_from: 'gate_output', conditions: [{ type: 'vrl', source: 'assert!(.reason == "typed_throttled" && .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'), diff --git a/log-shipper/diagnostics.json b/log-shipper/diagnostics.json index 34d3dcea..22f935d0 100644 --- a/log-shipper/diagnostics.json +++ b/log-shipper/diagnostics.json @@ -64,5 +64,6 @@ "db_pool_acquire_timeout": { "target": "tinycloud_core::db_pool", "level": "warn", "fields": ["elapsed_ms", "pool_size", "pool_idle", "pool_max", "suppressed_count"] }, "db_connect_failed": { "target": "tinycloud_core::db_pool", "level": "warn", "fields": ["class", "suppressed_count"] } }, + "typed_limit": { "records": 10, "window_secs": 60 }, "fallback": "unclassified" } diff --git a/log-shipper/fields.json b/log-shipper/fields.json index 66f5ac93..bbd17128 100644 --- a/log-shipper/fields.json +++ b/log-shipper/fields.json @@ -80,7 +80,7 @@ "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", "sql_operation_lock_wait", "sql_operation_lock_still_waiting", "sql_operation_lock_held", "sql_operation_still_running", "sql_actor_message_slow", "db_pool_acquire_timeout", "db_connect_failed", "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"] }, + "reason": { "type": "enum", "values": ["malformed_envelope", "unexpected_label", "unlabelled", "non_json", "oversized", "partial", "invalid_fields", "unknown_target", "filtered_level", "typed_throttled"] }, "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" }, diff --git a/scripts/tc959-logship.mjs b/scripts/tc959-logship.mjs index e358f4ca..594bc4d9 100644 --- a/scripts/tc959-logship.mjs +++ b/scripts/tc959-logship.mjs @@ -65,6 +65,37 @@ export function buildConfig({ sinkUri = 'https://s2795437.us-west-2a.betterstack const diagnostics = load('diagnostics.json'); const typedCodes = JSON.stringify(Object.keys(diagnostics.typed)); const typedSource = typedDiagnostics(diagnostics, schema.fields); + const { records: typedLimit, window_secs: typedWindow } = diagnostics.typed_limit; + if (!Number.isSafeInteger(typedLimit) || typedLimit < 1 || !Number.isSafeInteger(typedWindow) || typedWindow < 1) throw new TypeError('invalid typed diagnostic limit'); + const typedLimitSource = `local limit = ${typedLimit} +local window = ${typedWindow} +local started = 0 +local seen = {} +local dropped = 0 +function init(emit) + started = os.time() +end +function process(event, emit) + local now = os.time() + if now - started >= window then + seen = {} + started = now + end + local code = event.log.event_code + local n = (seen[code] or 0) + 1 + seen[code] = n + if n <= limit then + emit(event) + else + dropped = dropped + 1 + end +end +function flush(emit) + if dropped > 0 then + emit({ log = { reason = "typed_throttled", count = dropped } }) + dropped = 0 + end +end`; // Function replacements: VRL regex literals contain `$'`, a replacement pattern. let sanitize = readFileSync(resolve(root, 'log-shipper/sanitize.vrl'), 'utf8') .replaceAll('__METHODS__', JSON.stringify(schema.fields.method.values)) @@ -125,19 +156,24 @@ if reason != "" { }`), 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 + gate_counts: remap(['gate_route.rejected', 'gate_route._unmatched', 'allowlist.dropped', 'event_route._unmatched', 'typed_limit_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_reduce: { type: 'reduce', inputs: ['gate_counts', 'typed_limit_route.throttled'], 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)})` }, // Typed diagnostics keep their per-occurrence fields; only untyped codes are counted by reduction. event_route: { type: 'route', inputs: ['request_profile'], route: { request: '.event == "node_request" || .event == "ingress_request"', diagnostic: `(.event == "node_warning" || .event == "node_error") && !includes(${typedCodes}, .event_code)`, typed_diagnostic: `(.event == "node_warning" || .event == "node_error") && includes(${typedCodes}, .event_code)` } }, 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}`), + // Shipper-side cap, defence in depth over the node's own limiter: per event_code, at most + // `records` per fixed `window_secs` window. Excess records are dropped and only their count + // leaves, as the `typed_throttled` gate reason. Keys are the closed typed code set. + typed_limit: { type: 'lua', version: '2', inputs: ['event_route.typed_diagnostic'], source: typedLimitSource, hooks: { init: 'init', process: 'process', shutdown: 'flush' }, timers: [{ interval_seconds: 1, handler: 'flush' }] }, + typed_limit_route: { type: 'route', inputs: ['typed_limit'], route: { record: '!exists(.reason)', throttled: 'exists(.reason)' } }, }, sinks: { betterstack: { - type: 'http', inputs: ['event_route.request', 'event_route.typed_diagnostic', 'diagnostic_output', 'gate_output'], method: 'post', uri: sinkUri, + type: 'http', inputs: ['event_route.request', 'typed_limit_route.record', '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 },