Skip to content

Commit c3bcdf0

Browse files
authored
Fix xdebug transform calling WRITE_READY when no data consumed (#12760)
The probe-full-json transform called TSContCall(WRITE_READY) even when no data was consumed (towrite == 0), causing a tight loop that starved other transactions on the same ET_NET thread. Fix: Only call TSVIOReenable/TSContCall when towrite > 0. Added autest with slow chunked origin to verify the fix.
1 parent d967264 commit c3bcdf0

4 files changed

Lines changed: 229 additions & 2 deletions

File tree

plugins/xdebug/xdebug_transforms.cc

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -296,8 +296,13 @@ body_transform(TSCont contp, TSEvent event, void * /* edata ATS_UNUSED */)
296296
}
297297

298298
if (TSVIONTodoGet(src_vio) > 0) {
299-
TSVIOReenable(data->output_vio);
300-
TSContCall(TSVIOContGet(src_vio), TS_EVENT_VCONN_WRITE_READY, src_vio);
299+
if (towrite > 0) {
300+
// Only reenable when we consumed data. If we reenable and call
301+
// WRITE_READY when towrite is 0 (no data available yet), we create
302+
// a tight loop that starves other transactions and causes high CPU.
303+
TSVIOReenable(data->output_vio);
304+
TSContCall(TSVIOContGet(src_vio), TS_EVENT_VCONN_WRITE_READY, src_vio);
305+
}
301306
} else {
302307
// End of src vio
303308
// Write post body content and update output VIO
Lines changed: 78 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,78 @@
1+
#!/bin/bash
2+
# Licensed to the Apache Software Foundation (ASF) under one
3+
# or more contributor license agreements. See the NOTICE file
4+
# distributed with this work for additional information
5+
# regarding copyright ownership. The ASF licenses this file
6+
# to you under the Apache License, Version 2.0 (the
7+
# "License"); you may not use this file except in compliance
8+
# with the License. You may obtain a copy of the License at
9+
#
10+
# http://www.apache.org/licenses/LICENSE-2.0
11+
#
12+
# Unless required by applicable law or agreed to in writing, software
13+
# distributed under the License is distributed on an "AS IS" BASIS,
14+
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15+
# See the License for the specific language governing permissions and
16+
# limitations under the License.
17+
18+
# A simple server that sends headers and first chunk immediately, then delays
19+
# before sending subsequent chunks. This triggers the xdebug transform bug
20+
# when the transform is called but no body data is available yet.
21+
#
22+
# Usage: slow-body-server.sh <port> <outfile>
23+
24+
PORT=$1
25+
OUTFILE=$2
26+
27+
# Create a named pipe for the response
28+
FIFO=$(mktemp -u)
29+
mkfifo "$FIFO"
30+
31+
# Start nc in background, reading from the fifo
32+
nc -l "$PORT" > "$OUTFILE" < "$FIFO" &
33+
NC_PID=$!
34+
35+
# Open the fifo for writing
36+
exec 3>"$FIFO"
37+
38+
# Wait for the request to arrive (look for empty line ending headers)
39+
while true; do
40+
if [[ -f "$OUTFILE" ]]; then
41+
if grep -q $'^\r$' "$OUTFILE" 2>/dev/null || grep -q '^$' "$OUTFILE" 2>/dev/null; then
42+
break
43+
fi
44+
fi
45+
sleep 0.1
46+
done
47+
48+
# Send headers with chunked encoding
49+
printf "HTTP/1.1 200 OK\r\n" >&3
50+
printf "Content-Type: text/plain\r\n" >&3
51+
printf "Transfer-Encoding: chunked\r\n" >&3
52+
printf "X-Response: slow-chunked\r\n" >&3
53+
printf "\r\n" >&3
54+
55+
# Send first chunk immediately
56+
printf "5\r\n" >&3
57+
printf "hello\r\n" >&3
58+
59+
# Delay before next chunk - this is the key to triggering the bug
60+
# The transform will see more data expected but buffer empty
61+
sleep 2
62+
63+
# Send second chunk
64+
printf "5\r\n" >&3
65+
printf "world\r\n" >&3
66+
67+
# End chunked encoding
68+
printf "0\r\n" >&3
69+
printf "\r\n" >&3
70+
71+
# Close the fifo
72+
exec 3>&-
73+
74+
# Wait for nc to finish
75+
wait $NC_PID 2>/dev/null
76+
77+
# Cleanup
78+
rm -f "$FIFO"
Lines changed: 64 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,64 @@
1+
#!/bin/bash
2+
# Licensed to the Apache Software Foundation (ASF) under one
3+
# or more contributor license agreements. See the NOTICE file
4+
# distributed with this work for additional information
5+
# regarding copyright ownership. The ASF licenses this file
6+
# to you under the Apache License, Version 2.0 (the
7+
# "License"); you may not use this file except in compliance
8+
# with the License. You may obtain a copy of the License at
9+
#
10+
# http://www.apache.org/licenses/LICENSE-2.0
11+
#
12+
# Unless required by applicable law or agreed to in writing, software
13+
# distributed under the License is distributed on an "AS IS" BASIS,
14+
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15+
# See the License for the specific language governing permissions and
16+
# limitations under the License.
17+
18+
# Verify the transform completed successfully and didn't produce excessive log output.
19+
#
20+
# Our test sends a 2-chunk response (5 bytes each). Normal behavior:
21+
# - expected (first chunk)
22+
# - consumed (first chunk)
23+
# - expected (HttpTunnel callback - no data yet)
24+
# - expected (second chunk)
25+
# - consumed (second chunk)
26+
#
27+
# That's 4 "expected" lines for 2 chunks. The bug would cause many more "expected"
28+
# lines as the transform loops, but in our test the loop might not be tight enough
29+
# to produce many lines. We check that we don't have an excessive number.
30+
31+
LOGFILE="$1"
32+
MAX_EXPECTED_LINES=10 # Allow up to 10; our 2-chunk response should produce ~4
33+
34+
if [[ ! -f "$LOGFILE" ]]; then
35+
echo "FAIL: Log file not found: $LOGFILE"
36+
exit 1
37+
fi
38+
39+
# Count "expected" lines
40+
expected_count=$(grep -c "bytes of body is expected" "$LOGFILE" 2>/dev/null || echo "0")
41+
42+
echo "Transform log analysis:"
43+
echo " 'expected' lines: $expected_count (max allowed: $MAX_EXPECTED_LINES)"
44+
echo ""
45+
echo "Log contents:"
46+
grep -E "(bytes of body is expected|consumed.*bytes)" "$LOGFILE"
47+
echo ""
48+
49+
if [[ $expected_count -gt $MAX_EXPECTED_LINES ]]; then
50+
echo "FAIL: Found $expected_count 'expected' lines - indicates potential loop bug"
51+
exit 1
52+
fi
53+
54+
# Also verify we got exactly 2 consumed lines (for our 2 chunks)
55+
consumed_count=$(grep -c "consumed.*bytes" "$LOGFILE" 2>/dev/null || echo "0")
56+
echo " 'consumed' lines: $consumed_count (expected: 2)"
57+
58+
if [[ $consumed_count -ne 2 ]]; then
59+
echo "FAIL: Expected 2 consumed lines but found $consumed_count"
60+
exit 1
61+
fi
62+
63+
echo "PASS: Transform completed normally"
64+
exit 0
Lines changed: 80 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,80 @@
1+
'''
2+
Verify xdebug plugin probe-full-json does not hang with slow origin servers.
3+
4+
This test reproduces a bug where the transform would enter an infinite loop
5+
when the origin server delays sending the response body. The bug occurs because
6+
the transform would reenable and call back upstream even when no data was
7+
available to consume.
8+
'''
9+
# Licensed to the Apache Software Foundation (ASF) under one
10+
# or more contributor license agreements. See the NOTICE file
11+
# distributed with this work for additional information
12+
# regarding copyright ownership. The ASF licenses this file
13+
# to you under the Apache License, Version 2.0 (the
14+
# "License"); you may not use this file except in compliance
15+
# with the License. You may obtain a copy of the License at
16+
#
17+
# http://www.apache.org/licenses/LICENSE-2.0
18+
#
19+
# Unless required by applicable law or agreed to in writing, software
20+
# distributed under the License is distributed on an "AS IS" BASIS,
21+
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
22+
# See the License for the specific language governing permissions and
23+
# limitations under the License.
24+
25+
Test.Summary = '''
26+
Test xdebug probe-full-json with slow origin to verify no infinite loop
27+
'''
28+
29+
Test.SkipUnless(Condition.PluginExists('xdebug.so'))
30+
Test.SkipUnless(Condition.HasProgram("nc", "nc (netcat) is required for custom slow server"))
31+
32+
# Configure ATS
33+
ts = Test.MakeATSProcess("ts", enable_cache=False)
34+
35+
ts.Disk.records_config.update(
36+
{
37+
"proxy.config.diags.debug.enabled": 1,
38+
"proxy.config.diags.debug.tags": "xdebug_transform",
39+
# Set reasonable timeouts
40+
"proxy.config.http.transaction_no_activity_timeout_in": 10,
41+
"proxy.config.http.transaction_no_activity_timeout_out": 10,
42+
})
43+
44+
ts.Disk.plugin_config.AddLine('xdebug.so --enable=probe-full-json')
45+
46+
# Reserve a port for the custom slow server
47+
Test.GetTcpPort("server_port")
48+
49+
ts.Disk.remap_config.AddLine(f"map / http://127.0.0.1:{Test.Variables.server_port}/")
50+
51+
# Start the custom slow-body server
52+
server = Test.Processes.Process(
53+
"server",
54+
f"bash -c '{Test.TestDirectory}/slow-body-server.sh {Test.Variables.server_port} {Test.RunDirectory}/server_request.txt'")
55+
56+
# Test with probe-full-json=nobody (which triggers the bug most easily)
57+
tr = Test.AddTestRun("Verify probe-full-json with slow body delivery")
58+
tr.TimeOut = 15 # Should complete well under this; timeout indicates hang/loop
59+
60+
# Make the request - use timeout to detect if the request hangs
61+
tr.Processes.Default.Command = (
62+
f'timeout 8 curl -s -o /dev/null -w "%{{http_code}}" '
63+
f'-H "Host: example.com" '
64+
f'-H "X-Debug: probe-full-json=nobody" '
65+
f'http://127.0.0.1:{ts.Variables.port}/test')
66+
tr.Processes.Default.ReturnCode = 0
67+
tr.Processes.Default.StartBefore(server)
68+
tr.Processes.Default.StartBefore(ts)
69+
70+
# Should get 200, not timeout (which would cause non-zero return and 124 output)
71+
tr.Processes.Default.Streams.stdout = Testers.ContainsExpression("200", "Should receive 200 OK, not timeout")
72+
73+
# Verify no infinite loop by checking the logs
74+
# The bug manifests as the transform being called with "bytes of body is expected"
75+
# but no data consumed. Every "expected" should be followed by "consumed".
76+
tr2 = Test.AddTestRun("Verify no infinite loop in transform")
77+
tr2.Processes.Default.Command = f"bash {Test.TestDirectory}/verify_no_loop.sh {ts.Variables.LOGDIR}/traffic.out"
78+
tr2.Processes.Default.ReturnCode = 0
79+
tr2.Processes.Default.Streams.stdout = Testers.ContainsExpression(
80+
"PASS", "Verification script should pass - every 'expected' followed by 'consumed'")

0 commit comments

Comments
 (0)