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
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 on lines +38 to +90
Copy link

Copilot AI Jan 9, 2026

Choose a reason for hiding this comment

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

Instance of context-manager class socket is closed in a finally block. Consider using 'with' statement.

Suggested change
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()
with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as sock:
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}")
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}")

Copilot uses AI. Check for mistakes.
print("Done")


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