Skip to content

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

Merged
jreadey merged 4 commits into
HDFGroup:masterfrom
joaopaulosr95:feat/structured-logging
Jul 24, 2026
Merged

feat: json log format and W3C trace context propagation#446
jreadey merged 4 commits into
HDFGroup:masterfrom
joaopaulosr95:feat/structured-logging

Conversation

@joaopaulosr95

Copy link
Copy Markdown
Contributor

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
Contributor 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.

@jhendersonHDF
jhendersonHDF requested a review from jreadey July 21, 2026 16:03
Comment thread hsds/hsds_logger.py
if extra:
obj.update(extra)
obj["msg"] = msg
print(json.dumps(obj, default=str))
Comment thread hsds/hsds_logger.py
tag = level_name
ts = _timestamp()
trace = f"[{trace_id}] " if trace_id else ""
print(f"{prefix}{ts}{tag}> {trace}{msg}")
@jreadey jreadey self-assigned this Jul 24, 2026
Comment thread hsds/hsds_logger.py
if extra:
obj.update(extra)
obj["msg"] = msg
print(json.dumps(obj, default=str))

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks like this is a false positive from the security agent.

@jreadey jreadey left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good! This is something I've been meaning to do myself for sometime.
There's one security warning, but seems there's no real issue.

@jreadey
jreadey merged commit f91f9e0 into HDFGroup:master Jul 24, 2026
22 of 23 checks passed
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.

3 participants