Skip to content

feat: json log format and W3C trace context propagation#446

Open
joaopaulosr95 wants to merge 1 commit into
HDFGroup:masterfrom
joaopaulosr95:feat/structured-logging
Open

feat: json log format and W3C trace context propagation#446
joaopaulosr95 wants to merge 1 commit into
HDFGroup:masterfrom
joaopaulosr95:feat/structured-logging

Conversation

@joaopaulosr95

Copy link
Copy Markdown

Adds per-request correlation to hsds logs and an optional JSON output format as a way to make it easier to debug it in production.

Motivation

On a busy node, log lines from all in-flight requests interleave with nothing tying a line to the request that produced it, and there's no way to match SN and DN logs for the same client call. OTel-instrumented clients (h5pyd via requests instrumentation included) already send a W3C traceparent header; hsds just needs to read and forward it.

What changed

  • log.request() adopts the incoming traceparent (or generates a fresh trace id) into a ContextVar, so every line logged while handling that request carries its trace id
  • httpUtil.http_get/post/put/delete forward the header to DNs — one grep finds a client request across all nodes
  • new log_format config key: text (default, same REQ>/RSP>/LEVEL> layout as today) or json (one object per line, with method/path/domain on REQ and status/reason/path on RSP lines). Settable via config.yml, LOG_FORMAT env var, or --log_format
  • timestamps are now ISO 8601 UTC and on by default (log_timestamps: true)
  • removed the dead log-level filter in hsds_app._enqueue_output (was overridden by put_line = True since introduction)

Sample output, same request seen on SN and DN:

sn 2026-07-17T21:28:04.274Z REQ> [aaaabbbbccccdddd0000111122223333] PUT: / [hsdstest/home]
dn1 2026-07-17T21:28:04.292Z REQ> [aaaabbbbccccdddd0000111122223333] POST: /groups

{
  "time": "2026-07-17T21:29:04.832Z", 
  "level": "INFO", 
  "node": "sn", 
  "trace_id": "99998888777766665555444433332222", 
  "method": "GET", 
  "path": "/", 
  "domain": "hsdstest/home", 
  "msg": "GET: / [hsdstest/home]"
}  

Logger API is unchanged (log.info(...) etc.), so no call sites were touched; log_stats/req_count in /info behave as before.

Malformed traceparent headers are ignored, and a fresh trace id is generated.

Testing

New unit tests in tests/unit/logger_test.py cover both formats, level filtering, traceparent parse/generate/reject, and header forwarding on all four http_* helpers against a real aiohttp test server. Also verified on a local SN + 2 DN posix deployment: a single client PUT logs the same trace id on sn/dn1/dn2 in both formats.

@joaopaulosr95

Copy link
Copy Markdown
Author

@jreadey @mattjala flagging you both as you're the top contributors of this project. Yet independent of 447, this is also part of my attempt to make HSDS easier to operate.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant