diff --git a/proxy/http/HttpSM.cc b/proxy/http/HttpSM.cc index f763bf98ec2..c8f02f88e94 100644 --- a/proxy/http/HttpSM.cc +++ b/proxy/http/HttpSM.cc @@ -1985,12 +1985,20 @@ int HttpSM::state_read_server_response_header(int event, void *data) { STATE_ENTER(&HttpSM::state_read_server_response_header, event); + // If we had already received EOS, just go away. We would sometimes see + // a WRITE event appear after receiving EOS from the server connection + if (server_entry->eos) { + return 0; + } else if (data == server_entry->write_vio) { + return this->state_send_server_request_header(event, data); + } + + ink_assert(server_entry->eos != true); ink_assert(server_entry->read_vio == (VIO *)data); ink_assert(t_state.current.server->state == HttpTransact::STATE_UNDEFINED); ink_assert(t_state.current.state == HttpTransact::STATE_UNDEFINED); int bytes_used = 0; - VIO *vio = static_cast(data); switch (event) { case VC_EVENT_EOS: @@ -2036,7 +2044,7 @@ HttpSM::state_read_server_response_header(int event, void *data) // And don't allow empty headers from closed connections if ((state == PARSE_RESULT_DONE && t_state.hdr_info.server_response.version_get() == HTTP_0_9 && server_txn->get_transaction_id() > 1) || - (server_entry->eos && vio->ndone == 0)) { + (server_entry->eos && state == PARSE_RESULT_CONT)) { // No more data will be coming state = PARSE_RESULT_ERROR; } // Check to see if we are over the hdr size limit @@ -2049,6 +2057,15 @@ HttpSM::state_read_server_response_header(int event, void *data) server_entry->read_vio->nbytes = server_entry->read_vio->ndone; http_parser_clear(&http_parser); milestones[TS_MILESTONE_SERVER_READ_HEADER_DONE] = Thread::get_hrtime(); + + // If there is a post body in transit, give up on it + if (tunnel.is_tunnel_alive()) { + tunnel.abort_tunnel(); + // Make sure client connection is closed when we are done in case there is cruft left over + t_state.client_info.keep_alive = HTTP_NO_KEEPALIVE; + // Similarly the server connection should also be closed + t_state.current.server->keep_alive = HTTP_NO_KEEPALIVE; + } } switch (state) { @@ -2113,7 +2130,14 @@ HttpSM::state_read_server_response_header(int event, void *data) this->disable_redirect(); } - do_api_callout(); + // Go ahead and process the hooks assuming any body tunnel has already completed + if (!tunnel.is_tunnel_alive()) { + SMDebug("http_seq", "Continue processing response"); + do_api_callout(); + } else { + SMDebug("http_seq", "Defer processing response until post body is processed"); + server_entry->read_vio->disable(); // Disable the read until we finish the tunnel + } break; case PARSE_RESULT_CONT: ink_assert(server_entry->eos == false); @@ -2130,9 +2154,13 @@ HttpSM::state_read_server_response_header(int event, void *data) int HttpSM::state_send_server_request_header(int event, void *data) { - STATE_ENTER(&HttpSM::state_send_server_request_header, event); ink_assert(server_entry != nullptr); - ink_assert(server_entry->write_vio == (VIO *)data || server_entry->read_vio == (VIO *)data); + if (server_entry->read_vio == data) { + return this->state_read_server_response_header(event, data); + } + ink_assert(server_entry->eos == false); + ink_assert(server_entry->write_vio == (VIO *)data); + STATE_ENTER(&HttpSM::state_send_server_request_header, event); int method; @@ -2156,34 +2184,12 @@ HttpSM::state_send_server_request_header(int event, void *data) // Go ahead and set up the post tunnel if we are not waiting for a 100 response if (!t_state.hdr_info.client_request.m_100_continue_required) { do_setup_post_tunnel(HTTP_SERVER_VC); - } else { - setup_server_read_response_header(); } } - } else { - // It's time to start reading the response - setup_server_read_response_header(); } break; - case VC_EVENT_READ_READY: - // We already did the read for the response header and - // we got some data. Wait for the request header - // send before dealing with it. However, we need to - // disable further IO here since the whole response - // may be in the buffer and we can not switch buffers - // on the io core later - ink_assert(server_entry->read_vio == (VIO *)data); - // setting nbytes to ndone would disable reads and remove it from the read queue. - // We can't do this in the epoll paradigm because we may be missing epoll errors that would - // prevent us from leaving this state. - // setup_server_read_response_header will trigger READ_READY to itself if there is data in the buffer. - - // server_entry->read_vio->nbytes = server_entry->read_vio->ndone; - - break; - case VC_EVENT_EOS: // EOS of stream comes from the read side. Treat it as // as error if there is nothing in the read buffer. If @@ -2892,7 +2898,15 @@ HttpSM::tunnel_handler_post(int event, void *data) call_transact_and_set_next_state(HttpTransact::HandleRequestBufferDone); break; } - setup_server_read_response_header(); + // Is the response header ready and waiting? + // If so, go ahead and do the hook processing + if (milestones[TS_MILESTONE_SERVER_READ_HEADER_DONE] != 0) { + Warning("Process waiting response id=[%" PRId64, sm_id); + t_state.current.state = HttpTransact::CONNECTION_ALIVE; + t_state.transact_return_point = HttpTransact::HandleResponse; + t_state.api_next_action = HttpTransact::SM_ACTION_API_READ_RESPONSE_HDR; + do_api_callout(); + } break; default: ink_release_assert(0); @@ -5605,21 +5619,15 @@ HttpSM::handle_post_failure() t_state.client_info.keep_alive = HTTP_NO_KEEPALIVE; t_state.current.server->keep_alive = HTTP_NO_KEEPALIVE; - if (server_txn->get_remote_reader()->read_avail() > 0) { - tunnel.deallocate_buffers(); - tunnel.reset(); - // There's data from the server so try to read the header - setup_server_read_response_header(); - } else { - tunnel.deallocate_buffers(); - tunnel.reset(); - // Server died - if (t_state.current.state == HttpTransact::STATE_UNDEFINED || t_state.current.state == HttpTransact::CONNECTION_ALIVE) { - t_state.set_connect_fail(server_txn->get_netvc()->lerrno); - t_state.current.state = HttpTransact::CONNECTION_CLOSED; - } - call_transact_and_set_next_state(HttpTransact::HandleResponse); + ink_assert(server_txn->get_remote_reader()->read_avail() == 0); + tunnel.deallocate_buffers(); + tunnel.reset(); + // Server died + if (t_state.current.state == HttpTransact::STATE_UNDEFINED || t_state.current.state == HttpTransact::CONNECTION_ALIVE) { + t_state.set_connect_fail(server_txn->get_netvc()->lerrno); + t_state.current.state = HttpTransact::CONNECTION_CLOSED; } + call_transact_and_set_next_state(HttpTransact::HandleResponse); } // void HttpSM::handle_http_server_open() @@ -5658,7 +5666,7 @@ HttpSM::handle_http_server_open() if (method != HTTP_WKSIDX_TRACE && (t_state.hdr_info.request_content_length > 0 || t_state.client_info.transfer_encoding == HttpTransact::CHUNKED_ENCODING) && do_post_transform_open()) { - do_setup_post_tunnel(HTTP_TRANSFORM_VC); + do_setup_post_tunnel(HTTP_TRANSFORM_VC); // Seems like we should be sending the request along this way too } else if (server_txn != nullptr) { setup_server_send_request_api(); } @@ -6263,6 +6271,9 @@ HttpSM::setup_server_send_request() // Make sure the VC is using correct timeouts. We may be reusing a previously used server session server_txn->set_inactivity_timeout(get_server_inactivity_timeout()); + + // Go on and set up the read response header too + setup_server_read_response_header(); } void @@ -6276,6 +6287,8 @@ HttpSM::setup_server_read_response_header() ink_assert(server_txn != nullptr && server_txn->get_remote_reader() != nullptr); + SMDebug("http", "[setup_server_read_response_header] Setting up the header read"); + // Now that we've got the ability to read from the // server, setup to read the response header server_entry->vc_handler = &HttpSM::state_read_server_response_header; @@ -6434,6 +6447,9 @@ HttpSM::setup_100_continue_transfer() ua_txn->set_half_close_flag(false); ua_entry->in_tunnel = true; tunnel.tunnel_run(p); + + // Set up the header response read again. Already processed the 100 response + setup_server_read_response_header(); } ////////////////////////////////////////////////////////////////////////// @@ -7591,6 +7607,8 @@ HttpSM::set_next_state() break; } + // This is called in some case if the 100 continue header is from a HTTP/1.0 server + // Likely an obsolete case now and should probably return an error case HttpTransact::SM_ACTION_SERVER_PARSE_NEXT_HDR: { setup_server_read_response_header(); break; diff --git a/proxy/http/HttpTunnel.cc b/proxy/http/HttpTunnel.cc index d01ec08bd10..820ec734c60 100644 --- a/proxy/http/HttpTunnel.cc +++ b/proxy/http/HttpTunnel.cc @@ -498,6 +498,26 @@ HttpTunnel::kill_tunnel() this->reset(); } +void +HttpTunnel::abort_tunnel() +{ + active = false; + deallocate_buffers(); + for (auto &producer : producers) { + if (producer.alive && producer.vc) { + producer.vc->do_io_read(this, 0, nullptr); + } + producer.alive = false; + } + for (auto &consumer : consumers) { + if (consumer.alive && consumer.vc) { + consumer.vc->do_io_write(this, 0, nullptr); + } + consumer.alive = false; + } + reset(); +} + HttpTunnelProducer * HttpTunnel::alloc_producer() { diff --git a/proxy/http/HttpTunnel.h b/proxy/http/HttpTunnel.h index d73fc0c48fc..f4c8888ee61 100644 --- a/proxy/http/HttpTunnel.h +++ b/proxy/http/HttpTunnel.h @@ -273,6 +273,7 @@ class HttpTunnel : public Continuation void init(HttpSM *sm_arg, Ptr &amutex); void reset(); + void abort_tunnel(); void kill_tunnel(); bool is_tunnel_active() const diff --git a/tests/gold_tests/post/post-early-return.test.py b/tests/gold_tests/post/post-early-return.test.py new file mode 100644 index 00000000000..fbcee87ace7 --- /dev/null +++ b/tests/gold_tests/post/post-early-return.test.py @@ -0,0 +1,113 @@ +''' +''' +# 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 + +# ---- +# Setup Test +# ---- +Test.Summary = ''' +Test a case when the origin returns before the post is completed +''' +Test.ContinueOnFail = True + +Test.GetTcpPort("upstream_port") + +# ---- +# Setup ATS +# ---- +ts = Test.MakeATSProcess("ts", select_ports=True, enable_tls=True, enable_cache=False) + +# add ssl materials like key, certificates for the server +ts.addDefaultSSLFiles() + +ts.Disk.remap_config.AddLine( + 'map / http://127.0.0.1:{0}'.format(Test.Variables.upstream_port) +) +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.ssl.server.cert.path': '{0}'.format(ts.Variables.SSLDir), + 'proxy.config.ssl.server.private_key.path': '{0}'.format(ts.Variables.SSLDir), + 'proxy.config.diags.debug.enabled': 0, + # 'proxy.config.http2.initial_window_size_in': 2*16384, # Make a ludacrisly small window + 'proxy.config.diags.debug.tags': 'http', +}) + +big_post_body = "0123456789" * 231070 +big_post_body_file = open(os.path.join(Test.RunDirectory, "big_post_body"), "w") +big_post_body_file.write(big_post_body) +big_post_body_file.close() + +# First two cases we are using curl with no means to delay the post body. Even for the large body case, it looks like ATS processes the entire body before getting the response header +# The third case has an explicit multi-second sleep which ensures the early response path is exercised +test_run = Test.AddTestRun("http1.1 Post with small body early return") +test_run.Processes.Default.StartBefore(Test.Processes.ts) +test_run.Processes.Default.Command = '(nc -o output --sh-exec \'printf \"HTTP/1.1 420 Be Calm\r\nContent-Length: 0\r\n\r\n\"; sleep 1\' -l 127.0.0.1 {} & ) && curl -v -o /dev/null --http1.1 -d "small body" -k https://127.0.0.1:{}/post'.format( + Test.Variables.upstream_port, ts.Variables.ssl_port) +test_run.Processes.Default.Streams.All = Testers.ContainsExpression("HTTP/1.1 420 Be Calm", "Receive the early response") +test_run.StillRunningAfter = ts +test_run.Processes.Default.ReturnCode = 0 + +test_run = Test.AddTestRun("http1.1 Post with large body early return") +test_run.Processes.Default.Command = '(nc -o output2 --sh-exec \'printf \"HTTP/1.1 420 Be Calm\r\nContent-Length: 0\r\n\r\n\"; sleep 1\' -l 127.0.0.1 {} & ) && curl -H "Expect:" -v -o /dev/null --http1.1 -d @big_post_body -k https://127.0.0.1:{}/post'.format(Test.Variables.upstream_port, + ts.Variables.ssl_port) +test_run.Processes.Default.Streams.All = Testers.ContainsExpression("HTTP/1.1 420 Be Calm", "Receive the early response") +test_run.StillRunningAfter = ts +test_run.Processes.Default.ReturnCode = 0 + +test_run = Test.AddTestRun("http2 Post with large body, small window and early return") +test_run.Processes.Default.Command = '(nc -o output2 --sh-exec \'printf \"HTTP/1.1 420 Be Calm\r\nContent-Length: 0\r\n\r\n\"; sleep 1\' -l 127.0.0.1 {} & ) && curl -v -o /dev/null --http2 -d @big_post_body -k https://127.0.0.1:{}/post-http2'.format( + Test.Variables.upstream_port, ts.Variables.ssl_port) +test_run.Processes.Default.Streams.All = Testers.ContainsExpression("HTTP/2 420", "Receive the early response") +test_run.StillRunningAfter = ts +test_run.Processes.Default.ReturnCode = 0 + +client_out = Test.Disk.File("clientout") +client_out.Content = Testers.ExcludesExpression("0123456789", "The delayed body is not sent") +client_out.Content += Testers.ContainsExpression("HTTP/1.1 420 Be Calm", "Receive the early response") +client_out.Content += Testers.ContainsExpression("Connection: close", "ATS marks the client connection to close") + +client_out2 = Test.Disk.File("clientout2") +client_out2.Content = Testers.ExcludesExpression("0123456789", "The delayed body is not sent") +client_out2.Content += Testers.ContainsExpression("HTTP/1.1 420 Be Calm", "Receive the early response") +client_out2.Content += Testers.ContainsExpression("Connection: close", "ATS marks the client connection to close") + +client_out3 = Test.Disk.File("clientout3") +client_out3.Content = Testers.ExcludesExpression("0123456789", "The delayed body is not sent") +client_out3.Content += Testers.ContainsExpression("HTTP/1.1 420 Be Calm", "Receive the early response") +client_out3.Content += Testers.ContainsExpression("Connection: close", "ATS marks the client connection to close") + +test_run = Test.AddTestRun("http1.1 Post with paused body") +test_run.Processes.Default.Command = '(nc -o output3 --sh-exec \'printf \"HTTP/1.1 420 Be Calm\r\nContent-Length: 0\r\n\r\n\"; sleep 1\' -l 127.0.0.1 {} & ) && nc -o clientout --sh-exec \' printf \"POST /post HTTP/1.1\r\nHost: bob\r\nContent-Length: 20\r\n\r\n1234567890\"; sleep 4; printf \"0123456789\"\' 127.0.0.1 {}'.format(Test.Variables.upstream_port, + ts.Variables.port) +test_run.StillRunningAfter = ts +test_run.Processes.Default.ReturnCode = 0 + +test_run = Test.AddTestRun("http1.1 Post with delayed and paused body") +test_run.Processes.Default.Command = '(nc -o output3 --sh-exec \'printf \"HTTP/1.1 420 Be Calm\r\nContent-Length: 0\r\n\r\n\"; sleep 1\' -l 127.0.0.1 {} & ) && nc -o clientout3 --sh-exec \' printf \"POST /post HTTP/1.1\r\nHost: bob\r\nContent-Length: 20\r\n\r\n\"; sleep 1; printf \"1234567890\"; sleep 4; printf \"0123456789\"\' 127.0.0.1 {}'.format(Test.Variables.upstream_port, + ts.Variables.port) +test_run.StillRunningAfter = ts +test_run.Processes.Default.ReturnCode = 0 + +test_run = Test.AddTestRun("http1.1 Post with paused body and no delay on server") +test_run.Processes.Default.Command = '(nc -o output4 --sh-exec \'printf \"HTTP/1.1 420 Be Calm\r\nContent-Length: 0\r\n\r\n\"\' -l 127.0.0.1 {} & ) && nc -o clientout2 --sh-exec \' printf \"POST /post HTTP/1.1\r\nHost: bob\r\nContent-Length: 20\r\n\r\n1234567890\"; sleep 4; printf \"0123456789\"\' 127.0.0.1 {}'.format(Test.Variables.upstream_port, + ts.Variables.port) +test_run.StillRunningAfter = ts +test_run.Processes.Default.ReturnCode = 0