Skip to content

fix: keep whole SIP messages out of WARN logs - #178

Merged
shenjinti merged 1 commit into
restsend:mainfrom
tgeorge06:fix/warn-logs-without-sip-message
Oct 7, 2026
Merged

shenjinti merged 1 commit into
restsend:mainfrom
tgeorge06:fix/warn-logs-without-sip-message

Conversation

@tgeorge06

Copy link
Copy Markdown
Contributor

Fixes #177.

Problem

Some WARN records print a whole SIP message, with the From/To/Contact URIs, display names and the body:

  • DialogInner::send_prack_request and send_dialog_request print the whole request when tx.send() fails (src/dialog/dialog.rs:707, tx.original at line 712; dialog.rs:1153, req = %tx.original at line 1156).
  • WebSocketConnection::serve_loop prints the raw text frame when it does not parse (src/transport/websocket.rs:343).
  • The "bye skipped" WARN of ClientInviteDialog, InviteDialog and ServerInviteDialog (client_dialog.rs:163, invite_dialog.rs:430, server_dialog.rs:357) logs state = ?self.state(), and the returned error formats the state with {:?}. DialogState::Early, WaitAck and Confirmed hold the whole Response (dialog.rs:117-119), and Debug prints it.

WARN usually goes to production logs, and those fields are personal data (phone numbers, user names, SDP addresses).

Fix

  • Send failure: the WARN keeps its fields (id, destination, the error) and adds method; the request is logged right after it at DEBUG ("request that failed to send", with id and req).
  • WebSocket parse failure: the WARN logs len instead of the frame. The frame is already logged at INFO when it is received (websocket.rs:323), so nothing new is needed at DEBUG. This is how the binary-frame branch (websocket.rs:367) and the UDP transport (udp.rs:184, at DEBUG) already behave.
  • Skipped BYE: the WARN and the returned error use the existing Display of DialogState (dialog.rs:1642), which prints the dialog id and the state name (<id>(Early)) and never the embedded message.

Contract / coverage

What each WARN contains now:

  • "failed to send request error: <error>": id (the dialog id: Call-ID, local and remote tag), destination (transport and host:port, when known), method. The Call-ID and tags were already in this WARN and are kept: they are the identifiers an operator needs to find the call, and they carry no URI or display name. The error is the transaction's own Display; the in-tree send errors name an address or a transaction key, never the request (a custom TargetLocator controls the text of its own error).
  • "Error parsing SIP message" (WebSocket text frame): error, src, len. The parser's error can quote the start-line token it rejected (for example invalid method: NOT), as the binary-frame branch and the stream transport already log; not changed here.
  • "bye skipped: ...": dialog_id, state as <id>(<State>).

Full messages are still logged where they were, below WARN: the failed request at DEBUG next to its WARN, received WebSocket text at INFO, sent and received messages in the transports at INFO.

Behaviour change: the error returned by bye_with_headers (and bye) on a dialog that is not confirmed reads dialog <id> cannot send BYE in state <id>(Early) instead of the Debug dump. No caller in the repository matches on it.

Checked and not changed: every other warn! / error! in src/. None prints a message or a type whose Debug embeds one (DialogSnapshotState and TransactionState are plain enums; SendError's Debug omits its payload).

Tests

New src/dialog/tests/test_warn_logs.rs, with a small capturing tracing::Subscriber (the crate has no tracing-subscriber dev-dependency; tracing-subscriber is only enabled by the bench feature). Each test puts a marker in the From display name and URI user part and asserts that the WARN does not contain it:

  • test_failed_request_send_warns_without_the_request: a UAC dialog on an endpoint whose TargetLocator always fails. An INFO through do_request (send_dialog_request) and a PRACK through send_prack_request each give one WARN with method=INFO / method=PRACK and without the marker, and one DEBUG record with it.
  • test_bye_in_early_state_warns_without_the_response: the dialog in Early with a 180 carrying the marker; bye() on ClientInviteDialog, InviteDialog and ServerInviteDialog each fails with an error that reads (Early) and has no marker, and the three WARNs have none.
  • test_websocket_parse_failure_warns_without_the_message (websocket feature): a WebSocket server sends one unparsable text frame to WebSocketConnection::serve_loop. The WARN has len and no marker; the INFO record of the received frame still has it.

On main (5ef8ea6) all three fail:

---- dialog::tests::test_warn_logs::test_failed_request_send_warns_without_the_request stdout ----
panicked at src/dialog/tests/test_warn_logs.rs:118:5:
[" message=failed to send request error: Error: no route id=\"warn-call-a-b\" req=INFO sip:bob@127.0.0.1:5999 SIP/2.0\r\nVia: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bKwarn\r\nCSeq: 2 INFO\r\nFrom: \"private-marker\" <sip:private-marker@example.com>;tag=a\r\n...

---- dialog::tests::test_warn_logs::test_bye_in_early_state_warns_without_the_response stdout ----
panicked at src/dialog/tests/test_warn_logs.rs:151:9:
Error: dialog warn-call-a-b cannot send BYE in state Early(DialogId { call_id: "warn-call", local_tag: "a", remote_tag: "b" }, Response { status_code: Ringing, version: V2, headers: Headers([... From(From("\"private-marker\" <sip:private-marker@example.com>;tag=a")), ...]), body: [] })

---- dialog::tests::test_warn_logs::test_websocket_parse_failure_warns_without_the_message stdout ----
panicked at src/dialog/tests/test_warn_logs.rs:190:5:
[" message=Error parsing SIP message error=rsip error: could not parse part: invalid method: NOT src=WS 127.0.0.1:49711 raw_message=\"NOT SIP <sip:private-marker@example.com>\\r\\n\\r\\n\""]

Checks

Some WARN records carried a whole SIP message, with the From/To/Contact
URIs, display names and any body:

- the dialog layer's "failed to send request" (send_prack_request and
  send_dialog_request) printed the full request;
- the WebSocket transport's "Error parsing SIP message" printed the raw
  text frame;
- the "bye skipped" WARN of ClientInviteDialog, InviteDialog and
  ServerInviteDialog printed the dialog state with Debug, which for
  Early, WaitAck and Confirmed includes the whole response; the returned
  error did the same.

The send failure now logs the method at WARN and the request at DEBUG.
The WebSocket parse failure logs the frame length; the frame is already
logged at INFO when it is received. The BYE paths use the Display of
DialogState (dialog id and state name).
@shenjinti
shenjinti merged commit e3afed3 into restsend:main Oct 7, 2026
3 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.

WARN logs print whole SIP messages (request on send failure, WebSocket parse failure, dialog state on skipped BYE)

2 participants