bneradt opened a new issue, #13605:
URL: https://github.com/apache/trafficserver/issues/13605
## Summary
An origin connection created through `ConnectingEntry` can be omitted from
`ConnectionTracker`. This makes the live per-server connection gauges
undercount real origin connections and can also let
`proxy.config.http.per_server.connection.max` operate on an incomplete count.
The problem is timing-dependent: it occurs when multiple transactions on one
ATS event thread target the same origin while the first origin connection is
still being established.
## Observed failure
The failure was captured by the multi-group portion of
`origin_connection/per_server_connection_max.test.py`. The test configures:
- `proxy.config.http.per_server.connection.metric_enabled: 1`
- `proxy.config.http.per_server.connection.metric_aggregate: 2`
- `proxy.config.http.per_server.connection.match: both`
- a 500 ms raw-stat synchronization interval
- two concurrent requests to `multi.origin.com:<origin-a-port>`
- three concurrent requests to `multi.origin.com:<origin-b-port>`
- six-second origin response delays so every connection overlaps multiple
derived-metric update periods
The expected aggregate was:
```text
proxy.process.http.per_server.total_connection.multi.origin.com 5
proxy.process.http.per_server.current_connection.multi.origin.com 5
proxy.process.http.per_server.current_connection_max.multi.origin.com 3
```
After polling for ten seconds, CI consistently observed:
```text
proxy.process.http.per_server.current_connection.multi.origin.com 4
proxy.process.http.per_server.total_connection.multi.origin.com 5
proxy.process.http.per_server.blocked_connection.multi.origin.com 0
proxy.process.http.per_server.current_connection_max.multi.origin.com 2
```
Increasing the metric wait would not address this instance: the published
gauges remained at 4 and 2 until test teardown.
## Preserved sandbox evidence
The archived httpbin output proves all five requests reached the two origins
and overlapped. The timestamps below are response-completion times and the
reported durations are approximately six seconds:
```text
origin A:
19:04:25.6461 duration_ms=6000.55 GET /delay/6
19:04:25.6573 duration_ms=6000.87 GET /delay/6
origin B:
19:04:25.6483 duration_ms=6001.11 GET /delay/6
19:04:25.6607 duration_ms=6001.82 GET /delay/6
19:04:25.6607 duration_ms=6002.24 GET /delay/6
```
Thus the requests began between approximately 19:04:19.645 and
19:04:19.658. ATS also logged five distinct
`Http1ServerSession::new_connection`
events during that interval.
Two origin-B requests landed on `ET_NET 3`. The relevant trace was:
```text
[19:04:19.656] [ET_NET 3] [SM 2] Check for existing connect request
[19:04:19.656] [ET_NET 3] [SM 2] Queue multiplexed request
[19:04:19.657] [ET_NET 3] [SM 3] Add entry to connection queue. size=2
[19:04:19.657] [ET_NET 3] [SM 3] Queue behind existing request
[19:04:19.657] [ET_NET 3] ConnectingEntry: Kick off 2 state machines waiting
for origin
[19:04:19.657] [ET_NET 3] ConnectingEntry send CONNECT_EVENT_TXN to first 0
[19:04:19.657] [ET_NET 3] [SM 3] Connection handshake complete via
CONNECT_EVENT_TXN
[19:04:19.657] [ET_NET 3] ConnectingEntry Pass along CONNECT_EVENT_DIRECT 1
[19:04:19.657] [ET_NET 3] [SM 2] open connection to
multi.origin.com:<origin-b-port>
```
Five server sessions were created, but only four remained represented by the
connection tracker: two for origin A and two for origin B.
## Code path
`HttpSM::do_http_server_open()` calls `add_to_existing_request()` before it
obtains and reserves `t_state.outbound_conn_track_state`. A transaction that
joins an existing `ConnectingEntry` returns immediately and therefore has no
active tracker reservation.
When the connection completes, `ConnectingEntry::state_http_server_open()`
selects an arbitrary state machine from its `std::set<HttpSM *>` and calls
that
state machine's `create_server_session()`. If it selects the queued state
machine, the new physical server session is created without tracker
ownership,
because `HttpSM::create_server_session()` only transfers tracking when that
state machine's `outbound_conn_track_state` is active.
For HTTP/1, the other state machine is sent through `CONNECT_EVENT_DIRECT`
and
reserves again. This explains why the cumulative total reached 5 while the
instantaneous count was only 4: the cumulative metric received the retry
reservation, while the physical session created from the unreserved queued
state machine remained untracked.
For a multiplexing origin, the same ownership mismatch can affect the single
connection shared by all queued transactions.
## Expected behavior
The reservation made for the physical connection owned by a
`ConnectingEntry` should remain with that entry until the connection either:
1. succeeds and transfers the reservation to the resulting
`PoolableSession`, or
2. fails or is cancelled and releases the reservation.
The state machine selected to receive the completed connection should not
determine whether the physical connection is tracked.
## Reproduction characteristics
The exact Uranium scenario passed in six local attempts (five normal runs and
one run with a single ATS event thread). The CI failure depended on two
requests
being scheduled on the same event thread during the narrow origin-connect
window. The sandbox trace above captures that path directly, so this should
not
be treated as a metric synchronization timeout or fixed by weakening the
expected values.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
