Skip to content
Merged
Show file tree
Hide file tree
Changes from 2 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
1 change: 1 addition & 0 deletions include/proxy/hdrs/HTTP.h
Original file line number Diff line number Diff line change
Expand Up @@ -162,6 +162,7 @@ enum class SquidLogCode {
ERR_FUTURE_1 = 'I',
ERR_CLIENT_READ_ERROR = 'J', // Client side abort logging
ERR_LOOP_DETECTED = 'K', // Loop or cycle detected, request came back to this server
ERR_TUN_ACTIVE_TIMEOUT = 'T', // Tunnel (CONNECT) active timeout
ERR_UNKNOWN = 'Z'
};

Expand Down
8 changes: 8 additions & 0 deletions src/proxy/http/HttpSM.cc
Original file line number Diff line number Diff line change
Expand Up @@ -4064,6 +4064,10 @@ HttpSM::tunnel_handler_ssl_producer(int event, HttpTunnelProducer *p)
case VC_EVENT_ERROR:
case VC_EVENT_INACTIVITY_TIMEOUT:
case VC_EVENT_ACTIVE_TIMEOUT:
// Set squid code for tunnel active timeout
if (event == VC_EVENT_ACTIVE_TIMEOUT) {
t_state.squid_codes.log_code = SquidLogCode::ERR_TUN_ACTIVE_TIMEOUT;
}
// The other side of the connection is either already dead
// or rendered inoperative by the error on the connection
// Note: use tunnel close vc so the tunnel knows we are
Expand Down Expand Up @@ -4118,6 +4122,10 @@ HttpSM::tunnel_handler_ssl_consumer(int event, HttpTunnelConsumer *c)
case VC_EVENT_EOS:
case VC_EVENT_INACTIVITY_TIMEOUT:
case VC_EVENT_ACTIVE_TIMEOUT:
// Set squid code for tunnel active timeout
if (event == VC_EVENT_ACTIVE_TIMEOUT) {
t_state.squid_codes.log_code = SquidLogCode::ERR_TUN_ACTIVE_TIMEOUT;
}
// we need to mark the producer dead
// otherwise it can stay alive forever.
if (c->producer->alive) {
Expand Down
5 changes: 3 additions & 2 deletions src/proxy/logging/Log.cc
Original file line number Diff line number Diff line change
Expand Up @@ -655,7 +655,7 @@ Log::init_fields()

Ptr<LogFieldAliasTable> cache_code_map = make_ptr(new LogFieldAliasTable);
cache_code_map->init(
53, SquidLogCode::EMPTY, "UNDEFINED", SquidLogCode::TCP_HIT, "TCP_HIT", SquidLogCode::TCP_DISK_HIT, "TCP_DISK_HIT",
54, SquidLogCode::EMPTY, "UNDEFINED", SquidLogCode::TCP_HIT, "TCP_HIT", SquidLogCode::TCP_DISK_HIT, "TCP_DISK_HIT",
SquidLogCode::TCP_MEM_HIT, "TCP_MEM_HIT", SquidLogCode::TCP_MISS, "TCP_MISS", SquidLogCode::TCP_EXPIRED_MISS,
"TCP_EXPIRED_MISS", SquidLogCode::TCP_REFRESH_HIT, "TCP_REFRESH_HIT", SquidLogCode::TCP_REF_FAIL_HIT, "TCP_REFRESH_FAIL_HIT",
SquidLogCode::TCP_REFRESH_MISS, "TCP_REFRESH_MISS", SquidLogCode::TCP_CLIENT_REFRESH, "TCP_CLIENT_REFRESH_MISS",
Expand All @@ -676,7 +676,8 @@ Log::init_fields()
SquidLogCode::ERR_NO_RELAY, "ERR_NO_RELAY", SquidLogCode::ERR_DISK_IO, "ERR_DISK_IO", SquidLogCode::ERR_ZERO_SIZE_OBJECT,
"ERR_ZERO_SIZE_OBJECT", SquidLogCode::ERR_PROXY_DENIED, "ERR_PROXY_DENIED", SquidLogCode::ERR_WEBFETCH_DETECTED,
"ERR_WEBFETCH_DETECTED", SquidLogCode::ERR_FUTURE_1, "ERR_FUTURE_1", SquidLogCode::ERR_LOOP_DETECTED, "ERR_LOOP_DETECTED",
SquidLogCode::ERR_UNKNOWN, "ERR_UNKNOWN", SquidLogCode::TCP_CF_HIT, "TCP_CF_HIT");
SquidLogCode::ERR_TUN_ACTIVE_TIMEOUT, "ERR_TUN_ACTIVE_TIMEOUT", SquidLogCode::ERR_UNKNOWN, "ERR_UNKNOWN",
SquidLogCode::TCP_CF_HIT, "TCP_CF_HIT");

Ptr<LogFieldAliasTable> cache_subcode_map = make_ptr(new LogFieldAliasTable);
cache_subcode_map->init(2, SquidSubcode::EMPTY, "NONE", SquidSubcode::NUM_REDIRECTIONS_EXCEEDED, "NUM_REDIRECTIONS_EXCEEDED");
Expand Down
93 changes: 93 additions & 0 deletions tests/gold_tests/timeout/tunnel_active_timeout.test.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,93 @@
'''
Verify that tunnel active timeout produces ERR_TUN_ACTIVE_TIMEOUT squid code.
'''
# 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 os
import sys

Test.Summary = '''
Verify that tunnel active timeout produces ERR_TUN_ACTIVE_TIMEOUT squid code.
'''

ts = Test.MakeATSProcess("ts", enable_tls=True)
server = Test.MakeOriginServer("server", ssl=True)

# Simple response from origin
request_header = {"headers": "GET / HTTP/1.1\r\nHost: server\r\n\r\n", "timestamp": "1234", "body": ""}
response_header = {"headers": "HTTP/1.1 200 OK\r\nConnection: close\r\n\r\n", "timestamp": "1234", "body": "hello"}
server.addResponse("sessionlog.json", request_header, response_header)

ts.addDefaultSSLFiles()

ts.Disk.ssl_multicert_config.AddLine('dest_ip=* ssl_cert_name=server.pem ssl_key_name=server.key')

ts.Disk.records_config.update(
{
'proxy.config.diags.debug.enabled': 1,
'proxy.config.diags.debug.tags': 'http|ssl|tunnel',
'proxy.config.ssl.server.cert.path': ts.Variables.SSLDir,
'proxy.config.ssl.server.private_key.path': ts.Variables.SSLDir,
'proxy.config.ssl.client.verify.server.policy': 'PERMISSIVE',
'proxy.config.http.connect_ports': f'{server.Variables.SSL_Port}',
# Set a short active timeout for tunnels (2 seconds)
'proxy.config.http.transaction_active_timeout_in': 2,
# Force log flush every second for test reliability
'proxy.config.log.max_secs_per_buffer': 1,
})

ts.Disk.remap_config.AddLine(f'map / https://127.0.0.1:{server.Variables.SSL_Port}')

# Configure custom log format to capture squid code
ts.Disk.logging_yaml.AddLines(
'''
logging:
formats:
- name: custom
format: '%<crc> %<pssc> %<cqhm>'
logs:
- filename: squid.log
format: custom
'''.split("\n"))

# Test: Perform a CONNECT request that will time out
tr = Test.AddTestRun("Tunnel active timeout test")
tr.Processes.Default.StartBefore(server)
tr.Processes.Default.StartBefore(ts)

# Use the tunnel_timeout_client.py script to establish a CONNECT tunnel and then
# just hold the connection until ATS times it out
tr.Setup.Copy('tunnel_timeout_client.py')

# Connect, establish tunnel, then sleep to trigger active timeout
tr.Processes.Default.Command = (
f'{sys.executable} tunnel_timeout_client.py 127.0.0.1 {ts.Variables.port} '
f'127.0.0.1 {server.Variables.SSL_Port} 5')
# The connection will be closed by ATS due to timeout
tr.Processes.Default.ReturnCode = 0
tr.StillRunningAfter = ts

# Wait for the access log to be written
tr = Test.AddTestRun("Wait for the access log to write out")
tr.DelayStart = 3
tr.StillRunningAfter = ts
tr.Processes.Default.Command = 'echo "waiting for log flush"'
tr.Processes.Default.ReturnCode = 0

# Verify the squid code in the access log
ts.Disk.File(os.path.join(ts.Variables.LOGDIR, 'squid.log')).Content = Testers.ContainsExpression(
'ERR_TUN_ACTIVE_TIMEOUT.*CONNECT', 'Verify the tunnel timeout squid code is logged')
95 changes: 95 additions & 0 deletions tests/gold_tests/timeout/tunnel_timeout_client.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,95 @@
#!/usr/bin/env python3
'''
A simple client that establishes a CONNECT tunnel and then holds the connection
idle to trigger an active timeout.
'''
# 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():
if len(sys.argv) < 6:
print(f"Usage: {sys.argv[0]} proxy_host proxy_port target_host target_port sleep_seconds")
sys.exit(1)

proxy_host = sys.argv[1]
proxy_port = int(sys.argv[2])
target_host = sys.argv[3]
target_port = int(sys.argv[4])
sleep_seconds = int(sys.argv[5])

# Connect to the proxy
sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
sock.settimeout(10)

try:
sock.connect((proxy_host, proxy_port))
print(f"Connected to proxy {proxy_host}:{proxy_port}")

# Send CONNECT request
connect_request = f"CONNECT {target_host}:{target_port} HTTP/1.1\r\nHost: {target_host}:{target_port}\r\n\r\n"
sock.sendall(connect_request.encode())
print(f"Sent CONNECT request for {target_host}:{target_port}")

# Read the response
response = b""
while b"\r\n\r\n" not in response:
data = sock.recv(1024)
if not data:
break
response += data

response_str = response.decode()
print(f"Received response: {response_str.strip()}")

if "200" not in response_str:
print(f"CONNECT failed: {response_str}")
sock.close()
sys.exit(1)

print(f"Tunnel established, sleeping for {sleep_seconds} seconds to trigger active timeout...")

# Now hold the connection idle until the active timeout fires
# Use a longer socket timeout so we can detect when ATS closes the connection
sock.settimeout(sleep_seconds + 5)

try:
# Wait for data or connection close
data = sock.recv(1024)
if not data:
print("Connection closed by server (timeout)")
else:
print(f"Received data: {data}")
except socket.timeout:
print("Socket timeout waiting for server")
except Exception as e:
print(f"Exception: {e}")

except socket.timeout:
print("Socket timeout during connect/handshake")
except Exception as e:
print(f"Error: {e}")
finally:
sock.close()

Comment thread
bryancall marked this conversation as resolved.
Outdated
print("Done")


if __name__ == "__main__":
main()
Loading