trafficserver
trafficserver copied to clipboard
apache
H2 POST request causes crash
ATS master crashes while handling this request below.
$ curl -kv -d @~/tmp/8k --http2 -H "Expect: 100-Continue" https://127.0.0.1:8443/httpbin/post
Removing these 2 lines works for the crash, but I'm not sure if we can really remove those. The lines were added by the PR for H2-to-Origin. https://github.com/apache/trafficserver/blob/9909da8b5621ac85f0a474527cf7fd58a03b1ff0/proxy/http/HttpTunnel.cc#L995-L996
* thread #3, name = '[ET_NET 0]', stop reason = EXC_BAD_ACCESS (code=2, address=0x10a3a3d50)
* frame #0: 0x00000001835f42e8 libsystem_c.dylib`getenv + 8
frame #1: 0x00000001835f9d24 libsystem_c.dylib`_st_tzset_basic + 60
frame #2: 0x00000001835f9cb8 libsystem_c.dylib`localtime_r + 52
frame #3: 0x00000001836116dc libsystem_c.dylib`ctime_r + 48
frame #4: 0x0000000104fee444 libclang_rt.asan_osx_dynamic.dylib`wrap_ctime_r + 112
frame #5: 0x0000000103e33558 libtscore.10.dylib`(anonymous namespace)::BWF_Timestamp(w=0x000000010a3a4f00, spec=0x000000010a3a4e80) at BufferWriterFormat.cc:950:3
frame #6: 0x0000000100fcded4 traffic_server`ts::BufferWriter& ts::BufferWriter::printv<>(this=0x000000010a3a5400, fmt=(std::__1::string_view = "] "), args=size=0) at BufferWriter.h:660:11
frame #7: 0x0000000103e5ae54 libtscore.10.dylib`ts::FixedBufferWriter& ts::FixedBufferWriter::print<>(this=0x000000010a3a5400, fmt=(std::__1::string_view = "[{timestamp}] ")) at BufferWriter.h:887:53
frame #8: 0x0000000103e59c5c libtscore.10.dylib`Diags::print_va(this=0x0000000108502d40, debug_tag="http_trans", diags_level=DL_Debug, loc=0x0000000101833000, format_string="Adding Server: %s", ap="pu`\a\U00000001") const at Diags.cc:254:17
frame #9: 0x0000000103f72ef8 libtscore.10.dylib`LogMessage::message_print_helper(this=0x000000010cbb7828, fmt="Adding Server: %s", args="pu`\a\U00000001")::$_2::operator()(char const*, char*) const at LogMessage.cc:103:66
frame #10: 0x0000000103f72dc4 libtscore.10.dylib`decltype(__f=0x000000010cbb7828, __args=0x000000010a3a6840, __args=<no value available>)::$_2&>()(std::declval<char const*>(), std::declval<char*>())) std::__1::__invoke[abi:v15006]<LogMessage::message_print_helper(char const*, DiagsLevel, SourceLocation const&, char const*, char*)::$_2&, char const*, char*>(LogMessage::message_print_helper(char const*, DiagsLevel, SourceLocation const&, char const*, char*)::$_2&, char const*&&, char*&&) at invoke.h:394:23
frame #11: 0x0000000103f72ce0 libtscore.10.dylib`void std::__1::__invoke_void_return_wrapper<void, true>::__call<LogMessage::message_print_helper(__args=0x000000010cbb7828, __args=0x000000010a3a6840, __args=<no value available>)::$_2&, char const*, char*>(LogMessage::message_print_helper(char const*, DiagsLevel, SourceLocation const&, char const*, char*)::$_2&, char const*&&, char*&&) at invoke.h:479:9
frame #12: 0x0000000103f72cac libtscore.10.dylib`std::__1::__function::__alloc_func<LogMessage::message_print_helper(char const*, DiagsLevel, SourceLocation const&, char const*, char*)::$_2, std::__1::allocator<LogMessage::message_print_helper(char const*, DiagsLevel, SourceLocation const&, char const*, char*)::$_2>, void (char const*, char*)>::operator(this=0x000000010cbb7828, __arg=0x000000010a3a6840, __arg=<no value available>)[abi:v15006](char const*&&, char*&&) at function.h:185:16
frame #13: 0x0000000103f6ee54 libtscore.10.dylib`std::__1::__function::__func<LogMessage::message_print_helper(char const*, DiagsLevel, SourceLocation const&, char const*, char*)::$_2, std::__1::allocator<LogMessage::message_print_helper(char const*, DiagsLevel, SourceLocation const&, char const*, char*)::$_2>, void (char const*, char*)>::operator(this=0x000000010cbb7820, __arg=0x000000010a3a6840, __arg=<no value available>)(char const*&&, char*&&) at function.h:359:12
frame #14: 0x0000000103f62108 libtscore.10.dylib`std::__1::__function::__value_func<void (char const*, char*)>::operator(this=0x000000010a3a6d80, __args=0x000000010a3a6840, __args=<no value available>)[abi:v15006](char const*&&, char*&&) const at function.h:512:16
frame #15: 0x0000000103f5d26c libtscore.10.dylib`std::__1::function<void (char const*, char*)>::operator(this=0x000000010a3a6d80, __arg="Adding Server: %s", __arg="pu`\a\U00000001")(char const*, char*) const at function.h:1197:12
frame #16: 0x0000000103f5c9bc libtscore.10.dylib`LogMessage::message_helper(this=0x0000000101833060, current_configured_interval=(__rep_ = 0), log_function=0x000000010a3a6d80, fmt="Adding Server: %s", args="pu`\a\U00000001")> const&, char const*, char*) at LogMessage.cc:59:5
frame #17: 0x0000000103f5e584 libtscore.10.dylib`LogMessage::message_print_helper(this=0x0000000101833060, tag="http_trans", level=DL_Debug, loc=0x0000000101833000, fmt="Adding Server: %s", args="pu`\a\U00000001") at LogMessage.cc:101:3
frame #18: 0x0000000103f60b68 libtscore.10.dylib`LogMessage::print(this=0x0000000101833060, tag="http_trans", level=DL_Debug, loc=0x0000000101833000, fmt="Adding Server: %s") at LogMessage.cc:204:3
frame #19: 0x00000001004dcd20 traffic_server`HttpTransactHeaders::add_server_header_to_response(http_txn_conf=0x0000000113bbdce0, header=0x0000000113bbd848) at HttpTransactHeaders.cc:1177:7
frame #20: 0x000000010042e8ac traffic_server`HttpTransact::build_response_copy(s=0x0000000113bbd108, base_response=0x0000000113bbd8c8, outgoing_response=0x0000000113bbd848, outgoing_version=(vmajor = '\x01', vminor = '\x01')) at HttpTransact.cc:4107:3
frame #21: 0x0000000100472a74 traffic_server`HttpTransact::handle_100_continue_response(s=0x0000000113bbd108) at HttpTransact.cc:4091:5
frame #22: 0x000000010046eb6c traffic_server`HttpTransact::handle_forward_server_connection_open(s=0x0000000113bbd108) at HttpTransact.cc:3992:5
frame #23: 0x000000010046a1c0 traffic_server`HttpTransact::handle_response_from_server(s=0x0000000113bbd108) at HttpTransact.cc:3742:5
frame #24: 0x0000000100430dc4 traffic_server`HttpTransact::HandleResponse(s=0x0000000113bbd108) at HttpTransact.cc:3447:5
frame #25: 0x00000001002fa0a0 traffic_server`HttpSM::call_transact_and_set_next_state(this=0x0000000113bbd000, f=0x0000000000000000)(HttpTransact::State*)) at HttpSM.cc:7826:5
frame #26: 0x000000010030cb68 traffic_server`HttpSM::handle_api_return(this=0x0000000113bbd000) at HttpSM.cc:1701:5
frame #27: 0x000000010030a804 traffic_server`HttpSM::state_api_callout(this=0x0000000113bbd000, event=0, data=0x0000000000000000) at HttpSM.cc:1633:5
frame #28: 0x0000000100372ec8 traffic_server`HttpSM::do_api_callout_internal(this=0x0000000113bbd000) at HttpSM.cc:5781:10
frame #29: 0x00000001002ec9bc traffic_server`HttpSM::do_api_callout(this=0x0000000113bbd000) at HttpSM.cc:411:12
frame #30: 0x00000001002fe3fc traffic_server`HttpSM::tunnel_handler_post(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2964:7
frame #31: 0x00000001002eb700 traffic_server`HttpSM::main_handler(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2802:5
frame #32: 0x000000010000d588 traffic_server`Continuation::handleEvent(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at I_Continuation.h:228:12
frame #33: 0x00000001004ef5f4 traffic_server`HttpTunnel::tunnel_run(this=0x0000000113bbe948, p_arg=0x0000000113bbeb58) at HttpTunnel.cc:752:9
frame #34: 0x0000000100334890 traffic_server`HttpSM::do_setup_post_tunnel(this=0x0000000113bbd000, to_vc_type=HTTP_SERVER_VC) at HttpSM.cc:6386:10
frame #35: 0x000000010034db2c traffic_server`HttpSM::tunnel_handler_100_continue(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:3090:7
frame #36: 0x00000001002eb700 traffic_server`HttpSM::main_handler(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2802:5
frame #37: 0x000000010000d588 traffic_server`Continuation::handleEvent(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at I_Continuation.h:228:12
frame #38: 0x00000001004ef5f4 traffic_server`HttpTunnel::tunnel_run(this=0x0000000113bbe948, p_arg=0x0000000113bbeb58) at HttpTunnel.cc:752:9
frame #39: 0x00000001003782a4 traffic_server`HttpSM::setup_100_continue_transfer(this=0x0000000113bbd000) at HttpSM.cc:6869:10
frame #40: 0x0000000100381864 traffic_server`HttpSM::set_next_state(this=0x0000000113bbd000) at HttpSM.cc:8022:5
frame #41: 0x00000001002fa584 traffic_server`HttpSM::call_transact_and_set_next_state(this=0x0000000113bbd000, f=0x0000000000000000)(HttpTransact::State*)) at HttpSM.cc:7834:3
frame #42: 0x000000010030cb68 traffic_server`HttpSM::handle_api_return(this=0x0000000113bbd000) at HttpSM.cc:1701:5
frame #43: 0x000000010030a804 traffic_server`HttpSM::state_api_callout(this=0x0000000113bbd000, event=0, data=0x0000000000000000) at HttpSM.cc:1633:5
frame #44: 0x0000000100372ec8 traffic_server`HttpSM::do_api_callout_internal(this=0x0000000113bbd000) at HttpSM.cc:5781:10
frame #45: 0x00000001002ec9bc traffic_server`HttpSM::do_api_callout(this=0x0000000113bbd000) at HttpSM.cc:411:12
frame #46: 0x00000001002fe3fc traffic_server`HttpSM::tunnel_handler_post(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2964:7
frame #47: 0x00000001002eb700 traffic_server`HttpSM::main_handler(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2802:5
frame #48: 0x000000010000d588 traffic_server`Continuation::handleEvent(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at I_Continuation.h:228:12
frame #49: 0x00000001004ef5f4 traffic_server`HttpTunnel::tunnel_run(this=0x0000000113bbe948, p_arg=0x0000000113bbeb58) at HttpTunnel.cc:752:9
frame #50: 0x0000000100334890 traffic_server`HttpSM::do_setup_post_tunnel(this=0x0000000113bbd000, to_vc_type=HTTP_SERVER_VC) at HttpSM.cc:6386:10
frame #51: 0x000000010034db2c traffic_server`HttpSM::tunnel_handler_100_continue(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:3090:7
frame #52: 0x00000001002eb700 traffic_server`HttpSM::main_handler(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2802:5
frame #53: 0x000000010000d588 traffic_server`Continuation::handleEvent(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at I_Continuation.h:228:12
frame #54: 0x00000001004ef5f4 traffic_server`HttpTunnel::tunnel_run(this=0x0000000113bbe948, p_arg=0x0000000113bbeb58) at HttpTunnel.cc:752:9
frame #55: 0x00000001003782a4 traffic_server`HttpSM::setup_100_continue_transfer(this=0x0000000113bbd000) at HttpSM.cc:6869:10
frame #56: 0x0000000100381864 traffic_server`HttpSM::set_next_state(this=0x0000000113bbd000) at HttpSM.cc:8022:5
frame #57: 0x00000001002fa584 traffic_server`HttpSM::call_transact_and_set_next_state(this=0x0000000113bbd000, f=0x0000000000000000)(HttpTransact::State*)) at HttpSM.cc:7834:3
frame #58: 0x000000010030cb68 traffic_server`HttpSM::handle_api_return(this=0x0000000113bbd000) at HttpSM.cc:1701:5
frame #59: 0x000000010030a804 traffic_server`HttpSM::state_api_callout(this=0x0000000113bbd000, event=0, data=0x0000000000000000) at HttpSM.cc:1633:5
frame #60: 0x0000000100372ec8 traffic_server`HttpSM::do_api_callout_internal(this=0x0000000113bbd000) at HttpSM.cc:5781:10
frame #61: 0x00000001002ec9bc traffic_server`HttpSM::do_api_callout(this=0x0000000113bbd000) at HttpSM.cc:411:12
frame #62: 0x00000001002fe3fc traffic_server`HttpSM::tunnel_handler_post(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2964:7
frame #63: 0x00000001002eb700 traffic_server`HttpSM::main_handler(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2802:5
frame #64: 0x000000010000d588 traffic_server`Continuation::handleEvent(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at I_Continuation.h:228:12
frame #65: 0x00000001004ef5f4 traffic_server`HttpTunnel::tunnel_run(this=0x0000000113bbe948, p_arg=0x0000000113bbeb58) at HttpTunnel.cc:752:9
frame #66: 0x0000000100334890 traffic_server`HttpSM::do_setup_post_tunnel(this=0x0000000113bbd000, to_vc_type=HTTP_SERVER_VC) at HttpSM.cc:6386:10
frame #67: 0x000000010034db2c traffic_server`HttpSM::tunnel_handler_100_continue(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:3090:7
frame #68: 0x00000001002eb700 traffic_server`HttpSM::main_handler(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2802:5
frame #69: 0x000000010000d588 traffic_server`Continuation::handleEvent(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at I_Continuation.h:228:12
frame #70: 0x00000001004ef5f4 traffic_server`HttpTunnel::tunnel_run(this=0x0000000113bbe948, p_arg=0x0000000113bbeb58) at HttpTunnel.cc:752:9
frame #71: 0x00000001003782a4 traffic_server`HttpSM::setup_100_continue_transfer(this=0x0000000113bbd000) at HttpSM.cc:6869:10
frame #72: 0x0000000100381864 traffic_server`HttpSM::set_next_state(this=0x0000000113bbd000) at HttpSM.cc:8022:5
frame #73: 0x00000001002fa584 traffic_server`HttpSM::call_transact_and_set_next_state(this=0x0000000113bbd000, f=0x0000000000000000)(HttpTransact::State*)) at HttpSM.cc:7834:3
{{snip}}
frame #1145: 0x00000001002fa584 traffic_server`HttpSM::call_transact_and_set_next_state(this=0x0000000113bbd000, f=0x0000000000000000)(HttpTransact::State*)) at HttpSM.cc:7834:3
frame #1146: 0x000000010030cb68 traffic_server`HttpSM::handle_api_return(this=0x0000000113bbd000) at HttpSM.cc:1701:5
frame #1147: 0x000000010030a804 traffic_server`HttpSM::state_api_callout(this=0x0000000113bbd000, event=0, data=0x0000000000000000) at HttpSM.cc:1633:5
frame #1148: 0x0000000100372ec8 traffic_server`HttpSM::do_api_callout_internal(this=0x0000000113bbd000) at HttpSM.cc:5781:10
frame #1149: 0x00000001002ec9bc traffic_server`HttpSM::do_api_callout(this=0x0000000113bbd000) at HttpSM.cc:411:12
frame #1150: 0x00000001002fe3fc traffic_server`HttpSM::tunnel_handler_post(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2964:7
frame #1151: 0x00000001002eb700 traffic_server`HttpSM::main_handler(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2802:5
frame #1152: 0x000000010000d588 traffic_server`Continuation::handleEvent(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at I_Continuation.h:228:12
frame #1153: 0x00000001004ef5f4 traffic_server`HttpTunnel::tunnel_run(this=0x0000000113bbe948, p_arg=0x0000000113bbeb58) at HttpTunnel.cc:752:9
frame #1154: 0x0000000100334890 traffic_server`HttpSM::do_setup_post_tunnel(this=0x0000000113bbd000, to_vc_type=HTTP_SERVER_VC) at HttpSM.cc:6386:10
frame #1155: 0x000000010034db2c traffic_server`HttpSM::tunnel_handler_100_continue(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:3090:7
frame #1156: 0x00000001002eb700 traffic_server`HttpSM::main_handler(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at HttpSM.cc:2802:5
frame #1157: 0x000000010000d588 traffic_server`Continuation::handleEvent(this=0x0000000113bbd000, event=2301, data=0x0000000113bbe948) at I_Continuation.h:228:12
frame #1158: 0x00000001004ef5f4 traffic_server`HttpTunnel::tunnel_run(this=0x0000000113bbe948, p_arg=0x0000000113bbeb58) at HttpTunnel.cc:752:9
frame #1159: 0x00000001003782a4 traffic_server`HttpSM::setup_100_continue_transfer(this=0x0000000113bbd000) at HttpSM.cc:6869:10
frame #1160: 0x0000000100381864 traffic_server`HttpSM::set_next_state(this=0x0000000113bbd000) at HttpSM.cc:8022:5
frame #1161: 0x00000001002fa584 traffic_server`HttpSM::call_transact_and_set_next_state(this=0x0000000113bbd000, f=0x0000000000000000)(HttpTransact::State*)) at HttpSM.cc:7834:3
frame #1162: 0x000000010030cb68 traffic_server`HttpSM::handle_api_return(this=0x0000000113bbd000) at HttpSM.cc:1701:5
frame #1163: 0x000000010030a804 traffic_server`HttpSM::state_api_callout(this=0x0000000113bbd000, event=0, data=0x0000000000000000) at HttpSM.cc:1633:5
frame #1164: 0x0000000100372ec8 traffic_server`HttpSM::do_api_callout_internal(this=0x0000000113bbd000) at HttpSM.cc:5781:10
frame #1165: 0x00000001002ec9bc traffic_server`HttpSM::do_api_callout(this=0x0000000113bbd000) at HttpSM.cc:411:12
frame #1166: 0x000000010032dc20 traffic_server`HttpSM::state_read_server_response_header(this=0x0000000113bbd000, event=100, data=0x0000000113ca3e08) at HttpSM.cc:2165:7
frame #1167: 0x00000001002eb594 traffic_server`HttpSM::main_handler(this=0x0000000113bbd000, event=100, data=0x0000000113ca3e08) at HttpSM.cc:2799:5
frame #1168: 0x000000010000d588 traffic_server`Continuation::handleEvent(this=0x0000000113bbd000, event=100, data=0x0000000113ca3e08) at I_Continuation.h:228:12
frame #1169: 0x0000000100ec12f8 traffic_server`read_signal_and_update(event=100, vc=0x0000000113ca3bf0) at UnixNetVConnection.cc:82:24
frame #1170: 0x0000000100ebf854 traffic_server`read_from_net(nh=0x0000000109b08c00, vc=0x0000000113ca3bf0, thread=0x0000000109b04800) at UnixNetVConnection.cc:322:11
frame #1171: 0x0000000100ebe00c traffic_server`UnixNetVConnection::net_read_io(this=0x0000000113ca3bf0, nh=0x0000000109b08c00, lthread=0x0000000109b04800) at UnixNetVConnection.cc:854:3
frame #1172: 0x0000000100e84dac traffic_server`NetHandler::process_ready_list(this=0x0000000109b08c00) at UnixNet.cc:405:11
frame #1173: 0x0000000100e865c0 traffic_server`NetHandler::waitForActivity(this=0x0000000109b08c00, timeout=10000000) at UnixNet.cc:540:3
frame #1174: 0x000000010116cdf4 traffic_server`EThread::execute_regular(this=0x0000000109b04800) at UnixEThread.cc:285:14
frame #1175: 0x000000010116e078 traffic_server`EThread::execute(this=0x0000000109b04800) at UnixEThread.cc:334:11
frame #1176: 0x00000001011688b8 traffic_server`spawn_thread_internal(a=0x0000000107432780) at Thread.cc:79:12
I took a stab at reproducing this via an autest with the following patch:
Click to expand
diff --git a/tests/gold_tests/h2/h2origin.test.py b/tests/gold_tests/h2/h2origin.test.py
index cedbc7d00..e3db7b971 100644
--- a/tests/gold_tests/h2/h2origin.test.py
+++ b/tests/gold_tests/h2/h2origin.test.py
@@ -17,6 +17,8 @@ Test communication to origin with H2
# See the License for the specific language governing permissions and
# limitations under the License.
+import os
+
Test.Summary = '''
Test communication to origin with H2
'''
@@ -32,6 +34,7 @@ ts = Test.MakeATSProcess("ts", enable_tls="true")
ts.addDefaultSSLFiles()
replay_file = "replay_h2origin/"
server = Test.MakeVerifierServerProcess("h2-origin", replay_file)
+httpbin = Test.MakeHttpBinServer("httpbin")
ts.Disk.records_config.update({
'proxy.config.ssl.server.cert.path': '{0}'.format(ts.Variables.SSLDir),
'proxy.config.ssl.server.private_key.path': '{0}'.format(ts.Variables.SSLDir),
@@ -47,9 +50,10 @@ ts.Disk.records_config.update({
'proxy.config.ssl.client.verify.server.policy': 'PERMISSIVE',
})
-ts.Disk.remap_config.AddLine(
- 'map / https://127.0.0.1:{0}'.format(server.Variables.https_port)
-)
+ts.Disk.remap_config.AddLines([
+ f'map /httpbin http://127.0.0.1:{httpbin.Variables.Port}',
+ f'map / https://127.0.0.1:{server.Variables.https_port}'
+])
ts.Disk.ssl_multicert_config.AddLine(
'dest_ip=* ssl_cert_name=server.pem ssl_key_name=server.key'
)
@@ -74,14 +78,22 @@ tr.AddVerifierClientProcess("client", replay_file, http_ports=[ts.Variables.port
tr.StillRunningAfter = ts
tr.TimeOut = 60
-# Just a check to flush out the traffic log until we have a clean shutdown for traffic_server
-tr = Test.AddTestRun("Wait for the access log to write out")
-tr.DelayStart = 10
-tr.StillRunningAfter = ts
-tr.StillRunningAfter = server
-tr.Processes.Default.Command = 'ls'
+tr = Test.AddTestRun("Test a POST request with an Expect: 100-continue header")
+content_file = os.path.join(Test.RunDirectory, '8k')
+with open(content_file, 'wb') as f:
+ f.write(os.urandom(8192))
+tr.Processes.Default.StartBefore(httpbin)
+tr.Processes.Default.Command = (
+ f'curl -kv -d @{content_file} --http2 -H "Expect: 100-Continue" '
+ f'https://127.0.0.1:{ts.Variables.ssl_port}/httpbin/post')
tr.Processes.Default.ReturnCode = 0
+# Wait until the transaction log is written.
+tr = Test.AddTestRun("Wait for the access log to write out")
+cond_wait_path = os.path.join(Test.Variables.AtsTestToolsDir, 'condwait')
+squid_log_path = os.path.join(ts.Variables.LOGDIR, 'squid.log')
+tr.Processes.Default.Command = f'{cond_wait_path} 60 1 -f {squid_log_path}'
+
# UUIDs 1-4 should be http/1.1 clients and H2 origin
# UUIDs 5-9 should be http/2 clients and H2 origins
ts.Disk.squid_log.Content = Testers.ContainsExpression(" [1-4] http/1.1 http/2", "cases 1-4 request http/1.1")
The interesting portion of the patch being the following new TestRun:
tr = Test.AddTestRun("Test a POST request with an Expect: 100-continue header")
content_file = os.path.join(Test.RunDirectory, '8k')
with open(content_file, 'wb') as f:
f.write(os.urandom(8192))
tr.Processes.Default.StartBefore(httpbin)
tr.Processes.Default.Command = (
f'curl -kv -d @{content_file} --http2 -H "Expect: 100-Continue" '
f'https://127.0.0.1:{ts.Variables.ssl_port}/httpbin/post')
tr.Processes.Default.ReturnCode = 0
Our local autests use go-httpbin because httpbin is deprecated and no longer supported. Masakazu confirmed that when he switched his remap from map /httpbin/ http://httpbin.org/ to map /httpbin/ http://httpbingo.org/, the crash no longer reproduced. So it seems the crash relies upon some behavior in httpbin that go-httpbin does not quite replicate.
I'm going to try to reproduce the crash using Proxy Verifier. I think I saw a crash with that in an earlier attempt, but Proxy Verifier could use some Expect: 100-continue updates.
This issue has been automatically marked as stale because it has not had recent activity. Marking it stale to flag it for further consideration by the community.
![github-actions[bot] avatar](https://avatars.githubusercontent.com/in/15368?v=4 "Published by a pub.dev verified publisher"){kind=small}