Packet timestamp for 2.1.13 release#4
Conversation
Under OpenSSL 3.0+, unexpected socket closures before a clean SSL/TLS shutdown alert is exchanged are classified as protocol errors rather than clean EOFs, causing regression tests to fail. - https_bev: enable allow_dirty_shutdown on server bufferevents to handle abrupt client socket closures cleanly - http_incomplete_errorcb: accept BEV_EVENT_ERROR with an OpenSSL error as a successful termination (OpenSSL 3.0 treats raw socket shutdowns as TLS protocol errors)
Implement kernel-measured socket receive timestamps with nanosecond precision on supported platforms via the recvmsg() syscall. Each recvmsg() call writes into a freshly allocated evbuffer chain so that every call gets an independent timestamp; timestamps are never silently discarded due to chain reuse. Infrastructure changes: - evbuffer-internal.h: Add timestamp storage and validity flag to evbuffer_chain structure. - evbuffer_read_with_timestamp(): New internal function for reading data via recvmsg(), parsing control messages for timestamps, and safeguarding against MSG_CTRUNC truncation. Always allocates a fresh chain per call so per-call timestamps are preserved independently. - bufferevent-internal.h: Add recv_timestamps_enabled flag to the bufferevent_private structure. - bufferevent_sock.c: Enable receive timestamps and swap standard reads with evbuffer_read_with_timestamp() when requested. - bufferevent_openssl.c: Add a custom socket BIO to extract kernel timestamps during direct socket reads, and propagate timestamps from underlying bufferevents in filtered TLS mode. - Build system: Add CMake and Autotools socket timestamp checks for SO_TIMESTAMP and SO_TIMESTAMPNS option availability. Public API additions: - BEV_OPT_RECV_TIMESTAMPS option flag for socket bufferevents. - evbuffer_get_timestamp() to fetch the receipt timestamp of the oldest data currently in the buffer. - evbuffer_commit_space_with_timespec() to commit reserved space and manually attach a timestamp to the committed chains. Conflict resolution: preserved the upstream UBSAN fix (if (chain->buffer) guard in evbuffer_pullup) while adding timestamp propagation alongside it.
| if (use_recvmsg) { | ||
| /* Allocate a fresh chain for each recvmsg() call so that | ||
| * every call gets its own chain with an independent timestamp. */ | ||
| struct evbuffer_chain *old_last = buf->last; |
There was a problem hiding this comment.
Use-after-free in evbuffer_read_impl_ recvmsg path (buffer.c:2402-2409)
old_last is captured before evbuffer_chain_insert(), but the insert calls evbuffer_free_trailing_empty_chains() (buffer.c:320), which frees any trailing chain with off == 0 — potentially including buf->last itself (the helper's comment at buffer.c:287 warns of exactly this). chainp = &old_last->next then points into freed memory, and the accounting loop at buffer.c:2549-2567 reads and writes through it.
The triggering state — an empty unpinned chain at buf->last — is created by this function itself: on n <= 0 (EAGAIN/EINTR/EOF) it exits via done (buffer.c:2535-2542), leaving the freshly inserted, still-empty chain in the buffer.
Reproduction (ordinary nonblocking read loop, two calls on the same buffer):
Call 1 — EAGAIN:
- buffer.c:2403 — chain A allocated (off == 0).
- buffer.c:2408 — A inserted; it is now buf->last.
- buffer.c:2473 — recvmsg() returns -1 (EAGAIN).
- buffer.c:2535 — early exit via done; A remains in the buffer, still empty.
Call 2 — data available:
- buffer.c:2402 — old_last = buf->last, i.e. A.
- buffer.c:2403 — chain B allocated.
- buffer.c:2408 — evbuffer_chain_insert(buf, B) → buffer.c:320 → evbuffer_free_trailing_empty_chains() frees A (empty, unpinned) and links B in its place.
- buffer.c:2409 — chainp = &old_last->next = &A->next → dangling pointer into freed memory.
- buffer.c:2473 — recvmsg() succeeds, n > 0, data written into B (the iovec set at 2411-2412 is correct).
- buffer.c:2549 — CHAIN_SPACE_LEN(*chainp) reads A->next from freed memory → garbage pointer, then reads fields through it.
- buffer.c:2555 or 2562-2566 — off and timestamp written through the garbage pointer.
- buffer.c:2567 — buf->last_with_datap = chainp stores the dangling pointer into the evbuffer, so later inserts walk freed memory too.
- Even without a crash, the read is misaccounted: the bytes landed in B but B->off is never updated, while buf->total_len += n (buffer.c:2576).
Since evbuffer_read_with_timestamp() is exported public API, EAGAIN-then-success is normal usage, not an edge case. The same state is also reachable via evbuffer_reserve_space() without commit, or evbuffer_expand(), before a read.
Suggested fix: (1) compute chainp after the insert instead of via old_last, e.g. chainp = (*buf->last_with_datap) ? &(*buf->last_with_datap)->next : buf->last_with_datap; (the new chain has off == 0, so the insert cannot move last_with_datap); (2) on n <= 0, remove and free the just-inserted empty chain before returning. A regression test doing EAGAIN-then-success under ASan would catch this.
| { | ||
| #if !defined(_WIN32) && !defined(__APPLE__) | ||
| if (use_recvmsg) { | ||
| int r = (int)recv(fd, NULL, 0, MSG_PEEK | MSG_TRUNC); |
| n = get_n_bytes_readable_on_socket(fd); | ||
| if (n <= 0 || n > EVBUFFER_MAX_READ) | ||
| n = get_n_bytes_readable_on_socket(fd, use_recvmsg); | ||
| if (n <= 0 || (n > EVBUFFER_MAX_READ && !use_recvmsg)) |
There was a problem hiding this comment.
More about the watermark being exceeded than rate limits
BEV_OPT_RECV_TIMESTAMPS silently overrides the caller's howmuch limit, breaking read watermarks and rate limits (buffer.c:2387-2391)
In evbuffer_read_impl_:
- buffer.c:2384 — n = get_n_bytes_readable_on_socket(fd, use_recvmsg).
- buffer.c:2385 — for the recvmsg path, n is deliberately not clamped to EVBUFFER_MAX_READ (the && !use_recvmsg condition).
- buffer.c:2388-2390 — if (use_recvmsg && n > howmuch) howmuch = n; — the caller's requested limit is raised to whatever the socket probe reported.
But the caller has already encoded two contracts into howmuch:
- bufferevent_sock.c:212-218 — the read high watermark: howmuch = bufev->wm_read.high - evbuffer_get_length(input) so the input buffer never exceeds wm_read.high.
- bufferevent_sock.c:220-223 — the rate limit: howmuch is clamped to bufferevent_get_read_max_().
The override discards both. Consequences:
- The input buffer can grow past wm_read.high — on Linux/TCP by up to EVBUFFER_MAX_READ (4096) per call, since the MSG_PEEK|MSG_TRUNC probe returns 0 for stream sockets and the code falls back to EVBUFFER_MAX_READ (buffer.c:2311-2315, 2385-2386). Watermark-based flow control sees more buffered data than it ever asked to read.
- bufferevent_decrement_read_buckets_(bufev_p, res) (bufferevent_sock.c:257) is charged the full over-read, so rate-limit buckets go further negative than intended — reads burst past the configured limit and then stall longer.
- On datagram sockets the probe does return the pending datagram size, so howmuch (and the fresh chain allocated from it at buffer.c:2403) is unbounded by EVBUFFER_MAX_READ entirely.
The header comment on BEV_OPT_RECV_TIMESTAMPS (include/event2/bufferevent.h) documents the rate-limit bypass, but not the watermark overshoot — and the "full message is fetched … exact datagram size" rationale only holds for datagram sockets, which socket bufferevents aren't.
Suggested fix: honor the caller's howmuch (drop the override at buffer.c:2388-2390). A timestamp is still captured per recvmsg() call regardless of how much is read, so nothing is lost; the remaining data is picked up on the next readable event with its own fresh chain and timestamp. If the override is intentional for the datagram case, gate it on socket type or at minimum extend the BEV_OPT_RECV_TIMESTAMPS docs to state that read high watermarks may be exceeded.
Note that this would cause truncation of data over UDP (but that is no different from the "old" code as it also suffers from that)
Added support for packet timestamp