Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 10 additions & 0 deletions src/proxy/http/HttpSM.cc
Original file line number Diff line number Diff line change
Expand Up @@ -2145,6 +2145,16 @@ HttpSM::state_read_server_response_header(int event, void *data)
// If there is a post body in transit, give up on it
if (tunnel.is_tunnel_alive()) {
tunnel.abort_tunnel();
// abort_tunnel() cancels I/O but does not close VCs or clean up
// vc_table entries. When a request transform is active the
// post_transform_info entry still references the TransformVConnection
// with in_tunnel=true, which causes cleanup_entry() to skip
// do_io_close() — leaking the VC. Close it explicitly here.
if (post_transform_info.entry != nullptr) {
post_transform_info.vc->do_io_close();

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

This is the shape I was hoping for — the comment now describes the actual defect, and the close is explicit rather than a side effect of clearing in_tunnel.

One nit: the guard tests post_transform_info.entry, but this line dereferences post_transform_info.vc. The invariant does hold today — do_post_transform_open() only creates the entry when vc is non-null and sets entry->vc = vc, and state_common_wait_for_transform_read() nulls both together — but post_transform_info.entry->vc->do_io_close() is the more direct expression, and it's the very pointer cleanup_entry() asserts on (ink_assert(e->vc)) one line later. Either that, or guard on .vc the way the other sites in this file do.

For the record on the other direction: TransformVConnection::do_io_close() early-returns on m_closed != 0, so a double close here is harmless.

vc_table.cleanup_entry(post_transform_info.entry);
Comment thread
sxia-aviatrix marked this conversation as resolved.
post_transform_info.entry = nullptr;
Comment thread
sxia-aviatrix marked this conversation as resolved.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Still open from the last round — flagging once rather than re-explaining. This leaves post_transform_info.vc non-null with entry == nullptr, and tunnel_handler_post_or_put() checks only .vc before dereferencing .entry.

Leaving .vc set is deliberate and correct (it's what makes transform_cleanup() skip the chain), so the only question is whether tunnel_handler_post_or_put() is reachable after this abort. If you've satisfied yourself that it isn't, a one-line comment saying so would save the next reader the trip.

}
// Make sure client connection is closed when we are done in case there is cruft left over
t_state.client_info.keep_alive = HTTPKeepAlive::NO_KEEPALIVE;
// Similarly the server connection should also be closed
Expand Down
77 changes: 77 additions & 0 deletions tests/gold_tests/slow_post/partial_post_client.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,77 @@
#!/usr/bin/env python3
"""Send a partial POST to trigger the abort_tunnel code path.

Sends POST headers claiming a large Content-Length but only sends a small
chunk of body data. When a request transform plugin is active, this causes
ATS to call abort_tunnel() while the transform entry is still in the vc_table.
"""

# Licensed to the Apache Software Foundation (ASF) under one
# or more contributor license agreements. See the NOTICE file
# distributed with this work for additional information
# regarding copyright ownership. The ASF licenses this file
# to you under the Apache License, Version 2.0 (the
# "License"); you may not use this file except in compliance
# with the License. You may obtain a copy of the License at
#
# http://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.

import socket
import sys


def main() -> int:
"""Run the client."""
host = sys.argv[1] if len(sys.argv) > 1 else '127.0.0.1'
port = int(sys.argv[2]) if len(sys.argv) > 2 else 8080

request = (
'POST / HTTP/1.1\r\n'
'Host: quick.server.com\r\n'
'Content-Type: application/octet-stream\r\n'
'Content-Length: 100000\r\n'
Comment thread
sxia-aviatrix marked this conversation as resolved.
'\r\n').encode()

partial_body = b'x' * 4096

sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
sock.settimeout(5)
try:
sock.connect((host, port))
sock.sendall(request + partial_body)
print(f'Sent POST headers (Content-Length: 100000) + {len(partial_body)} bytes')

try:
response = sock.recv(4096)
except ConnectionError:
# ATS may reset the connection after responding since the POST
# body is incomplete. This is acceptable — the important thing
# is that ATS did not crash.
print('HTTP/1.1 connection reset (expected for partial POST)')
Comment thread
sxia-aviatrix marked this conversation as resolved.
return 0
Comment on lines +52 to +57

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Same point as on the test, from this side: 'HTTP/1.1 connection reset ...' is doing double duty as a human-readable log line and as the token that ContainsExpression('HTTP/1.1') matches over in quick_server.test.py. If a reset really is an acceptable outcome, print something that can't be mistaken for a status line (CONNECTION RESET) and give the test a tester for that string specifically.

Also worth checking: except ConnectionError won't catch a clean FIN — that surfaces as recv() returning b'', which falls through to the return 1 branch below. Since ATS sets NO_KEEPALIVE on this path, a clean close after the response is the more likely outcome, so make sure the branch you expect to hit is the one you're actually asserting on.

except socket.timeout:
print('ERROR: timeout waiting for response', file=sys.stderr)
return 1

if response:
first_line = response.split(b'\r\n')[0].decode(errors='replace')
print(first_line)
if first_line.startswith('HTTP/1.1'):
return 0
print('ERROR: unexpected response', file=sys.stderr)
return 1
else:
print('ERROR: connection closed with no response', file=sys.stderr)
return 1
finally:
sock.close()


if __name__ == '__main__':
sys.exit(main())
57 changes: 40 additions & 17 deletions tests/gold_tests/slow_post/quick_server.test.py
Original file line number Diff line number Diff line change
@@ -1,4 +1,8 @@
"""Verify ATS handles a server that replies before receiving a full request."""
"""Verify ATS handles a server that replies before receiving a full request.

Also verifies ATS does not leak the TransformVConnection when abort_tunnel()
is called with a request transform plugin active (use_request_transform=True).
"""

# Licensed to the Apache Software Foundation (ASF) under one
# or more contributor license agreements. See the NOTICE file
Expand Down Expand Up @@ -27,24 +31,27 @@ class QuickServerTest:
"""Verify that ATS doesn't delay responses behind slow posts."""

_init_file = '__init__.py'
_http_utils = 'http_utils.py'
_slow_post_client = 'slow_post_client.py'
_partial_post_client = 'partial_post_client.py'
_quick_server = 'quick_server.py'

_dns_counter = 0
_server_counter = 0
_ts_counter = 0

def __init__(self, abort_request: bool, drain_request: bool, abort_response_headers: bool):
def __init__(self, abort_request: bool, drain_request: bool, abort_response_headers: bool, use_request_transform: bool = False):
Comment thread
bneradt marked this conversation as resolved.
"""Initialize the test.

:param drain_request: Whether the server should drain the request body.
:param abort_request: Whether the client should abort the request body.
before disconnecting.
:param abort_response_headers: Whether the server should abort response headers.
:param use_request_transform: Whether to install a request transform plugin
hooked at TS_HTTP_READ_REQUEST_HDR_HOOK and use a partial POST client.
"""
self._should_drain_request = drain_request
self._should_abort_request = abort_request
self._should_abort_response_headers = abort_response_headers
self._use_request_transform = use_request_transform

def _configure_dns(self, tr: 'TestRun') -> None:
"""Configure the DNS.
Expand Down Expand Up @@ -89,13 +96,17 @@ def _configure_traffic_server(self, tr: 'TestRun'):
'proxy.config.dns.nameservers': f'127.0.0.1:{self._dns.Variables.Port}',
'proxy.config.dns.resolv_conf': 'NULL',
})
if self._use_request_transform:
Test.PrepareTestPlugin(
os.path.join(Test.Variables.AtsTestPluginsDir, 'tunnel_transform.so'), self._ts, plugin_args='request_hdr')

def run(self):
"""Run the test."""
tr = Test.AddTestRun(
f'Aborting request: {self._should_abort_request}, '
f'Draining request: {self._should_drain_request}, '
f'Aborting response headers: {self._should_abort_response_headers}')
f'Aborting response headers: {self._should_abort_response_headers}, '
f'Request transform: {self._use_request_transform}')

self._configure_dns(tr)
self._configure_server(tr)
Expand All @@ -105,22 +116,30 @@ def run(self):
http_utils = os.path.join(tools_dir, 'http_utils.py')
tr.Setup.CopyAs(self._init_file, Test.RunDirectory)
tr.Setup.CopyAs(http_utils, Test.RunDirectory)
tr.Setup.CopyAs(self._slow_post_client, Test.RunDirectory)
tr.Setup.CopyAs(self._quick_server, Test.RunDirectory)

client_command = (f'{sys.executable} {self._slow_post_client} '
'127.0.0.1 '
f'{self._ts.Variables.port} ')
if not self._should_abort_request:
client_command += '--finish-request '
p = tr.Processes.Default
p.Command = client_command
if self._should_abort_request or self._should_abort_response_headers:
p.Streams.All += Testers.ExcludesExpression('HTTP/1.1 200 OK', 'Verify response was received')
if self._use_request_transform:
tr.Setup.CopyAs(self._partial_post_client, Test.RunDirectory)
p = tr.Processes.Default
p.Command = (f'{sys.executable} {self._partial_post_client} '
f'127.0.0.1 {self._ts.Variables.port}')
p.ReturnCode = 0
p.Streams.All += Testers.ContainsExpression('HTTP/1.1', 'Verify client received an HTTP response')
Comment thread
sxia-aviatrix marked this conversation as resolved.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

This is the one item I'd hold the PR on.

The client's reset path prints HTTP/1.1 connection reset (expected for partial POST) (partial_post_client.py:56), worded such that it satisfies ContainsExpression('HTTP/1.1'). So the tester labelled "Verify client received an HTTP response" passes when no response was received at all — and p.ReturnCode = 0 passes too, because that path returns 0. Someone scanning this file sees a real check where there isn't one.

Please pin down what ATS is actually expected to do here. The origin sends a complete HTTP/1.1 200 OK / Content-Length: 0 before the body finishes, and state_read_server_response_header() sets NO_KEEPALIVE on both sides after the abort — so I'd expect the 200 to be forwarded and then the connection closed, i.e. Testers.ContainsExpression('HTTP/1.1 200 OK', ...) deterministically, matching the other runs in this file.

If it genuinely races between "200 then FIN" and "RST", then say so explicitly: print something that isn't shaped like a status line, assert on it separately, and comment the race. As written, the message and the assertion are engineered to agree with each other regardless of what ATS did.

else:
p.Streams.All += Testers.ContainsExpression('HTTP/1.1 200 OK', 'Verify response was received')
tr.Setup.CopyAs(self._slow_post_client, Test.RunDirectory)
client_command = (f'{sys.executable} {self._slow_post_client} '
'127.0.0.1 '
f'{self._ts.Variables.port} ')
if not self._should_abort_request:
client_command += '--finish-request '
p = tr.Processes.Default
p.Command = client_command
if self._should_abort_request or self._should_abort_response_headers:
p.Streams.All += Testers.ExcludesExpression('HTTP/1.1 200 OK', 'Verify response was received')
else:
p.Streams.All += Testers.ContainsExpression('HTTP/1.1 200 OK', 'Verify response was received')
p.ReturnCode = 0

p.ReturnCode = 0
self._ts.StartBefore(self._dns)
self._ts.StartBefore(self._server)
p.StartBefore(self._ts)
Expand All @@ -132,3 +151,7 @@ def run(self):
for abort_response_headers in [True, False]:
test = QuickServerTest(abort_request, drain_request, abort_response_headers)
test.run()

# Partial POST with a request transform plugin: exercises the abort_tunnel()
# cleanup path for TransformVConnection entries in the vc_table.
QuickServerTest(abort_request=True, drain_request=False, abort_response_headers=False, use_request_transform=True).run()

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Two things on this line.

abort_request=True is inert for the transform run — nothing reads _should_abort_request in the use_request_transform branch — yet the generated run name will still print "Aborting request: True". Pass False, or leave the flags that don't apply out of the name.

More important: now that the root cause is correctly identified as a leaked TransformVConnection rather than a use-after-free, this run can't catch a regression on its own — a leak doesn't fail an autest. It only has teeth under ASAN/LSAN. Worth saying that in the comment above, and worth confirming the ASAN autest job actually runs slow_post; otherwise this is a "doesn't crash" smoke test and the leak could come back unnoticed.

45 changes: 33 additions & 12 deletions tests/tools/plugins/tunnel_transform.cc
Original file line number Diff line number Diff line change
@@ -1,6 +1,12 @@
/** @file

An example program that does a null transform of response body content.
Null transform plugin for request and/or response body content.

Modes (selected by plugin argument):
(default) — hook at TS_HTTP_TUNNEL_START_HOOK, add both request
and response transforms (original behavior)
request_hdr — hook at TS_HTTP_READ_REQUEST_HDR_HOOK, add only the
request transform

@section license License

Expand All @@ -21,6 +27,7 @@
limitations under the License.
*/

#include <cstring>
#include <stdio.h>
#include <unistd.h>
#include <inttypes.h>
Expand All @@ -31,10 +38,11 @@
static const char PLUGIN_TAG[] = PLUGIN_NAME;
static DbgCtl plugin_ctl{PLUGIN_TAG};

static int stat_ua_bytes_sent = 0; // number of bytes seen by the transform from UA to OS
static int stat_os_bytes_sent = 0; // number of bytes seen by the transform from OS to UA
static int stat_error = 0;
static int stat_test_done = 0;
static int stat_ua_bytes_sent = 0; // number of bytes seen by the transform from UA to OS
static int stat_os_bytes_sent = 0; // number of bytes seen by the transform from OS to UA
static int stat_error = 0;
static int stat_test_done = 0;
static bool request_hdr_mode = false; // when true, hook at READ_REQUEST_HDR and request transform only

typedef struct {
TSVIO output_vio;
Expand Down Expand Up @@ -99,7 +107,8 @@ handle_transform(TSCont contp, bool forward)
data->output_buffer = TSIOBufferCreate();
data->output_reader = TSIOBufferReaderAlloc(data->output_buffer);
Dbg(plugin_ctl, "\tWriting %" PRId64 " bytes on VConn", TSVIONBytesGet(input_vio));
data->output_vio = TSVConnWrite(output_conn, contp, data->output_reader, INT64_MAX);
int64_t nbytes = (request_hdr_mode && TSVIONBytesGet(input_vio) > 0) ? TSVIONBytesGet(input_vio) : INT64_MAX;
Comment thread
sxia-aviatrix marked this conversation as resolved.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

This is load-bearing and needs a comment, because it reads like an incidental tweak and someone will eventually "simplify" it back.

TSVConnWrite()'s nbytes becomes the terminus write VIO's nbytes, which is what TransformTerminus::handle_event() hands the SM as the TRANSFORM_READ_READY payload. state_request_wait_for_transform_read() then does:

size = *(static_cast<int64_t *>(data));
if (size != INT64_MAX && size >= 0) {
  t_state.hdr_info.transform_request_cl = size;
  ...
} else {
  // No content length from the post.  This is a no go
  event = VC_EVENT_ERROR;
  Log::error("Request transformation failed to set content length");
}

So with the original INT64_MAX, the request-transform path fails the transaction before the post tunnel is ever set up, and the new test run would never reach abort_tunnel() at all. Something like "a request transform must report a real content length — INT64_MAX makes state_request_wait_for_transform_read() fail the transaction" would make that clear.

Good that the default mode still passes INT64_MAX: tests/gold_tests/tunnel/tunnel_transform.test.py loads this plugin with no arguments, so that path is unchanged.

data->output_vio = TSVConnWrite(output_conn, contp, data->output_reader, nbytes);
TSContDataSet(contp, data);
}

Expand Down Expand Up @@ -267,10 +276,12 @@ static void
transform_add(TSHttpTxn txnp)
{
Dbg(plugin_ctl, "Entering transform_add()");
TSVConn connp = TSTransformCreate(forward_null_transform, txnp);
TSVConn rev_connp = TSTransformCreate(reverse_null_transform, txnp);
TSVConn connp = TSTransformCreate(forward_null_transform, txnp);
TSHttpTxnHookAdd(txnp, TS_HTTP_REQUEST_TRANSFORM_HOOK, connp);
TSHttpTxnHookAdd(txnp, TS_HTTP_RESPONSE_TRANSFORM_HOOK, rev_connp);
if (!request_hdr_mode) {
TSVConn rev_connp = TSTransformCreate(reverse_null_transform, txnp);
TSHttpTxnHookAdd(txnp, TS_HTTP_RESPONSE_TRANSFORM_HOOK, rev_connp);
}
}

static int
Expand All @@ -280,8 +291,9 @@ transform_plugin(TSCont /* contp ATS_UNUSED */, TSEvent event, void *edata)

Dbg(plugin_ctl, "Entering transform_plugin()");
switch (event) {
case TS_EVENT_HTTP_READ_REQUEST_HDR:
case TS_EVENT_HTTP_TUNNEL_START:
Dbg(plugin_ctl, "\tEvent is TS_EVENT_HTTP_TUNNEL_START");
Dbg(plugin_ctl, "\tEvent is %d", event);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Minor: this drops the readable event name for both cases, and the two modes are now the main thing you'd be using this plugin's debug output to distinguish. Keeping them apart is worth more than sharing the line:

Dbg(plugin_ctl, "\tEvent is %s",
    event == TS_EVENT_HTTP_TUNNEL_START ? "TS_EVENT_HTTP_TUNNEL_START" : "TS_EVENT_HTTP_READ_REQUEST_HDR");

transform_add(txnp);
TSHttpTxnReenable(txnp, TS_EVENT_HTTP_CONTINUE);
return 0;
Expand All @@ -301,7 +313,7 @@ handleMsg(TSCont /* cont ATS_UNUSED */, TSEvent event, void * /* edata ATS_UNUSE
}

void
TSPluginInit(int /* argc ATS_UNUSED */, const char ** /* argv ATS_UNUSED */)
TSPluginInit(int argc, const char **argv)
{
TSPluginRegistrationInfo info;

Expand All @@ -315,14 +327,23 @@ TSPluginInit(int /* argc ATS_UNUSED */, const char ** /* argv ATS_UNUSED */)
goto Lerror;
}

if (argc > 1 && strcmp(argv[1], "request_hdr") == 0) {
request_hdr_mode = true;
}
Dbg(plugin_ctl, "mode: %s", request_hdr_mode ? "request_hdr" : "tunnel_start");

stat_ua_bytes_sent =
TSStatCreate("tunnel_transform.ua.bytes_sent", TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM);
stat_os_bytes_sent =
TSStatCreate("tunnel_transform.os.bytes_sent", TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM);
stat_error = TSStatCreate("tunnel_transform.error", TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM);
stat_test_done = TSStatCreate("tunnel_transform.test.done", TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM);

TSHttpHookAdd(TS_HTTP_TUNNEL_START_HOOK, TSContCreate(transform_plugin, nullptr));
if (request_hdr_mode) {
TSHttpHookAdd(TS_HTTP_READ_REQUEST_HDR_HOOK, TSContCreate(transform_plugin, nullptr));
} else {
TSHttpHookAdd(TS_HTTP_TUNNEL_START_HOOK, TSContCreate(transform_plugin, nullptr));
}
TSLifecycleHookAdd(TS_LIFECYCLE_MSG_HOOK, TSContCreate(handleMsg, TSMutexCreate()));
return;

Expand Down