feat(logger): add new logging apis - #759
Conversation
Codex Review SummaryThis comment shows the latest Codex review activity on this pull request.
ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
Codex reacts with 👀 while any review is running, comments if it has suggestions, and reacts with 👍 once all reviews finish with no findings. |
fb2baaa to
29dcbc0
Compare
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: fd6b7345e4
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
| ) | ||
| rendered_metadata["braintrust.template"] = body | ||
| try: | ||
| rendered_body = body.format_map(_LogTemplateParameters(parameters)) |
There was a problem hiding this comment.
When an omitted placeholder has a conversion or format specifier, such as logger.info("{user} owes {amount:.2f}", user="alice"), __missing__ supplies the string "{amount}", formatting that string as a float raises, and this broad fallback restores the entire original template. Consequently even supplied parameters are left uninterpolated, contrary to the documented behavior that only missing parameters remain as placeholders. Preserve the missing field's conversion/specifier instead of abandoning all rendering.
Useful? React with 👍 / 👎.
| if parameters: | ||
| if not isinstance(body, str): | ||
| raise TypeError("Log body must be a string when template parameters are provided") | ||
| rendered_metadata = dict(metadata) if metadata is not None else {} |
There was a problem hiding this comment.
When a caller combines template parameters with Pydantic-style metadata accepted by the rest of the logger API, this direct conversion can raise TypeError: an object implementing the supported model_dump() or dict() protocol is not necessarily iterable. The same metadata works when no template parameters are supplied because the normal event sanitizer handles those protocols, so logger.info("User {id}", metadata=model, id=...) unexpectedly emits no log. Retain the Metadata input contract and normalize it before merging the template attributes.
Useful? React with 👍 / 👎.
fd6b734 to
657bcd3
Compare
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 657bcd32df
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
|
|
||
| def info(self, body: Any, metadata: dict[str, Any] | None = None, **parameters: object) -> str: | ||
| """Capture a log at OpenTelemetry INFO severity.""" | ||
| return self.emit_log(body=body, level="info", metadata=metadata, **parameters) |
There was a problem hiding this comment.
level as a template parameter in helpers
When a severity helper is given a template parameter named level, such as logger.info("Connected at {level}", level="database"), the helper collects it in parameters and then passes it alongside the fixed level="info" argument, causing Python to raise TypeError: got multiple values for keyword argument 'level' before any log is emitted. Since named placeholders are otherwise advertised without restrictions, pass template parameters through a non-colliding container or render them before forwarding.
Useful? React with 👍 / 👎.
| parameters = record.args.items() if isinstance(record.args, dict) else enumerate(record.args) | ||
| metadata.update({f"braintrust.template.parameter.{key}": value for key, value in parameters}) |
There was a problem hiding this comment.
When standard logging interpolation uses a non-dict mapping such as collections.UserDict (logger.info("%(user)s", UserDict(user="alice"))), LogRecord stores that mapping directly in record.args and formats the message successfully. This branch instead treats it as positional arguments and enumerates its keys, recording braintrust.template.parameter.0 = "user" rather than braintrust.template.parameter.user = "alice", so the emitted template attributes are silently incorrect; recognize general Mapping instances here.
Useful? React with 👍 / 👎.
Abhijeet Prasad (AbhiPrasad)
changed the title
Add `Logger.emit_log()` so applications can emit independent `type="log"`
rows without constructing spans manually. Correlate rows with the active
Braintrust or OpenTelemetry context when available.
Seed each logger with a baseline trace ID for unscoped logs. This keeps
consecutive logs from one logger together while preserving unique row and span
IDs, and avoids grouping logs emitted by separate logger instances.
Map the six base OpenTelemetry severities into `context.otel.log` and add
`trace()`, `debug()`, `info()`, `warn()`, `error()`, and `fatal()` helpers.
logger.error("Payment failed", metadata={"payment_id": "pay_123"})
helper -> emit_log -> `type="log"` row
|-- active span: reuse trace/span IDs
`-- no span: reuse logger trace, generate span ID
Allow `emit_log()` and severity helpers to interpolate named parameters with Python format strings. Preserve the original template and parameter values in `braintrust.template` metadata so repeated messages remain queryable by their stable structure. Missing placeholders and malformed templates remain unchanged so logging does not disrupt application code.
Expose an opt-in standard-library logging handler that forwards formatted records, source metadata, timestamps, and template parameters through the Braintrust logging API while avoiding recursive SDK transport logs.
6ad11dc to
f8a9011
Compare
Render string.templatelib.Template bodies with their embedded values while retaining the reconstructed template and raw parameters in metadata. Load templatelib only on Python 3.14+ so the SDK remains compatible with Python 3.10 through 3.13.
|
🚀 |
Align emitted rows with the updated logs schema by moving canonical severity from metadata to span_attributes.log_level. This keeps user and template metadata free of schema-owned fields.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 75a1b2aecb
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
| parameter_name = interpolation.expression.strip() or str(index) | ||
| parameters[parameter_name] = interpolation.value |
There was a problem hiding this comment.
When a t-string repeats an expression that produces different values, such as it = iter([1, 2]); logger.info(t"{next(it)} {next(it)}"), both interpolations use the same parameter_name, so the second assignment silently overwrites the first. The rendered body remains "1 2", but the retained metadata contains only braintrust.template.parameter.next(it) = 2, losing a raw parameter the API promises to retain; use occurrence-specific keys when an expression is repeated.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 6e6c8b8. Repeated expressions now receive occurrence-specific keys in evaluation order (for example, next(it).0 and next(it).1), so every raw value is retained. Unique expressions keep their existing unsuffixed keys. Added a regression test for the 1 2 case.
logging.shutdown holds a handler lock while flush waits for HTTP workers. Filter Braintrust and urllib3 records through Handler.filter so those workers never try to acquire the same lock.
Suffix repeated interpolation expressions by occurrence so each evaluated value is preserved in log metadata. Unique expressions keep their existing parameter keys.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 6e6c8b84c4
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
| name="Log", | ||
| type=SpanTypeAttribute.LOG, | ||
| span_attributes={"log_level": level}, | ||
| start_time=captured_at, |
There was a problem hiding this comment.
When the handler forwards a replayed or synthetic LogRecord whose created value is exactly 0, this passes 0 into SpanImpl, where start_time or time.time() treats it as absent. The resulting row retains created and metrics.end at the Unix epoch but records metrics.start as the current time, corrupting the promised original timestamp and producing an invalid duration; handle zero explicitly rather than relying on the span constructor's falsy fallback.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 1289051. SpanImpl now treats only None as an absent start time, so a valid 0 timestamp is preserved. Added a regression test that sends a LogRecord with created = 0 through BraintrustLogHandler and verifies created, metrics.start, and metrics.end all remain at the Unix epoch.
Treat only None as an absent start time so replayed epoch log records keep created, start, and end timestamps aligned.
Keep the internal log span name while excluding it from serialized log rows so the schema contains only log-specific span attributes.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 73bf23d97d
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
| parameters = record.args.items() if isinstance(record.args, dict) else enumerate(record.args) | ||
| metadata.update({f"braintrust.template.parameter.{key}": value for key, value in parameters}) |
There was a problem hiding this comment.
When standard logging receives a mapping as its sole positional value, such as logger.info("payload=%s", {"id": 1}), LogRecord unwraps the one-element tuple and stores the dictionary directly in record.args, even though %s still formats the whole dictionary as argument 0. This branch instead interprets every dictionary as named interpolation and records braintrust.template.parameter.id = 1, losing the actual raw parameter braintrust.template.parameter.0 = {"id": 1}. Distinguish named %(key)s interpolation from a mapping supplied to a positional placeholder before constructing the metadata.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 6841bdf. Mapping-shaped LogRecord.args are now expanded by key only when the template contains an active named %(key) placeholder. A mapping used with a positional %s is retained as braintrust.template.parameter.0, and escaped %%(key)s is handled as positional. Added regression coverage for all three cases.
| "asctime", | ||
| "message", | ||
| } | ||
| _IGNORED_LOGGER_PREFIXES = ("braintrust", "urllib3") |
There was a problem hiding this comment.
When this handler is attached to a root or application logger, the prefix filter drops every urllib3 record before emission, including requests made by the application to its own services rather than by Braintrust. Applications commonly rely on urllib3.connectionpool logs for HTTP diagnostics, so enabling the Braintrust handler silently excludes that entire class of user logs. Scope recursion prevention to Braintrust transport activity rather than filtering the global urllib3 namespace.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 0d1073b. We no longer suppress the global urllib3 namespace. Braintrust HTTPConnection and Transport request scopes now set a ContextVar guard, and BraintrustLogHandler filters records only while that SDK transport guard is active (plus the existing braintrust logger namespace). Added regressions showing application urllib3 records are forwarded and SDK transport records are rejected before the handler lock, preserving the shutdown deadlock fix.
Mark Braintrust HTTP request scopes explicitly so the log handler suppresses only SDK transport activity instead of the entire urllib3 namespace.
Inspect percent-style placeholders before expanding mapping arguments so dictionaries passed to positional placeholders remain a single raw parameter.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 6841bdfe31
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
| if isinstance(record.args, Mapping) and _uses_named_percent_parameters(record.msg): | ||
| parameters = record.args.items() | ||
| else: | ||
| positional_args = (record.args,) if isinstance(record.args, Mapping) else record.args | ||
| parameters = enumerate(positional_args) |
There was a problem hiding this comment.
The new named-placeholder discriminator still loses positional parameter metadata for valid mixed templates. For example, logger.info("%s %(id)s", {"id": 1}) is rendered successfully by standard logging because the mapping is consumed both as the %s value and by %(id)s, but this branch records only braintrust.template.parameter.id and omits braintrust.template.parameter.0 for the positional placeholder. Handle mixed positional/named templates by retaining the mapping in both applicable forms.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 2b16d11. Percent placeholders are now scanned for positional and named usage independently. For %s %(id)s with {"id": 1}, metadata retains both braintrust.template.parameter.0 = {"id": 1} and braintrust.template.parameter.id = 1. Existing positional-only, named-only, and escaped-percent cases remain covered.
Detect positional and named percent placeholders independently so mixed mapping templates preserve both the raw positional value and keyed parameters.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 2b16d113dd
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
|
|
||
| class _InternalLogFilter(logging.Filter): | ||
| def filter(self, record: logging.LogRecord) -> bool: | ||
| return not _is_ignored_logger(record.name) and not _is_internal_http_transport() |
There was a problem hiding this comment.
When this handler is used behind a standard QueueHandler/QueueListener, filter() executes on the listener thread, so this ContextVar reads its default False even for an urllib3 record created inside a guarded Braintrust request. Fresh evidence beyond the prior fix is that the marker exists only in the originating execution context and is not attached to the LogRecord. With urllib3 debug or retry logging enabled, the handler can therefore re-ingest Braintrust transport logs and each upload can generate another record, causing an unbounded logging cycle; carry an internal marker on the record or otherwise make recursion filtering survive asynchronous dispatch.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 751ef63. BraintrustLogHandler now installs a chain-preserving LogRecordFactory that stamps records created while the Braintrust HTTP transport guard is active. The handler filter checks that persisted marker as well as the live ContextVar, so QueueHandler/QueueListener thread handoff retains recursion protection. Added an end-to-end queued-record regression that verifies the marker survives QueueHandler.prepare and the listener suppresses the record.
Stamp guarded transport records at creation time so QueueHandler and QueueListener dispatch cannot lose recursion protection across thread boundaries.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 751ef63974
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
| valid_levels = ", ".join(_LOG_LEVELS) | ||
| raise ValueError(f"Invalid log level {level!r}. Expected one of: {valid_levels}") | ||
|
|
||
| span_info = self.state.context_manager.get_current_span_info() |
There was a problem hiding this comment.
When BraintrustLogHandler runs behind a standard QueueHandler/QueueListener, this lookup executes on the listener thread, whose context does not contain the Braintrust or OpenTelemetry span that was active when the record was created. Logs emitted inside a span are therefore assigned the logger's baseline trace and a new span ID instead of being correlated with the active span; snapshot the originating span/trace IDs onto the LogRecord before it is queued and use them here.
Useful? React with 👍 / 👎.
| if key not in _STANDARD_LOG_RECORD_ATTRIBUTES and not key.startswith("_") | ||
| } | ||
|
|
||
| if record.args and isinstance(record.msg, str): |
There was a problem hiding this comment.
When this handler is consumed by a standard QueueListener, QueueHandler.prepare() renders the message and then sets record.args to None before enqueueing it. Consequently this condition is false for every queued parameterized log, so the rendered body survives but braintrust.template and all raw braintrust.template.parameter.* metadata are silently lost; preserve the template and arguments on the record at creation/enqueue time.
Useful? React with 👍 / 👎.
Snapshot template arguments and active span IDs when a LogRecord is created so QueueHandler preparation and QueueListener thread boundaries do not discard them. Key span snapshots by Braintrust state so queued records remain correlated with the handler's originating context.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: f8de8a57db
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
| with _LOG_RECORD_FACTORY_LOCK: | ||
| context_managers = tuple(_CONTEXT_MANAGERS.items()) |
There was a problem hiding this comment.
When a multithreaded application forks while another thread holds _LOG_RECORD_FACTORY_LOCK, the child inherits the lock in its acquired state but not the thread that can release it. Because the installed process-global record factory acquires this lock for every subsequent record, the child then hangs permanently on its first log call. Register an os.register_at_fork child reset for this lock or avoid acquiring a non-fork-aware lock in the record factory.
Useful? React with 👍 / 👎.
Tag urllib3 records at their source only while Braintrust HTTP transport is active. This keeps the marker queue-safe without suppressing unrelated application logs that happen to run in the same transport context. Keep tagged records available to non-Braintrust handlers while rejecting them before the Braintrust handler lock.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 0ff09af1a0
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
|
|
||
| def record_factory(*args: Any, **kwargs: Any) -> logging.LogRecord: | ||
| record = current_factory(*args, **kwargs) | ||
| if record.args and isinstance(record.msg, str): |
There was a problem hiding this comment.
When a multiprocessing-backed QueueHandler processes a parameterized record containing a non-pickleable argument, such as a lambda, lock, or open file, this attribute retains the original object after QueueHandler.prepare() renders the message and clears record.args. The queue feeder then cannot pickle the prepared record, so the log is dropped even though standard queued logging supports such arguments after rendering; preserve the metadata without attaching arbitrary raw objects to the queued LogRecord.
Useful? React with 👍 / 👎.
| _IGNORED_LOGGER_PREFIXES = ("braintrust",) | ||
| _URLLIB3_TRANSPORT_LOGGERS = ("urllib3.connectionpool", "urllib3.connection") | ||
| _INTERNAL_HTTP_TRANSPORT_RECORD_ATTRIBUTE = "_braintrust_internal_http_transport" | ||
| _LOG_RECORD_FACTORY_ATTRIBUTE = "_braintrust_log_record_factory" |
There was a problem hiding this comment.
When a Braintrust upload is retried with urllib3 debug logging enabled, urllib3 emits its retry message from urllib3.util.retry, which is not one of these two source loggers and therefore never receives the transport marker. A root BraintrustLogHandler consequently re-ingests that internal record; repeated upload failures can continually generate additional rows, and a shutdown flush waiting on the HTTP worker can deadlock when that worker tries to acquire the handler lock. Apply the guarded marker to all urllib3 transport records rather than only these two module loggers.
Useful? React with 👍 / 👎.
Replace the inherited logging-hooks lock in forked children so the process-global LogRecord factory cannot deadlock when another parent thread held the original lock. Cover the failure with a bounded POSIX fork regression that verifies the child can create a record.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: ab5d9a1226
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "Codex (@codex) review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "Codex (@codex) address that feedback".
| def _safe_template_parameter(value: Any) -> Any: | ||
| if isinstance(value, (str, float, int, bool)): | ||
| return value | ||
| return _safe_parameter_repr(value) |
There was a problem hiding this comment.
When a normal logging call passes a structured or null argument, such as logger.info("items=%s", [1, 2]) or logger.info("value=%s", None), the installed record factory always snapshots it through this function, so the retained template parameter becomes the string "[1, 2]" or "None" even without a queue. This loses the raw JSON type and prevents users from filtering or inspecting structured parameters; preserve values that are already safely serializable/pickleable and fall back to repr only for unsafe objects.
Useful? React with 👍 / 👎.
2 participants
resolves https://linear.app/braintrustdata/issue/SDK-341/add-logging-api-to-python-sdk
ref https://app.notion.com/p/braintrustdata/Braintrust-Logs-Schema-and-SDK-API-3def7858028980e29a83cddb3f81203b
schema https://github.com/braintrustdata/braintrust/pull/20692
AI Summary
Add first-class log emission to the project logger so applications can create independent
type="log"rows without constructing spans manually.Logger.emit_log(body, level, metadata).trace(),debug(),info(),warn(),error(), andfatal()convenience methods.span_attributes["log_level"].SpanTypeAttribute.LOG.Usage
Emit directly or use a severity helper:
Log methods also accept named
str.formatparameters:On Python 3.14+, log methods also accept t-strings. Their interpolation values are already embedded, so no separate keyword parameters are needed:
Both forms store the rendered message in
output:They also retain the stable template and its raw parameters for querying and grouping. Canonical severity follows the updated logs schema and lives in
span_attributes, separate from user metadata:{ "output": "User user_123 paid 12.50", "span_attributes": { "type": "log", "log_level": "info", }, "metadata": { "source": "checkout", "braintrust.template": "User {user_id} paid {amount:.2f}", "braintrust.template.parameter.user_id": "user_123", "braintrust.template.parameter.amount": 12.5, }, }Missing
str.formatparameters remain as placeholders, and malformed templates fall back to the original body so formatting errors do not disrupt application code. T-string conversions and format specifications follow f-string rendering semantics; unsupported formatting leaves the affected placeholder intact. Bodies may remain non-string JSON values when no template parameters are supplied.T-string support is loaded only on Python 3.14+, preserving SDK compatibility with Python 3.10 through 3.13.
Trace correlation
Each log has a unique row ID and span ID unless it is correlated with an active span. A logger seeds one baseline trace ID when it is created, so consecutive unscoped logs from that logger remain grouped without grouping logs from separate logger instances.
This works with both native Braintrust spans and active OpenTelemetry spans through the existing context manager abstraction.
Python logging handler
The opt-in
BraintrustLogHandlerforwards standard-libraryloggingrecords without enabling automatic instrumentation:The handler preserves formatted messages, original timestamps, exceptions, template parameters,
extrafields, logger/source metadata, active span correlation, and normalized severity inspan_attributes.log_level. Logs from Braintrust and itsurllib3transport are excluded to prevent recursive forwarding.