From 4deb7cd9658576b55b91983119bb3ef48bdb749e Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Mon, 6 Jan 2020 12:23:00 +0900 Subject: [PATCH 01/19] Reduce process duration of test_Http2FrequencyCounter (cherry picked from commit 0ad851937e66351b2dbee640678b3f0b9e157da8) --- proxy/http2/Http2FrequencyCounter.cc | 8 +- proxy/http2/Http2FrequencyCounter.h | 3 + .../unit_tests/test_Http2FrequencyCounter.cc | 102 +++++++++--------- 3 files changed, 62 insertions(+), 51 deletions(-) diff --git a/proxy/http2/Http2FrequencyCounter.cc b/proxy/http2/Http2FrequencyCounter.cc index dfe08b98507..9fab3e6acc6 100644 --- a/proxy/http2/Http2FrequencyCounter.cc +++ b/proxy/http2/Http2FrequencyCounter.cc @@ -26,7 +26,7 @@ void Http2FrequencyCounter::increment(uint16_t amount) { - ink_hrtime hrtime_sec = ink_hrtime_to_sec(Thread::get_hrtime()); + ink_hrtime hrtime_sec = this->_get_hrtime(); uint8_t counter_index = ((hrtime_sec % 60) >= 30); uint8_t last_index = ((this->_last_update % 60) >= 30); @@ -53,3 +53,9 @@ Http2FrequencyCounter::get_count() { return this->_count[0] + this->_count[1]; } + +ink_hrtime +Http2FrequencyCounter::_get_hrtime() +{ + return ink_hrtime_to_sec(Thread::get_hrtime()); +} diff --git a/proxy/http2/Http2FrequencyCounter.h b/proxy/http2/Http2FrequencyCounter.h index 9d2ed73b884..0b6de174afc 100644 --- a/proxy/http2/Http2FrequencyCounter.h +++ b/proxy/http2/Http2FrequencyCounter.h @@ -35,4 +35,7 @@ class Http2FrequencyCounter protected: uint16_t _count[2] = {0}; ink_hrtime _last_update = 0; + +private: + virtual ink_hrtime _get_hrtime(); }; diff --git a/proxy/http2/unit_tests/test_Http2FrequencyCounter.cc b/proxy/http2/unit_tests/test_Http2FrequencyCounter.cc index a1c0487420d..b69d58f1ef9 100644 --- a/proxy/http2/unit_tests/test_Http2FrequencyCounter.cc +++ b/proxy/http2/unit_tests/test_Http2FrequencyCounter.cc @@ -29,12 +29,22 @@ class TestHttp2FrequencyCounter : public Http2FrequencyCounter { public: void - set_internal_state(ink_hrtime last_update_sec, uint16_t count_0, uint16_t count_1) + set_internal_state(ink_hrtime now, ink_hrtime last_update_sec, uint16_t count_0, uint16_t count_1) { + this->_now = now; this->_last_update = last_update_sec; this->_count[0] = count_0; this->_count[1] = count_1; } + +private: + ink_hrtime + _get_hrtime() override + { + return this->_now; + } + + ink_hrtime _now = 0; }; TEST_CASE("Http2FrequencyCounter_basic", "[http2][Http2FrequencyCounter]") @@ -49,47 +59,45 @@ TEST_CASE("Http2FrequencyCounter_basic", "[http2][Http2FrequencyCounter]") counter.increment(2); REQUIRE(counter.get_count() == 3); - counter.set_internal_state(ink_hrtime_to_sec(Thread::get_hrtime()) - 10, 1, 2); + ink_hrtime now = ink_hrtime_to_sec(Thread::get_hrtime_updated()); + counter.set_internal_state(now, now - 10, 1, 2); REQUIRE(counter.get_count() == 3); } SECTION("Update at 0") { ink_hrtime now = ink_hrtime_to_sec(Thread::get_hrtime_updated()); - while (now % 60 != 0) { - sleep(1); - now = ink_hrtime_to_sec(Thread::get_hrtime_updated()); - } + now -= now % 60; - counter.set_internal_state(now - 5, 1, 2); + counter.set_internal_state(now, now - 5, 1, 2); counter.increment(); CHECK(counter.get_count() == 3); - counter.set_internal_state(now - 10, 1, 2); + counter.set_internal_state(now, now - 10, 1, 2); counter.increment(); CHECK(counter.get_count() == 3); - counter.set_internal_state(now - 20, 1, 2); + counter.set_internal_state(now, now - 20, 1, 2); counter.increment(); CHECK(counter.get_count() == 3); - counter.set_internal_state(now - 30, 1, 2); + counter.set_internal_state(now, now - 30, 1, 2); counter.increment(); CHECK(counter.get_count() == 3); - counter.set_internal_state(now - 40, 1, 2); + counter.set_internal_state(now, now - 40, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 50, 1, 2); + counter.set_internal_state(now, now - 50, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 60, 1, 2); + counter.set_internal_state(now, now - 60, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 70, 1, 2); + counter.set_internal_state(now, now - 70, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); } @@ -97,40 +105,38 @@ TEST_CASE("Http2FrequencyCounter_basic", "[http2][Http2FrequencyCounter]") SECTION("Update at 10") { ink_hrtime now = ink_hrtime_to_sec(Thread::get_hrtime_updated()); - while (now % 60 != 10) { - sleep(1); - now = ink_hrtime_to_sec(Thread::get_hrtime_updated()); - } + now -= now % 60; + now += 10; - counter.set_internal_state(now - 5, 1, 2); + counter.set_internal_state(now, now - 5, 1, 2); counter.increment(); CHECK(counter.get_count() == 4); - counter.set_internal_state(now - 10, 1, 2); + counter.set_internal_state(now, now - 10, 1, 2); counter.increment(); CHECK(counter.get_count() == 4); - counter.set_internal_state(now - 20, 1, 2); + counter.set_internal_state(now, now - 20, 1, 2); counter.increment(); CHECK(counter.get_count() == 3); - counter.set_internal_state(now - 30, 1, 2); + counter.set_internal_state(now, now - 30, 1, 2); counter.increment(); CHECK(counter.get_count() == 3); - counter.set_internal_state(now - 40, 1, 2); + counter.set_internal_state(now, now - 40, 1, 2); counter.increment(); CHECK(counter.get_count() == 3); - counter.set_internal_state(now - 50, 1, 2); + counter.set_internal_state(now, now - 50, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 60, 1, 2); + counter.set_internal_state(now, now - 60, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 70, 1, 2); + counter.set_internal_state(now, now - 70, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); } @@ -138,40 +144,38 @@ TEST_CASE("Http2FrequencyCounter_basic", "[http2][Http2FrequencyCounter]") SECTION("Update at 30") { ink_hrtime now = ink_hrtime_to_sec(Thread::get_hrtime_updated()); - while (now % 60 != 30) { - sleep(1); - now = ink_hrtime_to_sec(Thread::get_hrtime_updated()); - } + now -= now % 60; + now += 30; - counter.set_internal_state(now - 5, 1, 2); + counter.set_internal_state(now, now - 5, 1, 2); counter.increment(); CHECK(counter.get_count() == 2); - counter.set_internal_state(now - 10, 1, 2); + counter.set_internal_state(now, now - 10, 1, 2); counter.increment(); CHECK(counter.get_count() == 2); - counter.set_internal_state(now - 20, 1, 2); + counter.set_internal_state(now, now - 20, 1, 2); counter.increment(); CHECK(counter.get_count() == 2); - counter.set_internal_state(now - 30, 1, 2); + counter.set_internal_state(now, now - 30, 1, 2); counter.increment(); CHECK(counter.get_count() == 2); - counter.set_internal_state(now - 40, 1, 2); + counter.set_internal_state(now, now - 40, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 50, 1, 2); + counter.set_internal_state(now, now - 50, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 60, 1, 2); + counter.set_internal_state(now, now - 60, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 70, 1, 2); + counter.set_internal_state(now, now - 70, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); } @@ -179,40 +183,38 @@ TEST_CASE("Http2FrequencyCounter_basic", "[http2][Http2FrequencyCounter]") SECTION("Update at 40") { ink_hrtime now = ink_hrtime_to_sec(Thread::get_hrtime_updated()); - while (now % 60 != 40) { - sleep(1); - now = ink_hrtime_to_sec(Thread::get_hrtime_updated()); - } + now -= now % 60; + now += 40; - counter.set_internal_state(now - 5, 1, 2); + counter.set_internal_state(now, now - 5, 1, 2); counter.increment(); CHECK(counter.get_count() == 4); - counter.set_internal_state(now - 10, 1, 2); + counter.set_internal_state(now, now - 10, 1, 2); counter.increment(); CHECK(counter.get_count() == 4); - counter.set_internal_state(now - 20, 1, 2); + counter.set_internal_state(now, now - 20, 1, 2); counter.increment(); CHECK(counter.get_count() == 2); - counter.set_internal_state(now - 30, 1, 2); + counter.set_internal_state(now, now - 30, 1, 2); counter.increment(); CHECK(counter.get_count() == 2); - counter.set_internal_state(now - 40, 1, 2); + counter.set_internal_state(now, now - 40, 1, 2); counter.increment(); CHECK(counter.get_count() == 2); - counter.set_internal_state(now - 50, 1, 2); + counter.set_internal_state(now, now - 50, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 60, 1, 2); + counter.set_internal_state(now, now - 60, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); - counter.set_internal_state(now - 70, 1, 2); + counter.set_internal_state(now, now - 70, 1, 2); counter.increment(); CHECK(counter.get_count() == 1); } From ef63035dc7e22a03adc870e572684ac27ab3cbbc Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Thu, 7 Feb 2019 12:38:24 +0900 Subject: [PATCH 02/19] Add history to HTTP/2 (cherry picked from commit 84d59dc083a37a8b98d446c81fc2853bb131a11d) Conflicts: proxy/http2/Http2ClientSession.cc proxy/http2/Http2Stream.cc --- proxy/http2/Http2ClientSession.cc | 16 ++++++++++++++++ proxy/http2/Http2ClientSession.h | 6 ++++++ proxy/http2/Http2ConnectionState.cc | 25 ++++++++++++++++++++++--- proxy/http2/Http2Stream.cc | 12 ++++++++++++ proxy/http2/Http2Stream.h | 3 +++ 5 files changed, 59 insertions(+), 3 deletions(-) diff --git a/proxy/http2/Http2ClientSession.cc b/proxy/http2/Http2ClientSession.cc index cddc4ec21f0..e7776e3b036 100644 --- a/proxy/http2/Http2ClientSession.cc +++ b/proxy/http2/Http2ClientSession.cc @@ -25,8 +25,14 @@ #include "HttpDebugNames.h" #include "tscore/ink_base64.h" +#define REMEMBER(e, r) \ + { \ + this->remember(MakeSourceLocation(), e, r); \ + } + #define STATE_ENTER(state_name, event) \ do { \ + REMEMBER(event, this->recursion) \ SsnDebug(this, "http2_cs", "[%" PRId64 "] [%s, %s]", this->connection_id(), #state_name, \ HttpDebugNames::get_event_name(event)); \ } while (0) @@ -35,6 +41,7 @@ #define HTTP2_SET_SESSION_HANDLER(handler) \ do { \ + REMEMBER(NO_EVENT, this->recursion); \ this->session_handler = (handler); \ } while (0) @@ -65,6 +72,7 @@ Http2ClientSession::destroy() { if (!in_destroy) { in_destroy = true; + REMEMBER(NO_EVENT, this->recursion) Http2SsnDebug("session destroy"); // Let everyone know we are going down do_api_callout(TS_HTTP_SSN_CLOSE_HOOK); @@ -96,6 +104,7 @@ Http2ClientSession::free() return; } + REMEMBER(NO_EVENT, this->recursion) Http2SsnDebug("session free"); HTTP2_DECREMENT_THREAD_DYN_STAT(HTTP2_STAT_CURRENT_CLIENT_SESSION_COUNT, this->mutex->thread_holding); @@ -271,6 +280,7 @@ Http2ClientSession::do_io_shutdown(ShutdownHowTo_t howto) void Http2ClientSession::do_io_close(int alerrno) { + REMEMBER(NO_EVENT, this->recursion) Http2SsnDebug("session closed"); ink_assert(this->mutex->thread_holding == this_ethread()); @@ -621,6 +631,12 @@ Http2ClientSession::decrement_current_active_client_connections_stat() HTTP2_DECREMENT_THREAD_DYN_STAT(HTTP2_STAT_CURRENT_ACTIVE_CLIENT_CONNECTION_COUNT, this_ethread()); } +void +Http2ClientSession::remember(const SourceLocation &location, int event, int reentrant) +{ + this->_history.push_back(location, event, reentrant); +} + bool Http2ClientSession::_should_do_something_else() { diff --git a/proxy/http2/Http2ClientSession.h b/proxy/http2/Http2ClientSession.h index e8b43a55a86..ca8977be38c 100644 --- a/proxy/http2/Http2ClientSession.h +++ b/proxy/http2/Http2ClientSession.h @@ -29,6 +29,7 @@ #include "Http2ConnectionState.h" #include #include "tscore/ink_inet.h" +#include "tscore/History.h" // Name Edata Description // HTTP2_SESSION_EVENT_INIT Http2ClientSession * HTTP/2 session is born @@ -316,6 +317,9 @@ class Http2ClientSession : public ProxyClientSession return write_buffer->max_read_avail(); } + // Record history from Http2ConnectionState + void remember(const SourceLocation &location, int event, int reentrant = NO_REENTRANT); + // noncopyable Http2ClientSession(Http2ClientSession &) = delete; Http2ClientSession &operator=(const Http2ClientSession &) = delete; @@ -347,6 +351,8 @@ class Http2ClientSession : public ProxyClientSession IpEndpoint cached_client_addr; IpEndpoint cached_local_addr; + History _history; + // For Upgrade: h2c Http2UpgradeContext upgrade_context; diff --git a/proxy/http2/Http2ConnectionState.cc b/proxy/http2/Http2ConnectionState.cc index 5fc3a9ee325..f0e182321fa 100644 --- a/proxy/http2/Http2ConnectionState.cc +++ b/proxy/http2/Http2ConnectionState.cc @@ -26,9 +26,17 @@ #include "Http2ClientSession.h" #include "Http2Stream.h" #include "Http2DebugNames.h" +#include "HttpDebugNames.h" #include #include +#define REMEMBER(e, r) \ + { \ + if (this->ua_session) { \ + this->ua_session->remember(MakeSourceLocation(), e, r); \ + } \ + } + #define Http2ConDebug(ua_session, fmt, ...) \ SsnDebug(ua_session, "http2_con", "[%" PRId64 "] " fmt, ua_session->connection_id(), ##__VA_ARGS__); @@ -936,6 +944,7 @@ Http2ConnectionState::main_event_handler(int event, void *edata) case HTTP2_SESSION_EVENT_INIT: { ink_assert(this->ua_session == nullptr); this->ua_session = (Http2ClientSession *)edata; + REMEMBER(event, this->recursion); // [RFC 7540] 3.5. HTTP/2 Connection Preface. Upon establishment of a TCP connection and // determination that HTTP/2 will be used by both peers, each endpoint MUST @@ -961,6 +970,7 @@ Http2ConnectionState::main_event_handler(int event, void *edata) // Finalize HTTP/2 Connection case HTTP2_SESSION_EVENT_FINI: { SCOPED_MUTEX_LOCK(lock, this->mutex, this_ethread()); + REMEMBER(event, this->recursion); ink_assert(this->fini_received == false); this->fini_received = true; @@ -970,6 +980,7 @@ Http2ConnectionState::main_event_handler(int event, void *edata) } break; case HTTP2_SESSION_EVENT_XMIT: { + REMEMBER(event, this->recursion); SCOPED_MUTEX_LOCK(lock, this->mutex, this_ethread()); send_data_frames_depends_on_priority(); _scheduled = false; @@ -977,6 +988,7 @@ Http2ConnectionState::main_event_handler(int event, void *edata) // Parse received HTTP/2 frames case HTTP2_SESSION_EVENT_RECV: { + REMEMBER(event, this->recursion); const Http2Frame *frame = (Http2Frame *)edata; const Http2StreamId stream_id = frame->header().streamid; Http2Error error; @@ -1023,6 +1035,7 @@ Http2ConnectionState::main_event_handler(int event, void *edata) // Initiate a gracefull shutdown case HTTP2_SESSION_EVENT_SHUTDOWN_INIT: { + REMEMBER(event, this->recursion); ink_assert(shutdown_state == HTTP2_SHUTDOWN_NOT_INITIATED); shutdown_state = HTTP2_SHUTDOWN_INITIATED; // [RFC 7540] 6.8. GOAWAY @@ -1036,6 +1049,7 @@ Http2ConnectionState::main_event_handler(int event, void *edata) // Continue a gracefull shutdown case HTTP2_SESSION_EVENT_SHUTDOWN_CONT: { + REMEMBER(event, this->recursion); ink_assert(shutdown_state == HTTP2_SHUTDOWN_INITIATED); shutdown_cont_event = nullptr; shutdown_state = HTTP2_SHUTDOWN_IN_PROGRESS; @@ -1072,8 +1086,10 @@ Http2ConnectionState::main_event_handler(int event, void *edata) } int -Http2ConnectionState::state_closed(int /* event */, void *edata) +Http2ConnectionState::state_closed(int event, void *edata) { + REMEMBER(event, this->recursion); + if (edata == zombie_event) { // Zombie session is still around. Assert! ink_release_assert(zombie_event == nullptr); @@ -1257,6 +1273,7 @@ Http2ConnectionState::delete_stream(Http2Stream *stream) } Http2StreamDebug(ua_session, stream->get_id(), "Delete stream"); + REMEMBER(NO_EVENT, this->recursion); if (Http2::stream_priority_enabled) { Http2DependencyTree::Node *node = stream->priority_node; @@ -1298,6 +1315,8 @@ Http2ConnectionState::delete_stream(Http2Stream *stream) void Http2ConnectionState::release_stream(Http2Stream *stream) { + REMEMBER(NO_EVENT, this->recursion) + if (stream) { // Decrement total_client_streams_count here, because it's a counter include streams in the process of shutting down. // Other counters (client_streams_in_count/client_streams_out_count) are already decremented in delete_stream(). @@ -1837,6 +1856,8 @@ Http2ConnectionState::send_ping_frame(Http2StreamId id, uint8_t flag, const uint void Http2ConnectionState::send_goaway_frame(Http2StreamId id, Http2ErrorCode ec) { + ink_assert(this->ua_session != nullptr); + Http2ConDebug(ua_session, "Send GOAWAY frame, last_stream_id: %d", id); if (ec != Http2ErrorCode::HTTP2_ERROR_NO_ERROR) { @@ -1846,8 +1867,6 @@ Http2ConnectionState::send_goaway_frame(Http2StreamId id, Http2ErrorCode ec) Http2Frame frame(HTTP2_FRAME_TYPE_GOAWAY, 0, 0); Http2Goaway goaway; - ink_assert(this->ua_session != nullptr); - goaway.last_streamid = id; goaway.error_code = ec; diff --git a/proxy/http2/Http2Stream.cc b/proxy/http2/Http2Stream.cc index 5af0ef125c7..66c8a1d6ba9 100644 --- a/proxy/http2/Http2Stream.cc +++ b/proxy/http2/Http2Stream.cc @@ -28,6 +28,11 @@ #include +#define REMEMBER(e, r) \ + { \ + this->_history.push_back(MakeSourceLocation(), e, r); \ + } + #define Http2StreamDebug(fmt, ...) \ SsnDebug(parent, "http2_stream", "[%" PRId64 "] [%u] " fmt, parent->connection_id(), this->get_id(), ##__VA_ARGS__); @@ -37,6 +42,7 @@ int Http2Stream::main_event_handler(int event, void *edata) { SCOPED_MUTEX_LOCK(lock, this->mutex, this_ethread()); + REMEMBER(event, this->reentrancy_count); if (!this->_switch_thread_if_not_on_right_thread(event, edata)) { // Not on the right thread @@ -325,6 +331,7 @@ Http2Stream::do_io_close(int /* flags */) super::release(nullptr); if (!closed) { + REMEMBER(NO_EVENT, this->reentrancy_count); Http2StreamDebug("do_io_close"); // When we get here, the SM has initiated the shutdown. Either it received a WRITE_COMPLETE, or it is shutting down. Any @@ -376,6 +383,8 @@ void Http2Stream::terminate_if_possible() { if (terminate_stream && reentrancy_count == 0) { + REMEMBER(NO_EVENT, this->reentrancy_count); + Http2ClientSession *h2_parent = static_cast(parent); SCOPED_MUTEX_LOCK(lock, h2_parent->connection_state.mutex, this_ethread()); h2_parent->connection_state.delete_stream(this); @@ -389,6 +398,7 @@ Http2Stream::initiating_close() { if (!closed) { SCOPED_MUTEX_LOCK(lock, this->mutex, this_ethread()); + REMEMBER(NO_EVENT, this->reentrancy_count); Http2StreamDebug("initiating_close"); // Set the state of the connection to closed @@ -457,6 +467,7 @@ Http2Stream::send_tracked_event(Event *event, int send_event, VIO *vio) } if (event == nullptr) { + REMEMBER(send_event, this->reentrancy_count); event = this_ethread()->schedule_imm(this, send_event, vio); } @@ -702,6 +713,7 @@ Http2Stream::reenable(VIO *vio) void Http2Stream::destroy() { + REMEMBER(NO_EVENT, this->reentrancy_count); Http2StreamDebug("Destroy stream, sent %" PRIu64 " bytes", this->bytes_sent); SCOPED_MUTEX_LOCK(lock, this->mutex, this_ethread()); // Clean up after yourself if this was an EOS diff --git a/proxy/http2/Http2Stream.h b/proxy/http2/Http2Stream.h index 3be1057a584..6f65f6c57a3 100644 --- a/proxy/http2/Http2Stream.h +++ b/proxy/http2/Http2Stream.h @@ -28,6 +28,7 @@ #include "Http2DebugNames.h" #include "../http/HttpTunnel.h" // To get ChunkedHandler #include "Http2DependencyTree.h" +#include "tscore/History.h" class Http2Stream; class Http2ConnectionState; @@ -246,6 +247,8 @@ class Http2Stream : public ProxyClientTransaction VIO read_vio; VIO write_vio; + History _history; + bool trailing_header = false; bool chunked = false; From c7ea72c5c4910fc1e1a04fd12fde4b2135d3120b Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Fri, 14 Jun 2019 09:23:26 +0900 Subject: [PATCH 03/19] HTTP/2: increment write_vio.ndone by consumed size (cherry picked from commit d3639e0f98d319f77a6fbd4ced5465578d64ad87) --- proxy/http2/Http2Stream.cc | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/proxy/http2/Http2Stream.cc b/proxy/http2/Http2Stream.cc index 66c8a1d6ba9..5d17881319b 100644 --- a/proxy/http2/Http2Stream.cc +++ b/proxy/http2/Http2Stream.cc @@ -593,8 +593,8 @@ Http2Stream::update_write_request(IOBufferReader *buf_reader, int64_t write_len, // Still parsing the response_header int bytes_used = 0; int state = this->response_header.parse_resp(&http_parser, this->response_reader, &bytes_used, false); - // HTTPHdr::parse_resp() consumed the response_reader in above - write_vio.ndone += this->response_header.length_get(); + // HTTPHdr::parse_resp() consumed the response_reader in above (consumed size is `bytes_used`) + write_vio.ndone += bytes_used; switch (state) { case PARSE_RESULT_DONE: { From 63a0ebe99eef9c0b40b1de5941726cec7f3d7d35 Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Fri, 14 Jun 2019 09:39:48 +0900 Subject: [PATCH 04/19] HTTP/2: cancel reading buffer when ATS received GOAWAY (cherry picked from commit 204749518b8265ecf466187ccdf6b6f881d9724f) Conflicts: proxy/http2/Http2ClientSession.cc --- proxy/http2/Http2ClientSession.cc | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/proxy/http2/Http2ClientSession.cc b/proxy/http2/Http2ClientSession.cc index e7776e3b036..cab22ee75df 100644 --- a/proxy/http2/Http2ClientSession.cc +++ b/proxy/http2/Http2ClientSession.cc @@ -566,8 +566,9 @@ Http2ClientSession::state_process_frame_read(int event, VIO *vio, bool inside_fr } while (this->sm_reader->read_avail() >= (int64_t)HTTP2_FRAME_HEADER_LEN) { - // Cancel reading if there was an error - if (connection_state.tx_error_code.code != static_cast(Http2ErrorCode::HTTP2_ERROR_NO_ERROR)) { + // Cancel reading if there was an error or connection is closed + if (connection_state.tx_error_code.code != static_cast(Http2ErrorCode::HTTP2_ERROR_NO_ERROR) || + connection_state.is_state_closed()) { Http2SsnDebug("reading a frame has been canceled (%u)", connection_state.tx_error_code.code); break; } From 1255a275d71bb1e62e1c50d59193c3ec00488bf4 Mon Sep 17 00:00:00 2001 From: Masakazu Kitajo Date: Wed, 3 Jul 2019 11:04:57 +0900 Subject: [PATCH 05/19] Separate out common header compression logic to hdrs directory (cherry picked from commit eb87569fd9743658c224be4ece93d4462bb2d630) Conflicts: .gitignore proxy/hdrs/Makefile.am proxy/http2/HPACK.cc --- .gitignore | 2 +- proxy/{http2 => hdrs}/HuffmanCodec.cc | 0 proxy/{http2 => hdrs}/HuffmanCodec.h | 0 proxy/hdrs/Makefile.am | 21 ++- proxy/hdrs/XPACK.cc | 202 ++++++++++++++++++++ proxy/hdrs/XPACK.h | 37 ++++ proxy/{http2 => hdrs}/test_Huffmancode.cc | 0 proxy/http2/HPACK.cc | 215 +++------------------- proxy/http2/HPACK.h | 5 +- proxy/http2/HTTP2.cc | 1 - proxy/http2/Makefile.am | 17 +- proxy/http2/RegressionHPACK.cc | 18 +- 12 files changed, 295 insertions(+), 223 deletions(-) rename proxy/{http2 => hdrs}/HuffmanCodec.cc (100%) rename proxy/{http2 => hdrs}/HuffmanCodec.h (100%) create mode 100644 proxy/hdrs/XPACK.cc create mode 100644 proxy/hdrs/XPACK.h rename proxy/{http2 => hdrs}/test_Huffmancode.cc (100%) diff --git a/.gitignore b/.gitignore index 10a0d15df99..fd3dd118cde 100644 --- a/.gitignore +++ b/.gitignore @@ -97,8 +97,8 @@ iocore/eventsystem/test_MIOBufferWriter iocore/hostdb/test_RefCountCache proxy/hdrs/test_mime +proxy/hdrs/test_Huffmancode proxy/http/test_ForwardedConfig -proxy/http2/test_Huffmancode proxy/http2/test_Http2DependencyTree proxy/http2/test_Http2FrequencyCounter proxy/http2/test_HPACK diff --git a/proxy/http2/HuffmanCodec.cc b/proxy/hdrs/HuffmanCodec.cc similarity index 100% rename from proxy/http2/HuffmanCodec.cc rename to proxy/hdrs/HuffmanCodec.cc diff --git a/proxy/http2/HuffmanCodec.h b/proxy/hdrs/HuffmanCodec.h similarity index 100% rename from proxy/http2/HuffmanCodec.h rename to proxy/hdrs/HuffmanCodec.h diff --git a/proxy/hdrs/Makefile.am b/proxy/hdrs/Makefile.am index 42dad696a94..15c0265d07c 100644 --- a/proxy/hdrs/Makefile.am +++ b/proxy/hdrs/Makefile.am @@ -43,7 +43,11 @@ libhdrs_a_SOURCES = \ MIME.cc \ MIME.h \ URL.cc \ - URL.h + URL.h \ + HuffmanCodec.cc \ + HuffmanCodec.h \ + XPACK.cc \ + XPACK.h if BUILD_TESTS libhdrs_a_SOURCES += \ @@ -62,9 +66,11 @@ load_http_hdr_LDADD = -L. -lhdrs \ $(top_builddir)/src/tscpp/util/libtscpputil.la \ @LIBTCL@ -check_PROGRAMS = test_mime +check_PROGRAMS = \ + test_mime \ + test_Huffmancode -TESTS = test_mime +TESTS = $(check_PROGRAMS) test_mime_LDADD = -L. -lhdrs \ $(top_builddir)/src/tscore/libtscore.la \ @@ -78,6 +84,15 @@ test_mime_LDADD = -L. -lhdrs \ test_mime_SOURCES = test_mime.cc +test_Huffmancode_LDADD = \ + $(top_builddir)/src/tscore/libtscore.la \ + $(top_builddir)/src/tscpp/util/libtscpputil.la + +test_Huffmancode_SOURCES = \ + test_Huffmancode.cc \ + HuffmanCodec.cc \ + HuffmanCodec.h + #test_UNUSED_SOURCES = \ # test_urlhash.cc diff --git a/proxy/hdrs/XPACK.cc b/proxy/hdrs/XPACK.cc new file mode 100644 index 00000000000..e987479b933 --- /dev/null +++ b/proxy/hdrs/XPACK.cc @@ -0,0 +1,202 @@ +/** @file + + Common functions for HPACK and QPACK + + @section license License + + 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. + */ + +#include "tscore/Arena.h" +#include "tscore/ink_memory.h" +#include "XPACK.h" +#include "HuffmanCodec.h" + +// +// [RFC 7541] 5.1. Integer representation +// +int64_t +xpack_decode_integer(uint64_t &dst, const uint8_t *buf_start, const uint8_t *buf_end, uint8_t n) +{ + if (buf_start >= buf_end) { + return XPACK_ERROR_COMPRESSION_ERROR; + } + + const uint8_t *p = buf_start; + + dst = (*p & ((1 << n) - 1)); + if (dst == static_cast(1 << n) - 1) { + int m = 0; + do { + if (++p >= buf_end) { + return XPACK_ERROR_COMPRESSION_ERROR; + } + + uint64_t added_value = *p & 0x7f; + if ((UINT64_MAX >> m) < added_value) { + // Excessively large integer encodings - in value or octet + // length - MUST be treated as a decoding error. + return XPACK_ERROR_COMPRESSION_ERROR; + } + dst += added_value << m; + m += 7; + } while (*p & 0x80); + } + + return p - buf_start + 1; +} + +// +// [RFC 7541] 5.2. String Literal Representation +// return content from String Data (Length octets) with huffman decoding if it is encoded +// +int64_t +xpack_decode_string(Arena &arena, char **str, uint64_t &str_length, const uint8_t *buf_start, const uint8_t *buf_end, uint8_t n) +{ + if (buf_start >= buf_end) { + return XPACK_ERROR_COMPRESSION_ERROR; + } + + const uint8_t *p = buf_start; + bool isHuffman = *p & (0x01 << n); + uint64_t encoded_string_len = 0; + int64_t len = 0; + + len = xpack_decode_integer(encoded_string_len, p, buf_end, n); + if (len == XPACK_ERROR_COMPRESSION_ERROR) { + return XPACK_ERROR_COMPRESSION_ERROR; + } + p += len; + + if ((p + encoded_string_len) > buf_end) { + return XPACK_ERROR_COMPRESSION_ERROR; + } + + if (isHuffman) { + // Allocate temporary area twice the size of before decoded data + *str = arena.str_alloc(encoded_string_len * 2); + + len = huffman_decode(*str, p, encoded_string_len); + if (len < 0) { + return XPACK_ERROR_COMPRESSION_ERROR; + } + str_length = len; + } else { + *str = arena.str_alloc(encoded_string_len); + + memcpy(*str, reinterpret_cast(p), encoded_string_len); + + str_length = encoded_string_len; + } + + return p + encoded_string_len - buf_start; +} + +// +// [RFC 7541] 5.1. Integer representation +// +int64_t +xpack_encode_integer(uint8_t *buf_start, const uint8_t *buf_end, uint64_t value, uint8_t n) +{ + if (buf_start >= buf_end) { + return -1; + } + + uint8_t *p = buf_start; + + // Preserve the first n bits + uint8_t prefix = *buf_start & (0xFF << n); + + if (value < (static_cast(1 << n) - 1)) { + *(p++) = value; + } else { + *(p++) = (1 << n) - 1; + value -= (1 << n) - 1; + while (value >= 128) { + if (p >= buf_end) { + return -1; + } + *(p++) = (value & 0x7F) | 0x80; + value = value >> 7; + } + if (p + 1 >= buf_end) { + return -1; + } + *(p++) = value; + } + + // Restore the prefix + *buf_start |= prefix; + + return p - buf_start; +} + +int64_t +xpack_encode_string(uint8_t *buf_start, const uint8_t *buf_end, const char *value, uint64_t value_len, uint8_t n) +{ + uint8_t *p = buf_start; + bool use_huffman = true; + char *data = nullptr; + int64_t data_len = 0; + + // TODO Choose whether to use Huffman encoding wisely + // cppcheck-suppress knownConditionTrueFalse; leaving "use_huffman" for wise huffman usage in the future + if (use_huffman && value_len) { + data = static_cast(ats_malloc(value_len * 4)); + if (data == nullptr) { + return -1; + } + data_len = huffman_encode(reinterpret_cast(data), reinterpret_cast(value), value_len); + } + + // Length + const int64_t len = xpack_encode_integer(p, buf_end, data_len, n); + if (len == -1) { + if (use_huffman) { + ats_free(data); + } + + return -1; + } + + if (use_huffman) { + *p |= 0x01 << n; + } else { + *p &= ~(0x01 << n); + } + p += len; + + if (buf_end < p || buf_end - p < data_len) { + if (use_huffman) { + ats_free(data); + } + + return -1; + } + + // Value + if (data_len) { + memcpy(p, data, data_len); + p += data_len; + } + + if (use_huffman) { + ats_free(data); + } + + return p - buf_start; +} diff --git a/proxy/hdrs/XPACK.h b/proxy/hdrs/XPACK.h new file mode 100644 index 00000000000..70814a512b0 --- /dev/null +++ b/proxy/hdrs/XPACK.h @@ -0,0 +1,37 @@ +/** @file + * + * A brief file description + * + * @section license License + * + * 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. + */ + +#pragma once + +#include +#include "tscore/Arena.h" + +const static int XPACK_ERROR_COMPRESSION_ERROR = -1; +const static int XPACK_ERROR_SIZE_EXCEEDED_ERROR = -2; + +// These primitives are shared with HPACK and QPACK. +int64_t xpack_encode_integer(uint8_t *buf_start, const uint8_t *buf_end, uint64_t value, uint8_t n); +int64_t xpack_decode_integer(uint64_t &dst, const uint8_t *buf_start, const uint8_t *buf_end, uint8_t n); +int64_t xpack_encode_string(uint8_t *buf_start, const uint8_t *buf_end, const char *value, uint64_t value_len, uint8_t n = 7); +int64_t xpack_decode_string(Arena &arena, char **str, uint64_t &str_length, const uint8_t *buf_start, const uint8_t *buf_end, + uint8_t n = 7); diff --git a/proxy/http2/test_Huffmancode.cc b/proxy/hdrs/test_Huffmancode.cc similarity index 100% rename from proxy/http2/test_Huffmancode.cc rename to proxy/hdrs/test_Huffmancode.cc diff --git a/proxy/http2/HPACK.cc b/proxy/http2/HPACK.cc index 80b4c06cbff..b13e7c6b127 100644 --- a/proxy/http2/HPACK.cc +++ b/proxy/http2/HPACK.cc @@ -472,92 +472,6 @@ HpackDynamicTable::_mime_hdr_gc() } } -// -// [RFC 7541] 5.1. Integer representation -// -int64_t -encode_integer(uint8_t *buf_start, const uint8_t *buf_end, uint32_t value, uint8_t n) -{ - if (buf_start >= buf_end) { - return -1; - } - - uint8_t *p = buf_start; - - if (value < (static_cast(1 << n) - 1)) { - *(p++) = value; - } else { - *(p++) = (1 << n) - 1; - value -= (1 << n) - 1; - while (value >= 128) { - if (p >= buf_end) { - return -1; - } - *(p++) = (value & 0x7F) | 0x80; - value = value >> 7; - } - if (p + 1 >= buf_end) { - return -1; - } - *(p++) = value; - } - return p - buf_start; -} - -int64_t -encode_string(uint8_t *buf_start, const uint8_t *buf_end, const char *value, size_t value_len) -{ - uint8_t *p = buf_start; - bool use_huffman = true; - char *data = nullptr; - int64_t data_len = 0; - - // TODO Choose whether to use Huffman encoding wisely - - if (use_huffman && value_len) { - data = static_cast(ats_malloc(value_len * 4)); - if (data == nullptr) { - return -1; - } - data_len = huffman_encode(reinterpret_cast(data), reinterpret_cast(value), value_len); - } - - // Length - const int64_t len = encode_integer(p, buf_end, data_len, 7); - if (len == -1) { - if (use_huffman) { - ats_free(data); - } - - return -1; - } - - if (use_huffman) { - *p |= 0x80; - } - p += len; - - if (buf_end < p || buf_end - p < data_len) { - if (use_huffman) { - ats_free(data); - } - - return -1; - } - - // Value - if (data_len) { - memcpy(p, data, data_len); - p += data_len; - } - - if (use_huffman) { - ats_free(data); - } - - return p - buf_start; -} - int64_t encode_indexed_header_field(uint8_t *buf_start, const uint8_t *buf_end, uint32_t index) { @@ -568,7 +482,7 @@ encode_indexed_header_field(uint8_t *buf_start, const uint8_t *buf_end, uint32_t uint8_t *p = buf_start; // Index - const int64_t len = encode_integer(p, buf_end, index, 7); + const int64_t len = xpack_encode_integer(p, buf_end, index, 7); if (len == -1) { return -1; } @@ -614,7 +528,8 @@ encode_literal_header_field_with_indexed_name(uint8_t *buf_start, const uint8_t } // Index - len = encode_integer(p, buf_end, index, prefix); + *p = 0; + len = xpack_encode_integer(p, buf_end, index, prefix); if (len == -1) { return -1; } @@ -629,7 +544,7 @@ encode_literal_header_field_with_indexed_name(uint8_t *buf_start, const uint8_t // Value String int value_len; const char *value = header.value_get(&value_len); - len = encode_string(p, buf_end, value, value_len); + len = xpack_encode_string(p, buf_end, value, value_len); if (len == -1) { return -1; } @@ -679,7 +594,7 @@ encode_literal_header_field_with_new_name(uint8_t *buf_start, const uint8_t *buf } // Name String - len = encode_string(p, buf_end, lower_name, name_len); + len = xpack_encode_string(p, buf_end, lower_name, name_len); if (len == -1) { return -1; } @@ -688,7 +603,7 @@ encode_literal_header_field_with_new_name(uint8_t *buf_start, const uint8_t *buf // Value String int value_len; const char *value = header.value_get(&value_len); - len = encode_string(p, buf_end, value, value_len); + len = xpack_encode_string(p, buf_end, value, value_len); if (len == -1) { return -1; } @@ -702,95 +617,15 @@ encode_literal_header_field_with_new_name(uint8_t *buf_start, const uint8_t *buf int64_t encode_dynamic_table_size_update(uint8_t *buf_start, const uint8_t *buf_end, uint32_t size) { - const int64_t len = encode_integer(buf_start, buf_end, size, 5); + buf_start[0] = 0x20; + const int64_t len = xpack_encode_integer(buf_start, buf_end, size, 5); if (len == -1) { return -1; } - buf_start[0] |= 0x20; return len; } -// -// [RFC 7541] 5.1. Integer representation -// -int64_t -decode_integer(uint32_t &dst, const uint8_t *buf_start, const uint8_t *buf_end, uint8_t n) -{ - if (buf_start >= buf_end) { - return HPACK_ERROR_COMPRESSION_ERROR; - } - - const uint8_t *p = buf_start; - - dst = (*p & ((1 << n) - 1)); - if (dst == static_cast(1 << n) - 1) { - int m = 0; - do { - if (++p >= buf_end) { - return HPACK_ERROR_COMPRESSION_ERROR; - } - - uint32_t added_value = *p & 0x7f; - if ((UINT32_MAX >> m) < added_value) { - // Excessively large integer encodings - in value or octet - // length - MUST be treated as a decoding error. - return HPACK_ERROR_COMPRESSION_ERROR; - } - dst += added_value << m; - m += 7; - } while (*p & 0x80); - } - - return p - buf_start + 1; -} - -// -// [RFC 7541] 5.2. String Literal Representation -// return content from String Data (Length octets) with huffman decoding if it is encoded -// -int64_t -decode_string(Arena &arena, char **str, uint32_t &str_length, const uint8_t *buf_start, const uint8_t *buf_end) -{ - if (buf_start >= buf_end) { - return HPACK_ERROR_COMPRESSION_ERROR; - } - - const uint8_t *p = buf_start; - bool isHuffman = *p & 0x80; - uint32_t encoded_string_len = 0; - int64_t len = 0; - - len = decode_integer(encoded_string_len, p, buf_end, 7); - if (len == HPACK_ERROR_COMPRESSION_ERROR) { - return HPACK_ERROR_COMPRESSION_ERROR; - } - p += len; - - if ((p + encoded_string_len) > buf_end) { - return HPACK_ERROR_COMPRESSION_ERROR; - } - - if (isHuffman) { - // Allocate temporary area twice the size of before decoded data - *str = arena.str_alloc(encoded_string_len * 2); - - len = huffman_decode(*str, p, encoded_string_len); - if (len < 0) { - return HPACK_ERROR_COMPRESSION_ERROR; - } - str_length = len; - } else { - *str = arena.str_alloc(encoded_string_len); - - memcpy(*str, reinterpret_cast(p), encoded_string_len); - - str_length = encoded_string_len; - } - - return p + encoded_string_len - buf_start; -} - // // [RFC 7541] 6.1. Indexed Header Field Representation // @@ -798,11 +633,11 @@ int64_t decode_indexed_header_field(MIMEFieldWrapper &header, const uint8_t *buf_start, const uint8_t *buf_end, HpackIndexingTable &indexing_table) { - uint32_t index = 0; + uint64_t index = 0; int64_t len = 0; - len = decode_integer(index, buf_start, buf_end, 7); - if (len == HPACK_ERROR_COMPRESSION_ERROR) { + len = xpack_decode_integer(index, buf_start, buf_end, 7); + if (len == XPACK_ERROR_COMPRESSION_ERROR) { return HPACK_ERROR_COMPRESSION_ERROR; } @@ -834,22 +669,22 @@ decode_literal_header_field(MIMEFieldWrapper &header, const uint8_t *buf_start, { const uint8_t *p = buf_start; bool isIncremental = false; - uint32_t index = 0; + uint64_t index = 0; int64_t len = 0; HpackField ftype = hpack_parse_field_type(*p); bool has_http2_violation = false; if (ftype == HpackField::INDEXED_LITERAL) { - len = decode_integer(index, p, buf_end, 6); + len = xpack_decode_integer(index, p, buf_end, 6); isIncremental = true; } else if (ftype == HpackField::NEVERINDEX_LITERAL) { - len = decode_integer(index, p, buf_end, 4); + len = xpack_decode_integer(index, p, buf_end, 4); } else { ink_assert(ftype == HpackField::NOINDEX_LITERAL); - len = decode_integer(index, p, buf_end, 4); + len = xpack_decode_integer(index, p, buf_end, 4); } - if (len == HPACK_ERROR_COMPRESSION_ERROR) { + if (len == XPACK_ERROR_COMPRESSION_ERROR) { return HPACK_ERROR_COMPRESSION_ERROR; } @@ -862,10 +697,10 @@ decode_literal_header_field(MIMEFieldWrapper &header, const uint8_t *buf_start, indexing_table.get_header_field(index, header); } else { char *name_str = nullptr; - uint32_t name_str_len = 0; + uint64_t name_str_len = 0; - len = decode_string(arena, &name_str, name_str_len, p, buf_end); - if (len == HPACK_ERROR_COMPRESSION_ERROR) { + len = xpack_decode_string(arena, &name_str, name_str_len, p, buf_end); + if (len == XPACK_ERROR_COMPRESSION_ERROR) { return HPACK_ERROR_COMPRESSION_ERROR; } @@ -884,10 +719,10 @@ decode_literal_header_field(MIMEFieldWrapper &header, const uint8_t *buf_start, // Decode header field value char *value_str = nullptr; - uint32_t value_str_len = 0; + uint64_t value_str_len = 0; - len = decode_string(arena, &value_str, value_str_len, p, buf_end); - if (len == HPACK_ERROR_COMPRESSION_ERROR) { + len = xpack_decode_string(arena, &value_str, value_str_len, p, buf_end); + if (len == XPACK_ERROR_COMPRESSION_ERROR) { return HPACK_ERROR_COMPRESSION_ERROR; } @@ -930,9 +765,9 @@ update_dynamic_table_size(const uint8_t *buf_start, const uint8_t *buf_end, Hpac } // Update header table size if its required. - uint32_t size = 0; - int64_t len = decode_integer(size, buf_start, buf_end, 5); - if (len == HPACK_ERROR_COMPRESSION_ERROR) { + uint64_t size = 0; + int64_t len = xpack_decode_integer(size, buf_start, buf_end, 5); + if (len == XPACK_ERROR_COMPRESSION_ERROR) { return HPACK_ERROR_COMPRESSION_ERROR; } diff --git a/proxy/http2/HPACK.h b/proxy/http2/HPACK.h index 5aa8ad5ac1c..f36c0c703aa 100644 --- a/proxy/http2/HPACK.h +++ b/proxy/http2/HPACK.h @@ -26,6 +26,7 @@ #include "tscore/ink_platform.h" #include "tscore/Diags.h" #include "HTTP.h" +#include "../hdrs/XPACK.h" #include @@ -154,10 +155,6 @@ class HpackIndexingTable }; // Low level interfaces -int64_t encode_integer(uint8_t *buf_start, const uint8_t *buf_end, uint32_t value, uint8_t n); -int64_t decode_integer(uint32_t &dst, const uint8_t *buf_start, const uint8_t *buf_end, uint8_t n); -int64_t encode_string(uint8_t *buf_start, const uint8_t *buf_end, const char *value, size_t value_len); -int64_t decode_string(Arena &arena, char **str, uint32_t &str_length, const uint8_t *buf_start, const uint8_t *buf_end); int64_t encode_indexed_header_field(uint8_t *buf_start, const uint8_t *buf_end, uint32_t index); int64_t encode_literal_header_field_with_indexed_name(uint8_t *buf_start, const uint8_t *buf_end, const MIMEFieldWrapper &header, uint32_t index, HpackIndexingTable &indexing_table, HpackField type); diff --git a/proxy/http2/HTTP2.cc b/proxy/http2/HTTP2.cc index a74415bb06b..2844c87fd55 100644 --- a/proxy/http2/HTTP2.cc +++ b/proxy/http2/HTTP2.cc @@ -23,7 +23,6 @@ #include "HTTP2.h" #include "HPACK.h" -#include "HuffmanCodec.h" #include "tscore/ink_assert.h" #include "records/P_RecCore.h" #include "records/P_RecProcess.h" diff --git a/proxy/http2/Makefile.am b/proxy/http2/Makefile.am index 7fe74800aeb..c0ae3abae05 100644 --- a/proxy/http2/Makefile.am +++ b/proxy/http2/Makefile.am @@ -50,9 +50,7 @@ libhttp2_a_SOURCES = \ Http2Stream.cc \ Http2Stream.h \ Http2SessionAccept.cc \ - Http2SessionAccept.h \ - HuffmanCodec.cc \ - HuffmanCodec.h + Http2SessionAccept.h if BUILD_TESTS libhttp2_a_SOURCES += \ @@ -60,26 +58,15 @@ libhttp2_a_SOURCES += \ endif check_PROGRAMS = \ - test_Huffmancode \ test_Http2DependencyTree \ test_Http2FrequencyCounter \ test_HPACK TESTS = \ - test_Huffmancode \ test_Http2DependencyTree \ test_Http2FrequencyCounter \ test_HPACK -test_Huffmancode_LDADD = \ - $(top_builddir)/src/tscore/libtscore.la \ - $(top_builddir)/src/tscpp/util/libtscpputil.la - -test_Huffmancode_SOURCES = \ - test_Huffmancode.cc \ - HuffmanCodec.cc \ - HuffmanCodec.h - test_Http2DependencyTree_LDADD = \ $(top_builddir)/src/tscore/libtscore.la \ $(top_builddir)/src/tscpp/util/libtscpputil.la @@ -117,8 +104,6 @@ test_HPACK_LDADD = \ test_HPACK_SOURCES = \ test_HPACK.cc \ - HuffmanCodec.cc \ - HuffmanCodec.h \ HPACK.cc \ HPACK.h diff --git a/proxy/http2/RegressionHPACK.cc b/proxy/http2/RegressionHPACK.cc index 7b2de58141a..77072276e8d 100644 --- a/proxy/http2/RegressionHPACK.cc +++ b/proxy/http2/RegressionHPACK.cc @@ -326,7 +326,7 @@ REGRESSION_TEST(HPACK_EncodeInteger)(RegressionTest *t, int, int *pstatus) for (const auto &i : integer_test_case) { memset(buf, 0, BUFSIZE_FOR_REGRESSION_TEST); - int len = encode_integer(buf, buf + BUFSIZE_FOR_REGRESSION_TEST, i.raw_integer, i.prefix); + int len = xpack_encode_integer(buf, buf + BUFSIZE_FOR_REGRESSION_TEST, i.raw_integer, i.prefix); box.check(len == i.encoded_field_len, "encoded length was %d, expecting %d", len, i.encoded_field_len); box.check(len > 0 && memcmp(buf, i.encoded_field, len) == 0, "encoded value was invalid"); @@ -345,7 +345,8 @@ REGRESSION_TEST(HPACK_EncodeString)(RegressionTest *t, int, int *pstatus) for (unsigned int i = 2; i < sizeof(string_test_case) / sizeof(string_test_case[0]); i++) { memset(buf, 0, BUFSIZE_FOR_REGRESSION_TEST); - len = encode_string(buf, buf + BUFSIZE_FOR_REGRESSION_TEST, string_test_case[i].raw_string, string_test_case[i].raw_string_len); + len = xpack_encode_string(buf, buf + BUFSIZE_FOR_REGRESSION_TEST, string_test_case[i].raw_string, + string_test_case[i].raw_string_len); box.check(len == string_test_case[i].encoded_field_len, "encoded length was %d, expecting %d", len, string_test_case[i].encoded_field_len); @@ -471,13 +472,13 @@ REGRESSION_TEST(HPACK_DecodeInteger)(RegressionTest *t, int, int *pstatus) TestBox box(t, pstatus); box = REGRESSION_TEST_PASSED; - uint32_t actual; + uint64_t actual; for (const auto &i : integer_test_case) { - int len = decode_integer(actual, i.encoded_field, i.encoded_field + i.encoded_field_len, i.prefix); + int len = xpack_decode_integer(actual, i.encoded_field, i.encoded_field + i.encoded_field_len, i.prefix); box.check(len == i.encoded_field_len, "decoded length was %d, expecting %d", len, i.encoded_field_len); - box.check(actual == i.raw_integer, "decoded value was %d, expected %d", actual, i.raw_integer); + box.check(actual == i.raw_integer, "decoded value was %" PRIu64 ", expected %d", actual, i.raw_integer); } } @@ -488,15 +489,16 @@ REGRESSION_TEST(HPACK_DecodeString)(RegressionTest *t, int, int *pstatus) Arena arena; char *actual = nullptr; - uint32_t actual_len = 0; + uint64_t actual_len = 0; hpack_huffman_init(); for (const auto &i : string_test_case) { - int len = decode_string(arena, &actual, actual_len, i.encoded_field, i.encoded_field + i.encoded_field_len); + int len = xpack_decode_string(arena, &actual, actual_len, i.encoded_field, i.encoded_field + i.encoded_field_len); box.check(len == i.encoded_field_len, "decoded length was %d, expecting %d", len, i.encoded_field_len); - box.check(actual_len == i.raw_string_len, "length of decoded string was %d, expecting %d", actual_len, i.raw_string_len); + box.check(actual_len == i.raw_string_len, "length of decoded string was %" PRIu64 ", expecting %d", actual_len, + i.raw_string_len); box.check(memcmp(actual, i.raw_string, actual_len) == 0, "decoded string was invalid"); } } From 5e8f47ddd2ccb26964fdc1607265d387673192e3 Mon Sep 17 00:00:00 2001 From: Masakazu Kitajo Date: Thu, 27 Jun 2019 12:09:52 +0900 Subject: [PATCH 06/19] Log H2 errors with the codes (cherry picked from commit 8510a1c244894b1582f112f1eccd1d5fa9e977b3) --- proxy/http2/HTTP2.h | 2 +- proxy/http2/Http2ConnectionState.cc | 8 ++++---- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/proxy/http2/HTTP2.h b/proxy/http2/HTTP2.h index 504b899169b..22b132d0f84 100644 --- a/proxy/http2/HTTP2.h +++ b/proxy/http2/HTTP2.h @@ -239,7 +239,7 @@ struct Http2FrameHeader { // [RFC 7540] 5.4. Error Handling struct Http2Error { Http2Error(const Http2ErrorClass error_class = Http2ErrorClass::HTTP2_ERROR_CLASS_NONE, - const Http2ErrorCode error_code = Http2ErrorCode::HTTP2_ERROR_NO_ERROR, const char *err_msg = nullptr) + const Http2ErrorCode error_code = Http2ErrorCode::HTTP2_ERROR_NO_ERROR, const char *err_msg = "") { cls = error_class; code = error_code; diff --git a/proxy/http2/Http2ConnectionState.cc b/proxy/http2/Http2ConnectionState.cc index f0e182321fa..93280a8b2fd 100644 --- a/proxy/http2/Http2ConnectionState.cc +++ b/proxy/http2/Http2ConnectionState.cc @@ -1011,8 +1011,8 @@ Http2ConnectionState::main_event_handler(int event, void *edata) const char *client_ip = ats_ip_ntop(ua_session->get_client_addr(), ipb, sizeof(ipb)); if (error.cls == Http2ErrorClass::HTTP2_ERROR_CLASS_CONNECTION) { if (error.msg) { - Error("HTTP/2 connection error client_ip=%s session_id=%" PRId64 " stream_id=%u %s", client_ip, - ua_session->connection_id(), stream_id, error.msg); + Error("HTTP/2 connection error code=0x%02x client_ip=%s session_id=%" PRId64 " stream_id=%u %s", + static_cast(error.code), client_ip, ua_session->connection_id(), stream_id, error.msg); } this->send_goaway_frame(this->latest_streamid_in, error.code); this->ua_session->set_half_close_local_flag(true); @@ -1024,8 +1024,8 @@ Http2ConnectionState::main_event_handler(int event, void *edata) // The Http2ClientSession will shutdown because connection_state.is_state_closed() will be true } else if (error.cls == Http2ErrorClass::HTTP2_ERROR_CLASS_STREAM) { if (error.msg) { - Error("HTTP/2 stream error client_ip=%s session_id=%" PRId64 " stream_id=%u %s", client_ip, ua_session->connection_id(), - stream_id, error.msg); + Error("HTTP/2 stream error code=0x%02x client_ip=%s session_id=%" PRId64 " stream_id=%u %s", static_cast(error.code), + client_ip, ua_session->connection_id(), stream_id, error.msg); } this->send_rst_stream_frame(stream_id, error.code); } From 50db0815503cee9bbed696b7ec3df28ad328def4 Mon Sep 17 00:00:00 2001 From: "Alan M. Carroll" Date: Fri, 28 Jun 2019 13:19:33 -0500 Subject: [PATCH 07/19] HTTP/2 - tweak for better field name handling. (cherry picked from commit 26c039d9fd0dda6e78f5ceb47fa416c5928df250) --- proxy/http2/Http2Stream.cc | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/proxy/http2/Http2Stream.cc b/proxy/http2/Http2Stream.cc index 5d17881319b..5fa978b4e59 100644 --- a/proxy/http2/Http2Stream.cc +++ b/proxy/http2/Http2Stream.cc @@ -763,9 +763,8 @@ void Http2Stream::response_initialize_data_handling(bool &is_done) { is_done = false; - const char *name = "transfer-encoding"; - const char *value = "chunked"; - int chunked_index = response_header.value_get_index(name, strlen(name), value, strlen(value)); + int chunked_index = response_header.value_get_index(TS_MIME_FIELD_TRANSFER_ENCODING, TS_MIME_LEN_TRANSFER_ENCODING, + TS_HTTP_VALUE_CHUNKED, TS_HTTP_LEN_CHUNKED); // -1 means this value was not found for this field if (chunked_index >= 0) { Http2StreamDebug("Response is chunked"); From ea4c7c9c37f97fcdc130e9d6dfe7e9b7a6f91438 Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Fri, 12 Jul 2019 07:55:14 +0900 Subject: [PATCH 08/19] Convert regression tests for XPACK into Catch based unit tests (cherry picked from commit fd5c84a96d39ff29a559d05c354ed6ea9299bece) Conflicts: .gitignore proxy/hdrs/Makefile.am proxy/http2/RegressionHPACK.cc --- .gitignore | 1 + proxy/hdrs/Makefile.am | 16 +++- proxy/hdrs/unit_tests/test_XPACK.cc | 123 ++++++++++++++++++++++++++++ proxy/http2/RegressionHPACK.cc | 104 ----------------------- 4 files changed, 139 insertions(+), 105 deletions(-) create mode 100644 proxy/hdrs/unit_tests/test_XPACK.cc diff --git a/.gitignore b/.gitignore index fd3dd118cde..767cb1e17ad 100644 --- a/.gitignore +++ b/.gitignore @@ -98,6 +98,7 @@ iocore/hostdb/test_RefCountCache proxy/hdrs/test_mime proxy/hdrs/test_Huffmancode +proxy/hdrs/test_XPACK proxy/http/test_ForwardedConfig proxy/http2/test_Http2DependencyTree proxy/http2/test_Http2FrequencyCounter diff --git a/proxy/hdrs/Makefile.am b/proxy/hdrs/Makefile.am index 15c0265d07c..bc060e527c4 100644 --- a/proxy/hdrs/Makefile.am +++ b/proxy/hdrs/Makefile.am @@ -68,7 +68,8 @@ load_http_hdr_LDADD = -L. -lhdrs \ check_PROGRAMS = \ test_mime \ - test_Huffmancode + test_Huffmancode \ + test_XPACK TESTS = $(check_PROGRAMS) @@ -93,6 +94,19 @@ test_Huffmancode_SOURCES = \ HuffmanCodec.cc \ HuffmanCodec.h +test_XPACK_CPPFLAGS = \ + $(AM_CPPFLAGS) \ + -I$(abs_top_srcdir)/tests/include + +test_XPACK_LDADD = \ + $(top_builddir)/src/tscore/libtscore.la \ + $(top_builddir)/src/tscpp/util/libtscpputil.la + +test_XPACK_SOURCES = \ + unit_tests/test_XPACK.cc \ + HuffmanCodec.cc \ + XPACK.cc + #test_UNUSED_SOURCES = \ # test_urlhash.cc diff --git a/proxy/hdrs/unit_tests/test_XPACK.cc b/proxy/hdrs/unit_tests/test_XPACK.cc new file mode 100644 index 00000000000..91bd8b31161 --- /dev/null +++ b/proxy/hdrs/unit_tests/test_XPACK.cc @@ -0,0 +1,123 @@ +/** @file + + Catch based unit tests for XPACK + + @section license License + + 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. + */ + +#define CATCH_CONFIG_MAIN + +#include "catch.hpp" + +#include "XPACK.h" +#include "HuffmanCodec.h" + +static constexpr int BUFSIZE_FOR_REGRESSION_TEST = 128; + +TEST_CASE("XPACK_Integer", "[xpack]") +{ + // [RFC 7541] C.1. Integer Representation Examples + static const struct { + uint32_t raw_integer; + uint8_t *encoded_field; + int encoded_field_len; + int prefix; + } integer_test_case[] = {{10, (uint8_t *)"\x0a", 1, 5}, {1337, (uint8_t *)"\x1F\x9A\x0A", 3, 5}, {42, (uint8_t *)R"(*)", 1, 8}}; + + SECTION("Encoding") + { + for (const auto &i : integer_test_case) { + uint8_t buf[BUFSIZE_FOR_REGRESSION_TEST] = {0}; + + int len = xpack_encode_integer(buf, buf + BUFSIZE_FOR_REGRESSION_TEST, i.raw_integer, i.prefix); + + REQUIRE(len > 0); + REQUIRE(len == i.encoded_field_len); + REQUIRE(memcmp(buf, i.encoded_field, len) == 0); + } + } + + SECTION("Decoding") + { + for (const auto &i : integer_test_case) { + uint64_t actual = 0; + int len = xpack_decode_integer(actual, i.encoded_field, i.encoded_field + i.encoded_field_len, i.prefix); + + REQUIRE(len == i.encoded_field_len); + REQUIRE(actual == i.raw_integer); + } + } +} + +TEST_CASE("XPACK_String", "[xpack]") +{ + // Example: custom-key: custom-header + const static struct { + char *raw_string; + uint32_t raw_string_len; + uint8_t *encoded_field; + int encoded_field_len; + } string_test_case[] = {{(char *)"", 0, + (uint8_t *)"\x0" + "", + 1}, + {(char *)"custom-key", 10, + (uint8_t *)"\xA" + "custom-key", + 11}, + {(char *)"", 0, + (uint8_t *)"\x80" + "", + 1}, + {(char *)"custom-key", 10, + (uint8_t *)"\x88" + "\x25\xa8\x49\xe9\x5b\xa9\x7d\x7f", + 9}}; + + SECTION("Encoding") + { + // FIXME Current encoder support only huffman conding. + for (unsigned int i = 2; i < sizeof(string_test_case) / sizeof(string_test_case[0]); i++) { + uint8_t buf[BUFSIZE_FOR_REGRESSION_TEST] = {0}; + int len = xpack_encode_string(buf, buf + BUFSIZE_FOR_REGRESSION_TEST, string_test_case[i].raw_string, + string_test_case[i].raw_string_len); + + REQUIRE(len > 0); + REQUIRE(len == string_test_case[i].encoded_field_len); + REQUIRE(memcmp(buf, string_test_case[i].encoded_field, len) == 0); + } + } + + SECTION("Decoding") + { + // Decoding string needs huffman tree + hpack_huffman_init(); + + for (const auto &i : string_test_case) { + Arena arena; + char *actual = nullptr; + uint64_t actual_len = 0; + int len = xpack_decode_string(arena, &actual, actual_len, i.encoded_field, i.encoded_field + i.encoded_field_len); + + REQUIRE(len == i.encoded_field_len); + REQUIRE(actual_len == i.raw_string_len); + REQUIRE(memcmp(actual, i.raw_string, actual_len) == 0); + } + } +} diff --git a/proxy/http2/RegressionHPACK.cc b/proxy/http2/RegressionHPACK.cc index 77072276e8d..8beb73d508c 100644 --- a/proxy/http2/RegressionHPACK.cc +++ b/proxy/http2/RegressionHPACK.cc @@ -41,37 +41,6 @@ const static int MAX_TABLE_SIZE = 4096; * * ***********************************************************************************/ -// [RFC 7541] C.1. Integer Representation Examples -const static struct { - uint32_t raw_integer; - uint8_t *encoded_field; - int encoded_field_len; - int prefix; -} integer_test_case[] = {{10, (uint8_t *)"\x0A", 1, 5}, {1337, (uint8_t *)"\x1F\x9A\x0A", 3, 5}, {42, (uint8_t *)"\x2A", 1, 8}}; - -// Example: custom-key: custom-header -const static struct { - char *raw_string; - uint32_t raw_string_len; - uint8_t *encoded_field; - int encoded_field_len; -} string_test_case[] = {{(char *)"", 0, - (uint8_t *)"\x0" - "", - 1}, - {(char *)"custom-key", 10, - (uint8_t *)"\xA" - "custom-key", - 11}, - {(char *)"", 0, - (uint8_t *)"\x80" - "", - 1}, - {(char *)"custom-key", 10, - (uint8_t *)"\x88" - "\x25\xa8\x49\xe9\x5b\xa9\x7d\x7f", - 9}}; - // [RFC 7541] C.2.4. Indexed Header Field const static struct { int index; @@ -317,43 +286,6 @@ const static struct { * * ***********************************************************************************/ -REGRESSION_TEST(HPACK_EncodeInteger)(RegressionTest *t, int, int *pstatus) -{ - TestBox box(t, pstatus); - box = REGRESSION_TEST_PASSED; - uint8_t buf[BUFSIZE_FOR_REGRESSION_TEST]; - - for (const auto &i : integer_test_case) { - memset(buf, 0, BUFSIZE_FOR_REGRESSION_TEST); - - int len = xpack_encode_integer(buf, buf + BUFSIZE_FOR_REGRESSION_TEST, i.raw_integer, i.prefix); - - box.check(len == i.encoded_field_len, "encoded length was %d, expecting %d", len, i.encoded_field_len); - box.check(len > 0 && memcmp(buf, i.encoded_field, len) == 0, "encoded value was invalid"); - } -} - -REGRESSION_TEST(HPACK_EncodeString)(RegressionTest *t, int, int *pstatus) -{ - TestBox box(t, pstatus); - box = REGRESSION_TEST_PASSED; - - uint8_t buf[BUFSIZE_FOR_REGRESSION_TEST]; - int len; - - // FIXME Current encoder support only huffman conding. - for (unsigned int i = 2; i < sizeof(string_test_case) / sizeof(string_test_case[0]); i++) { - memset(buf, 0, BUFSIZE_FOR_REGRESSION_TEST); - - len = xpack_encode_string(buf, buf + BUFSIZE_FOR_REGRESSION_TEST, string_test_case[i].raw_string, - string_test_case[i].raw_string_len); - - box.check(len == string_test_case[i].encoded_field_len, "encoded length was %d, expecting %d", len, - string_test_case[i].encoded_field_len); - box.check(len > 0 && memcmp(buf, string_test_case[i].encoded_field, len) == 0, "encoded string was invalid"); - } -} - REGRESSION_TEST(HPACK_EncodeIndexedHeaderField)(RegressionTest *t, int, int *pstatus) { TestBox box(t, pstatus); @@ -467,42 +399,6 @@ REGRESSION_TEST(HPACK_Encode)(RegressionTest *t, int, int *pstatus) } } -REGRESSION_TEST(HPACK_DecodeInteger)(RegressionTest *t, int, int *pstatus) -{ - TestBox box(t, pstatus); - box = REGRESSION_TEST_PASSED; - - uint64_t actual; - - for (const auto &i : integer_test_case) { - int len = xpack_decode_integer(actual, i.encoded_field, i.encoded_field + i.encoded_field_len, i.prefix); - - box.check(len == i.encoded_field_len, "decoded length was %d, expecting %d", len, i.encoded_field_len); - box.check(actual == i.raw_integer, "decoded value was %" PRIu64 ", expected %d", actual, i.raw_integer); - } -} - -REGRESSION_TEST(HPACK_DecodeString)(RegressionTest *t, int, int *pstatus) -{ - TestBox box(t, pstatus); - box = REGRESSION_TEST_PASSED; - - Arena arena; - char *actual = nullptr; - uint64_t actual_len = 0; - - hpack_huffman_init(); - - for (const auto &i : string_test_case) { - int len = xpack_decode_string(arena, &actual, actual_len, i.encoded_field, i.encoded_field + i.encoded_field_len); - - box.check(len == i.encoded_field_len, "decoded length was %d, expecting %d", len, i.encoded_field_len); - box.check(actual_len == i.raw_string_len, "length of decoded string was %" PRIu64 ", expecting %d", actual_len, - i.raw_string_len); - box.check(memcmp(actual, i.raw_string, actual_len) == 0, "decoded string was invalid"); - } -} - REGRESSION_TEST(HPACK_DecodeIndexedHeaderField)(RegressionTest *t, int, int *pstatus) { TestBox box(t, pstatus); From 0eefa91b9141e68724d440f0a6ae8d71724c0bd4 Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Wed, 24 Jul 2019 14:48:09 +0900 Subject: [PATCH 09/19] Add slow logs for HTTP/2 Connection & Stream (cherry picked from commit 0d2ad23921061c4117104b64d15bc17cae79c9fe) Conflicts: proxy/http2/HTTP2.cc proxy/http2/HTTP2.h proxy/http2/Http2Stream.cc proxy/http2/Http2Stream.h --- doc/admin-guide/files/records.config.en.rst | 20 +++++++ mgmt/RecordsConfig.cc | 4 ++ proxy/Milestones.h | 59 ++++++++++++++------- proxy/http2/HTTP2.cc | 4 ++ proxy/http2/HTTP2.h | 2 + proxy/http2/Http2ClientSession.cc | 11 ++++ proxy/http2/Http2ClientSession.h | 8 +++ proxy/http2/Http2ConnectionState.cc | 6 +++ proxy/http2/Http2Stream.cc | 40 +++++++++++++- proxy/http2/Http2Stream.h | 24 +++++++-- 10 files changed, 153 insertions(+), 25 deletions(-) diff --git a/doc/admin-guide/files/records.config.en.rst b/doc/admin-guide/files/records.config.en.rst index 109122e2a8b..f0d80c56102 100644 --- a/doc/admin-guide/files/records.config.en.rst +++ b/doc/admin-guide/files/records.config.en.rst @@ -2882,6 +2882,26 @@ Logging Configuration completion will cause its timing stats to be written to the :ts:cv:`debugging log file `. This is identifying data about the transaction and all of the :c:type:`transaction milestones `. +.. ts:cv:: CONFIG proxy.config.http2.connection.slow.log.threshold INT 0 + :reloadable: + :units: milliseconds + + If set to a non-zero value :arg:`N` then any HTTP/2 connection + that takes longer than :arg:`N` milliseconds from open to close will cause + its timing stats to be written to the :ts:cv:`debugging log file + `. This is identifying data about the + transaction and all of the :c:type:`transaction milestones `. + +.. ts:cv:: CONFIG proxy.config.http2.stream.slow.log.threshold INT 0 + :reloadable: + :units: milliseconds + + If set to a non-zero value :arg:`N` then any HTTP/2 stream + that takes longer than :arg:`N` milliseconds from open to close will cause + its timing stats to be written to the :ts:cv:`debugging log file + `. This is identifying data about the + transaction and all of the :c:type:`transaction milestones `. + .. ts:cv:: CONFIG proxy.config.log.config.filename STRING logging.yaml :reloadable: diff --git a/mgmt/RecordsConfig.cc b/mgmt/RecordsConfig.cc index 72a501f95a4..dbcb07f1b4b 100644 --- a/mgmt/RecordsConfig.cc +++ b/mgmt/RecordsConfig.cc @@ -658,6 +658,10 @@ static const RecordElement RecordsConfig[] = , {RECT_CONFIG, "proxy.config.http.slow.log.threshold", RECD_INT, "0", RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL} , + {RECT_CONFIG, "proxy.config.http2.connection.slow.log.threshold", RECD_INT, "0", RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL} + , + {RECT_CONFIG, "proxy.config.http2.stream.slow.log.threshold", RECD_INT, "0", RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL} + , //############################################################################## //# diff --git a/proxy/Milestones.h b/proxy/Milestones.h index d429e285b81..3170c0f38e0 100644 --- a/proxy/Milestones.h +++ b/proxy/Milestones.h @@ -1,6 +1,6 @@ /** @file - A brief file description + Milestones @section license License @@ -23,22 +23,32 @@ #pragma once -#include "tscore/ink_platform.h" -#include "tscore/ink_hrtime.h" #include "ts/apidefs.h" + +#include "tscore/ink_platform.h" #include "tscore/ink_hrtime.h" -///////////////////////////////////////////////////////////// -// -// class TransactionMilestones -// -///////////////////////////////////////////////////////////// -class TransactionMilestones +#include "I_EventSystem.h" + +template class Milestones { public: - TransactionMilestones() { ink_zero(milestones); } - ink_hrtime &operator[](TSMilestonesType ms) { return milestones[ms]; } - ink_hrtime operator[](TSMilestonesType ms) const { return milestones[ms]; } + ink_hrtime &operator[](T ms) { return this->_milestones[static_cast(ms)]; } + ink_hrtime operator[](T ms) const { return this->_milestones[static_cast(ms)]; } + + /** + * Mark given milestone with timestamp if it's not marked yet + * @param ms The milestone to mark + * @return N/A + */ + void + mark(T ms) + { + if (this->_milestones[static_cast(ms)] == 0) { + this->_milestones[static_cast(ms)] = Thread::get_hrtime(); + } + } + /** * Takes two milestones and returns the difference. * @param start The start time @@ -46,12 +56,12 @@ class TransactionMilestones * @return The difference time in milliseconds */ int64_t - difference_msec(TSMilestonesType ms_start, TSMilestonesType ms_end) const + difference_msec(T ms_start, T ms_end) const { - if (milestones[ms_end] == 0) { + if (this->_milestones[static_cast(ms_end)] == 0) { return -1; } - return ink_hrtime_to_msec(milestones[ms_end] - milestones[ms_start]); + return ink_hrtime_to_msec(this->_milestones[static_cast(ms_end)] - this->_milestones[static_cast(ms_start)]); } /** @@ -61,17 +71,26 @@ class TransactionMilestones * @return A double that is the difference time in seconds */ double - difference_sec(TSMilestonesType ms_start, TSMilestonesType ms_end) const + difference_sec(T ms_start, T ms_end) const { - return (double)difference_msec(ms_start, ms_end) / 1000.0; + return static_cast(difference_msec(ms_start, ms_end) / 1000.0); } + /** + * Takes two milestones and returns the difference. + * @param start The start time + * @param end The end time + * @return The difference time in high-resolution time + */ ink_hrtime - elapsed(TSMilestonesType ms_start, TSMilestonesType ms_end) const + elapsed(T ms_start, T ms_end) const { - return milestones[ms_end] - milestones[ms_start]; + return this->_milestones[static_cast(ms_end)] - this->_milestones[static_cast(ms_start)]; } private: - ink_hrtime milestones[TS_MILESTONE_LAST_ENTRY]; + std::array _milestones = {0}; }; + +// For compatibility with HttpSM.h and HttpTransact.h +using TransactionMilestones = Milestones; diff --git a/proxy/http2/HTTP2.cc b/proxy/http2/HTTP2.cc index 2844c87fd55..ddd74504522 100644 --- a/proxy/http2/HTTP2.cc +++ b/proxy/http2/HTTP2.cc @@ -740,6 +740,8 @@ uint32_t Http2::max_settings_frames_per_minute = 14; uint32_t Http2::max_ping_frames_per_minute = 60; uint32_t Http2::max_priority_frames_per_minute = 120; float Http2::min_avg_window_update = 2560.0; +uint32_t Http2::con_slow_log_threshold = 0; +uint32_t Http2::stream_slow_log_threshold = 0; void Http2::init() @@ -764,6 +766,8 @@ Http2::init() REC_EstablishStaticConfigInt32U(max_ping_frames_per_minute, "proxy.config.http2.max_ping_frames_per_minute"); REC_EstablishStaticConfigInt32U(max_priority_frames_per_minute, "proxy.config.http2.max_priority_frames_per_minute"); REC_EstablishStaticConfigFloat(min_avg_window_update, "proxy.config.http2.min_avg_window_update"); + REC_EstablishStaticConfigInt32U(con_slow_log_threshold, "proxy.config.http2.connection.slow.log.threshold"); + REC_EstablishStaticConfigInt32U(stream_slow_log_threshold, "proxy.config.http2.stream.slow.log.threshold"); // If any settings is broken, ATS should not start ink_release_assert(http2_settings_parameter_is_valid({HTTP2_SETTINGS_MAX_CONCURRENT_STREAMS, max_concurrent_streams_in})); diff --git a/proxy/http2/HTTP2.h b/proxy/http2/HTTP2.h index 22b132d0f84..515aabdc91f 100644 --- a/proxy/http2/HTTP2.h +++ b/proxy/http2/HTTP2.h @@ -385,6 +385,8 @@ class Http2 static uint32_t max_ping_frames_per_minute; static uint32_t max_priority_frames_per_minute; static float min_avg_window_update; + static uint32_t con_slow_log_threshold; + static uint32_t stream_slow_log_threshold; static void init(); }; diff --git a/proxy/http2/Http2ClientSession.cc b/proxy/http2/Http2ClientSession.cc index cab22ee75df..e2e6ddcad90 100644 --- a/proxy/http2/Http2ClientSession.cc +++ b/proxy/http2/Http2ClientSession.cc @@ -107,6 +107,16 @@ Http2ClientSession::free() REMEMBER(NO_EVENT, this->recursion) Http2SsnDebug("session free"); + this->_milestones.mark(Http2SsnMilestone::CLOSE); + ink_hrtime total_time = this->_milestones.elapsed(Http2SsnMilestone::OPEN, Http2SsnMilestone::CLOSE); + + // Slow Log + if (Http2::con_slow_log_threshold != 0 && ink_hrtime_from_msec(Http2::con_slow_log_threshold) < total_time) { + Error("[%" PRIu64 "] Slow H2 Connection: open: %" PRIu64 " close: %.3f", this->con_id, + ink_hrtime_to_msec(this->_milestones[Http2SsnMilestone::OPEN]), + this->_milestones.difference_sec(Http2SsnMilestone::OPEN, Http2SsnMilestone::CLOSE)); + } + HTTP2_DECREMENT_THREAD_DYN_STAT(HTTP2_STAT_CURRENT_CLIENT_SESSION_COUNT, this->mutex->thread_holding); // Update stats on how we died. May want to eliminate this. Was useful for @@ -186,6 +196,7 @@ Http2ClientSession::new_connection(NetVConnection *new_vc, MIOBuffer *iobuf, IOB ink_assert(new_vc->mutex->thread_holding == this_ethread()); HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_CURRENT_CLIENT_SESSION_COUNT, new_vc->mutex->thread_holding); HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_TOTAL_CLIENT_CONNECTION_COUNT, new_vc->mutex->thread_holding); + this->_milestones.mark(Http2SsnMilestone::OPEN); // HTTP/2 for the backdoor connections? Let's not deal woth that yet. ink_release_assert(backdoor == false); diff --git a/proxy/http2/Http2ClientSession.h b/proxy/http2/Http2ClientSession.h index ca8977be38c..90270162cec 100644 --- a/proxy/http2/Http2ClientSession.h +++ b/proxy/http2/Http2ClientSession.h @@ -30,6 +30,7 @@ #include #include "tscore/ink_inet.h" #include "tscore/History.h" +#include "Milestones.h" // Name Edata Description // HTTP2_SESSION_EVENT_INIT Http2ClientSession * HTTP/2 session is born @@ -50,6 +51,12 @@ enum class Http2SessionCod : int { HIGH_ERROR_RATE, }; +enum class Http2SsnMilestone { + OPEN = 0, + CLOSE, + LAST_ENTRY, +}; + size_t const HTTP2_HEADER_BUFFER_SIZE_INDEX = CLIENT_CONNECTION_FIRST_READ_BUFFER_SIZE_INDEX; // To support Upgrade: h2c @@ -352,6 +359,7 @@ class Http2ClientSession : public ProxyClientSession IpEndpoint cached_local_addr; History _history; + Milestones(Http2SsnMilestone::LAST_ENTRY)> _milestones; // For Upgrade: h2c Http2UpgradeContext upgrade_context; diff --git a/proxy/http2/Http2ConnectionState.cc b/proxy/http2/Http2ConnectionState.cc index 93280a8b2fd..e57e4bf1138 100644 --- a/proxy/http2/Http2ConnectionState.cc +++ b/proxy/http2/Http2ConnectionState.cc @@ -337,6 +337,7 @@ rcv_headers_frame(Http2ConnectionState &cstate, const Http2Frame &frame) empty_request = true; } + stream->mark_milestone(Http2StreamMilestone::START_DECODE_HEADERS); Http2ErrorCode result = stream->decode_header_blocks(*cstate.local_hpack_handle, cstate.server_settings.get(HTTP2_SETTINGS_HEADER_TABLE_SIZE)); @@ -356,6 +357,7 @@ rcv_headers_frame(Http2ConnectionState &cstate, const Http2Frame &frame) // Set up the State Machine if (!empty_request) { SCOPED_MUTEX_LOCK(stream_lock, stream->mutex, this_ethread()); + stream->mark_milestone(Http2StreamMilestone::START_TXN); stream->new_transaction(); // Send request header to SM stream->send_request(cstate); @@ -905,6 +907,7 @@ rcv_continuation_frame(Http2ConnectionState &cstate, const Http2Frame &frame) // Set up the State Machine SCOPED_MUTEX_LOCK(stream_lock, stream->mutex, this_ethread()); + stream->mark_milestone(Http2StreamMilestone::START_TXN); stream->new_transaction(); // Send request header to SM stream->send_request(cstate); @@ -1564,6 +1567,8 @@ Http2ConnectionState::send_headers_frame(Http2Stream *stream) h2_hdr.destroy(); return; } + + stream->mark_milestone(Http2StreamMilestone::START_ENCODE_HEADERS); Http2ErrorCode result = http2_encode_header_blocks(&h2_hdr, buf, buf_len, &header_blocks_size, *(this->remote_hpack_handle), client_settings.get(HTTP2_SETTINGS_HEADER_TABLE_SIZE)); if (result != Http2ErrorCode::HTTP2_ERROR_NO_ERROR) { @@ -1580,6 +1585,7 @@ Http2ConnectionState::send_headers_frame(Http2Stream *stream) flags |= HTTP2_FLAGS_HEADERS_END_STREAM; stream->send_end_stream = true; } + stream->mark_milestone(Http2StreamMilestone::START_TX_HEADERS_FRAMES); } else { payload_length = BUFFER_SIZE_FOR_INDEX(buffer_size_index[HTTP2_FRAME_TYPE_HEADERS]); } diff --git a/proxy/http2/Http2Stream.cc b/proxy/http2/Http2Stream.cc index 5fa978b4e59..122dcff4b7c 100644 --- a/proxy/http2/Http2Stream.cc +++ b/proxy/http2/Http2Stream.cc @@ -175,6 +175,7 @@ Http2Stream::send_request(Http2ConnectionState &cstate) // Is there a read_vio request waiting? this->update_read_request(INT64_MAX, true); + this->_http_sm_id = this->current_reader->sm_id; } bool @@ -627,6 +628,7 @@ Http2Stream::update_write_request(IOBufferReader *buf_reader, int64_t write_len, // make sure to send the end of stream is_done |= (write_vio.ntodo() + this->response_header.length_get()) == bytes_avail; if (this->response_is_data_available() || is_done) { + this->_milestones.mark(Http2StreamMilestone::START_TX_DATA_FRAMES); this->send_response_body(call_update); } break; @@ -638,6 +640,7 @@ Http2Stream::update_write_request(IOBufferReader *buf_reader, int64_t write_len, break; } } else { + this->_milestones.mark(Http2StreamMilestone::START_TX_DATA_FRAMES); this->send_response_body(call_update); } @@ -720,6 +723,8 @@ Http2Stream::destroy() ink_release_assert(this->closed); ink_release_assert(reentrancy_count == 0); + uint64_t cid = 0; + // Safe to initiate SSN_CLOSE if this is the last stream if (parent) { Http2ClientSession *h2_parent = static_cast(parent); @@ -730,14 +735,39 @@ Http2Stream::destroy() // Update session's stream counts, so it accurately goes into keep-alive state h2_parent->connection_state.release_stream(this); + cid = parent->connection_id(); } // Clean up the write VIO in case of inactivity timeout this->do_io_write(nullptr, 0, nullptr); HTTP2_DECREMENT_THREAD_DYN_STAT(HTTP2_STAT_CURRENT_CLIENT_STREAM_COUNT, _thread); - ink_hrtime end_time = Thread::get_hrtime(); - HTTP2_SUM_THREAD_DYN_STAT(HTTP2_STAT_TOTAL_TRANSACTIONS_TIME, _thread, end_time - _start_time); + + this->_milestones.mark(Http2StreamMilestone::CLOSE); + + ink_hrtime total_time = this->_milestones.elapsed(Http2StreamMilestone::OPEN, Http2StreamMilestone::CLOSE); + HTTP2_SUM_THREAD_DYN_STAT(HTTP2_STAT_TOTAL_TRANSACTIONS_TIME, this->_thread, total_time); + + // Slow Log + if (Http2::stream_slow_log_threshold != 0 && ink_hrtime_from_msec(Http2::stream_slow_log_threshold) < total_time) { + Error("[%" PRIu64 "] [%" PRIu32 "] [%" PRId64 "] Slow H2 Stream: " + "open: %" PRIu64 " " + "dec_hdrs: %.3f " + "txn: %.3f " + "enc_hdrs: %.3f " + "tx_hdrs: %.3f " + "tx_data: %.3f " + "close: %.3f", + cid, static_cast(this->_id), this->_http_sm_id, + ink_hrtime_to_msec(this->_milestones[Http2StreamMilestone::OPEN]), + this->_milestones.difference_sec(Http2StreamMilestone::OPEN, Http2StreamMilestone::START_DECODE_HEADERS), + this->_milestones.difference_sec(Http2StreamMilestone::OPEN, Http2StreamMilestone::START_TXN), + this->_milestones.difference_sec(Http2StreamMilestone::OPEN, Http2StreamMilestone::START_ENCODE_HEADERS), + this->_milestones.difference_sec(Http2StreamMilestone::OPEN, Http2StreamMilestone::START_TX_HEADERS_FRAMES), + this->_milestones.difference_sec(Http2StreamMilestone::OPEN, Http2StreamMilestone::START_TX_DATA_FRAMES), + this->_milestones.difference_sec(Http2StreamMilestone::OPEN, Http2StreamMilestone::CLOSE)); + } + _req_header.destroy(); response_header.destroy(); @@ -946,6 +976,12 @@ Http2Stream::decrement_server_rwnd(size_t amount) } } +void +Http2Stream::mark_milestone(Http2StreamMilestone type) +{ + this->_milestones.mark(type); +} + bool Http2Stream::_switch_thread_if_not_on_right_thread(int event, void *edata) { diff --git a/proxy/http2/Http2Stream.h b/proxy/http2/Http2Stream.h index 6f65f6c57a3..edb0116718c 100644 --- a/proxy/http2/Http2Stream.h +++ b/proxy/http2/Http2Stream.h @@ -29,12 +29,24 @@ #include "../http/HttpTunnel.h" // To get ChunkedHandler #include "Http2DependencyTree.h" #include "tscore/History.h" +#include "Milestones.h" class Http2Stream; class Http2ConnectionState; typedef Http2DependencyTree::Tree DependencyTree; +enum class Http2StreamMilestone { + OPEN = 0, + START_DECODE_HEADERS, + START_TXN, + START_ENCODE_HEADERS, + START_TX_HEADERS_FRAMES, + START_TX_DATA_FRAMES, + CLOSE, + LAST_ENTRY, +}; + class Http2Stream : public ProxyClientTransaction { public: @@ -47,12 +59,15 @@ class Http2Stream : public ProxyClientTransaction void init(Http2StreamId sid, ssize_t initial_rwnd) { + this->mark_milestone(Http2StreamMilestone::OPEN); + _id = sid; - _start_time = Thread::get_hrtime(); _thread = this_ethread(); this->_client_rwnd = initial_rwnd; + HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_CURRENT_CLIENT_STREAM_COUNT, _thread); HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_TOTAL_CLIENT_STREAM_COUNT, _thread); + sm_reader = request_reader = request_buffer.alloc_reader(); http_parser_init(&http_parser); // FIXME: Are you sure? every "stream" needs request_header? @@ -223,6 +238,8 @@ class Http2Stream : public ProxyClientTransaction return is_first_transaction_flag; } + void mark_milestone(Http2StreamMilestone type); + private: void response_initialize_data_handling(bool &is_done); void response_process_data(bool &is_done); @@ -238,16 +255,17 @@ class Http2Stream : public ProxyClientTransaction bool _switch_thread_if_not_on_right_thread(int event, void *edata); HTTPParser http_parser; - ink_hrtime _start_time = 0; - EThread *_thread = nullptr; + EThread *_thread = nullptr; Http2StreamId _id; Http2StreamState _state = Http2StreamState::HTTP2_STREAM_STATE_IDLE; + int64_t _http_sm_id = -1; HTTPHdr _req_header; VIO read_vio; VIO write_vio; History _history; + Milestones(Http2StreamMilestone::LAST_ENTRY)> _milestones; bool trailing_header = false; bool chunked = false; From 7a413960ef7b86744719fd1802fc8b6675ef2820 Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Wed, 7 Aug 2019 17:01:06 +0900 Subject: [PATCH 10/19] Allocate DependencyTree only if HTTP/2 stream priority is enabled (cherry picked from commit b2f62640c20ddd4acc7ccdb1876b4f58a9044df8) --- proxy/http2/Http2ConnectionState.h | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/proxy/http2/Http2ConnectionState.h b/proxy/http2/Http2ConnectionState.h index e6f4ff950b4..489ea9aa2fb 100644 --- a/proxy/http2/Http2ConnectionState.h +++ b/proxy/http2/Http2ConnectionState.h @@ -132,7 +132,9 @@ class Http2ConnectionState : public Continuation { local_hpack_handle = new HpackHandle(HTTP2_HEADER_TABLE_SIZE); remote_hpack_handle = new HpackHandle(HTTP2_HEADER_TABLE_SIZE); - dependency_tree = new DependencyTree(Http2::max_concurrent_streams_in); + if (Http2::stream_priority_enabled) { + dependency_tree = new DependencyTree(Http2::max_concurrent_streams_in); + } } void From 055d125ad4f1d669031f5fc67488b1de79566df4 Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Thu, 15 Aug 2019 14:46:29 +0900 Subject: [PATCH 11/19] Record HttpSM Id on new transaction There is a path of Http2Stream::update_read_request() starts shutdown and make current_reader nullptr. Copying HttpSM Id from current_reader should be done before the update_read_request() call. (cherry picked from commit 296cf29b02bf3aba6d22a4a7e66ae5441f5a212c) --- proxy/http2/Http2Stream.cc | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/proxy/http2/Http2Stream.cc b/proxy/http2/Http2Stream.cc index 122dcff4b7c..73d7a9301f7 100644 --- a/proxy/http2/Http2Stream.cc +++ b/proxy/http2/Http2Stream.cc @@ -148,6 +148,9 @@ Http2Stream::decode_header_blocks(HpackHandle &hpack_handle, uint32_t maximum_ta void Http2Stream::send_request(Http2ConnectionState &cstate) { + ink_release_assert(this->current_reader != nullptr); + this->_http_sm_id = this->current_reader->sm_id; + // Convert header to HTTP/1.1 format http2_convert_header_from_2_to_1_1(&_req_header); @@ -175,7 +178,6 @@ Http2Stream::send_request(Http2ConnectionState &cstate) // Is there a read_vio request waiting? this->update_read_request(INT64_MAX, true); - this->_http_sm_id = this->current_reader->sm_id; } bool From 107d5d549720537108d270dfc477b49cd90db34d Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Wed, 14 Aug 2019 10:06:40 +0900 Subject: [PATCH 12/19] Cleanup: Remove unused function & old comments (cherry picked from commit 59c4a58adca8cdbb3dd540ec8f8db0238d9b919c) --- proxy/http2/Http2ClientSession.cc | 6 ------ proxy/http2/Http2ClientSession.h | 6 ------ 2 files changed, 12 deletions(-) diff --git a/proxy/http2/Http2ClientSession.cc b/proxy/http2/Http2ClientSession.cc index e2e6ddcad90..0b09e4fa110 100644 --- a/proxy/http2/Http2ClientSession.cc +++ b/proxy/http2/Http2ClientSession.cc @@ -179,12 +179,6 @@ Http2ClientSession::start() read_vio = this->do_io_read(this, INT64_MAX, this->read_buffer); write_vio = this->do_io_write(this, INT64_MAX, this->sm_writer); - // 3.5 HTTP/2 Connection Preface. Upon establishment of a TCP connection and - // determination that HTTP/2 will be used by both peers, each endpoint MUST - // send a connection preface as a final confirmation ... - // this->write_buffer->write(HTTP2_CONNECTION_PREFACE, - // HTTP2_CONNECTION_PREFACE_LEN); - this->connection_state.init(); send_connection_event(&this->connection_state, HTTP2_SESSION_EVENT_INIT, this); this->handleEvent(VC_EVENT_READ_READY, read_vio); diff --git a/proxy/http2/Http2ClientSession.h b/proxy/http2/Http2ClientSession.h index 90270162cec..f99dd30d22b 100644 --- a/proxy/http2/Http2ClientSession.h +++ b/proxy/http2/Http2ClientSession.h @@ -318,12 +318,6 @@ class Http2ClientSession : public ProxyClientSession } } - int64_t - write_buffer_size() - { - return write_buffer->max_read_avail(); - } - // Record history from Http2ConnectionState void remember(const SourceLocation &location, int event, int reentrant = NO_REENTRANT); From 9d12a32188d73946318719091ff19bb464821612 Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Wed, 14 Aug 2019 10:33:59 +0900 Subject: [PATCH 13/19] Cleanup: Signal READ_READY event only if the buffer is readable READ_READY event is always signaled itself when Http2ClientSession is started. But this could waste some CPU cycle if there no data to read. (cherry picked from commit 03ff3379fbaffb433e632e7d302856699ffeb3a6) --- proxy/http2/Http2ClientSession.cc | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/proxy/http2/Http2ClientSession.cc b/proxy/http2/Http2ClientSession.cc index 0b09e4fa110..29d62b8215a 100644 --- a/proxy/http2/Http2ClientSession.cc +++ b/proxy/http2/Http2ClientSession.cc @@ -169,19 +169,20 @@ Http2ClientSession::free() void Http2ClientSession::start() { - VIO *read_vio; - SCOPED_MUTEX_LOCK(lock, this->mutex, this_ethread()); SET_HANDLER(&Http2ClientSession::main_event_handler); HTTP2_SET_SESSION_HANDLER(&Http2ClientSession::state_read_connection_preface); - read_vio = this->do_io_read(this, INT64_MAX, this->read_buffer); - write_vio = this->do_io_write(this, INT64_MAX, this->sm_writer); + VIO *read_vio = this->do_io_read(this, INT64_MAX, this->read_buffer); + write_vio = this->do_io_write(this, INT64_MAX, this->sm_writer); this->connection_state.init(); send_connection_event(&this->connection_state, HTTP2_SESSION_EVENT_INIT, this); - this->handleEvent(VC_EVENT_READ_READY, read_vio); + + if (this->sm_reader->is_read_avail_more_than(0)) { + this->handleEvent(VC_EVENT_READ_READY, read_vio); + } } void From 91ec71abfcfc56d8fd3e8ecc9e9f6982edc3208d Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Mon, 10 Jun 2019 11:08:54 +0900 Subject: [PATCH 14/19] Doc: Add documentation for HTTP/2 statistics (cherry picked from commit 532fa0d7b96e100b43d801192f1f0458ffa7722e) Conflicts: doc/admin-guide/monitoring/statistics/core/http-connection.en.rst --- .../statistics/core/http-connection.en.rst | 64 ++++++++++++++++++- .../statistics/core/http-transaction.en.rst | 25 ++++++++ 2 files changed, 88 insertions(+), 1 deletion(-) diff --git a/doc/admin-guide/monitoring/statistics/core/http-connection.en.rst b/doc/admin-guide/monitoring/statistics/core/http-connection.en.rst index 736850ebcda..46d9db95ca8 100644 --- a/doc/admin-guide/monitoring/statistics/core/http-connection.en.rst +++ b/doc/admin-guide/monitoring/statistics/core/http-connection.en.rst @@ -136,7 +136,69 @@ HTTP Connection This tracks the number of origin connections denied due to being over the :ts:cv:`proxy.config.http.origin_max_connections` limit. -.. ts:stat:: global proxy.process.http2.current_active_client_connections integer + +HTTP/2 +------ + + +.. ts:stat:: global proxy.process.http2.total_client_connections integer + :type: counter + + Represents the total number of HTTP/2 connections from client to the |TS|. + +.. ts:stat:: global proxy.process.http2.current_client_connections integer :type: gauge Represents the current number of HTTP/2 connections from client to the |TS|. + +.. ts:stat:: global proxy.process.http2.current_active_client_connections integer + :type: gauge + + Represents the current number of HTTP/2 active connections from client to the |TS|. + +.. ts:stat:: global proxy.process.http2.connection_errors integer + :type: counter + + Represents the total number of HTTP/2 connections errors. + +.. ts:stat:: global proxy.process.http2.session_die_default integer + :type: counter + + Represents the total number of closed HTTP/2 connections with + ``VC_EVENT_NONE`` event. + +.. ts:stat:: global proxy.process.http2.session_die_active integer + :type: counter + + Represents the total number of closed HTTP/2 connections with + ``VC_EVENT_ACTIVE_TIMEOUT`` event. + +.. ts:stat:: global proxy.process.http2.session_die_inactive integer + :type: counter + + Represents the total number of closed HTTP/2 connections with + ``VC_EVENT_INACTIVITY_TIMEOUT`` event. + +.. ts:stat:: global proxy.process.http2.session_die_eos integer + :type: counter + + Represents the total number of closed HTTP/2 connections with + ``VC_EVENT_EOS`` event. + +.. ts:stat:: global proxy.process.http2.session_die_error integer + :type: counter + + Represents the total number of closed HTTP/2 connections with + ``VC_EVENT_ERROR`` event. + +.. ts:stat:: global proxy.process.http2.session_die_other integer + :type: counter + + Represents the total number of closed HTTP/2 connections with + unknown event. + +.. ts:stat:: global proxy.process.http2.session_die_high_error_rate integer + :type: counter + + Represents the total number of closed HTTP/2 connections with high + error rate which is configured by :ts:cv:`proxy.config.http2.stream_error_rate_threshold`. diff --git a/doc/admin-guide/monitoring/statistics/core/http-transaction.en.rst b/doc/admin-guide/monitoring/statistics/core/http-transaction.en.rst index fd5772bb764..07a6e60a0d8 100644 --- a/doc/admin-guide/monitoring/statistics/core/http-transaction.en.rst +++ b/doc/admin-guide/monitoring/statistics/core/http-transaction.en.rst @@ -150,3 +150,28 @@ HTTP Transaction :units: seconds :ungathered: + +HTTP/2 +------ + + +.. ts:stat:: global proxy.process.http2.total_client_streams integer + :type: counter + + Represents the total number of HTTP/2 streams from client to the |TS|. + +.. ts:stat:: global proxy.process.http2.current_client_streams integer + :type: gauge + + Represents the current number of HTTP/2 streams from client to the |TS|. + +.. ts:stat:: global proxy.process.http2.total_transactions_time integer + :type: counter + :units: seconds + + Represents the total transaction time of HTTP/2 streams from client to the |TS|. + +.. ts:stat:: global proxy.process.http2.stream_errors integer + :type: counter + + Represents the total number of HTTP/2 stream errors. From 8b754734063d16795a0220be6cbe451f781fe681 Mon Sep 17 00:00:00 2001 From: Valentin Gutierrez Date: Thu, 29 Aug 2019 00:03:36 +0800 Subject: [PATCH 15/19] Provide stats for the recently introduced HTTP/2 rate limits Provide stats for the limits introduced by 9c09dbc11 (cherry picked from commit 5ec81125bd70d31f545cf959b65c4e929d26a192) --- .../statistics/core/http-connection.en.rst | 42 +++++++++++++++++++ proxy/http2/HTTP2.cc | 21 ++++++++++ proxy/http2/HTTP2.h | 6 +++ proxy/http2/Http2ConnectionState.cc | 6 +++ 4 files changed, 75 insertions(+) diff --git a/doc/admin-guide/monitoring/statistics/core/http-connection.en.rst b/doc/admin-guide/monitoring/statistics/core/http-connection.en.rst index 46d9db95ca8..d2e9014ffde 100644 --- a/doc/admin-guide/monitoring/statistics/core/http-connection.en.rst +++ b/doc/admin-guide/monitoring/statistics/core/http-connection.en.rst @@ -202,3 +202,45 @@ HTTP/2 Represents the total number of closed HTTP/2 connections with high error rate which is configured by :ts:cv:`proxy.config.http2.stream_error_rate_threshold`. + +.. ts:stat:: global proxy.process.http2.max_settings_per_frame_exceeded integer + :type: counter + + Represents the total number of closed HTTP/2 connections for exceeding the + maximum allowed number of settings per frame limit which is configured by + :ts:cv:`proxy.config.http2.max_settings_per_frame`. + +.. ts:stat:: global proxy.process.http2.max_settings_per_minute_exceeded integer + :type: counter + + Represents the total number of closed HTTP/2 connections for exceeding the + maximum allowed number of settings per minute limit which is configured by + :ts:cv:`proxy.config.http2.max_settings_per_minute`. + +.. ts:stat:: global proxy.process.http2.max_settings_frames_per_minute_exceeded integer + :type: counter + + Represents the total number of closed HTTP/2 connections for exceeding the + maximum allowed number of settings frames per minute limit which is configured by + :ts:cv:`proxy.config.http2.max_settings_frames_per_minute`. + +.. ts:stat:: global proxy.process.http2.max_ping_frames_per_minute_exceeded integer + :type: counter + + Represents the total number of closed HTTP/2 connections for exceeding the + maximum allowed number of ping frames per minute limit which is configured by + :ts:cv:`proxy.config.http2.max_ping_frames_per_minute`. + +.. ts:stat:: global proxy.process.http2.max_priority_frames_per_minute_exceeded integer + :type: counter + + Represents the total number of closed HTTP/2 connections for exceeding the + maximum allowed number of priority frames per minute limit which is configured by + :ts:cv:`proxy.config.http2.max_priority_frames_per_minute`. + +.. ts:stat:: global proxy.process.http2.insufficient_avg_window_update integer + :type: counter + + Represents the total number of closed HTTP/2 connections for not reaching the + minimum average window increment limit which is configured by + :ts:cv:`proxy.config.http2.min_avg_window_update`. diff --git a/proxy/http2/HTTP2.cc b/proxy/http2/HTTP2.cc index ddd74504522..8915ce76a70 100644 --- a/proxy/http2/HTTP2.cc +++ b/proxy/http2/HTTP2.cc @@ -63,6 +63,15 @@ static const char *const HTTP2_STAT_SESSION_DIE_INACTIVE_NAME = "pro static const char *const HTTP2_STAT_SESSION_DIE_EOS_NAME = "proxy.process.http2.session_die_eos"; static const char *const HTTP2_STAT_SESSION_DIE_ERROR_NAME = "proxy.process.http2.session_die_error"; static const char *const HTTP2_STAT_SESSION_DIE_HIGH_ERROR_RATE_NAME = "proxy.process.http2.session_die_high_error_rate"; +static const char *const HTTP2_STAT_MAX_SETTINGS_PER_FRAME_EXCEEDED_NAME = "proxy.process.http2.max_settings_per_frame_exceeded"; +static const char *const HTTP2_STAT_MAX_SETTINGS_PER_MINUTE_EXCEEDED_NAME = "proxy.process.http2.max_settings_per_minute_exceeded"; +static const char *const HTTP2_STAT_MAX_SETTINGS_FRAMES_PER_MINUTE_EXCEEDED_NAME = + "proxy.process.http2.max_settings_frames_per_minute_exceeded"; +static const char *const HTTP2_STAT_MAX_PING_FRAMES_PER_MINUTE_EXCEEDED_NAME = + "proxy.process.http2.max_ping_frames_per_minute_exceeded"; +static const char *const HTTP2_STAT_MAX_PRIORITY_FRAMES_PER_MINUTE_EXCEEDED_NAME = + "proxy.process.http2.max_priority_frames_per_minute_exceeded"; +static const char *const HTTP2_STAT_INSUFFICIENT_AVG_WINDOW_UPDATE_NAME = "proxy.process.http2.insufficient_avg_window_update"; union byte_pointer { byte_pointer(void *p) : ptr(p) {} @@ -820,6 +829,18 @@ Http2::init() static_cast(HTTP2_STAT_SESSION_DIE_ERROR), RecRawStatSyncSum); RecRegisterRawStat(http2_rsb, RECT_PROCESS, HTTP2_STAT_SESSION_DIE_HIGH_ERROR_RATE_NAME, RECD_INT, RECP_PERSISTENT, static_cast(HTTP2_STAT_SESSION_DIE_HIGH_ERROR_RATE), RecRawStatSyncSum); + RecRegisterRawStat(http2_rsb, RECT_PROCESS, HTTP2_STAT_MAX_SETTINGS_PER_FRAME_EXCEEDED_NAME, RECD_INT, RECP_PERSISTENT, + static_cast(HTTP2_STAT_MAX_SETTINGS_PER_FRAME_EXCEEDED), RecRawStatSyncSum); + RecRegisterRawStat(http2_rsb, RECT_PROCESS, HTTP2_STAT_MAX_SETTINGS_PER_MINUTE_EXCEEDED_NAME, RECD_INT, RECP_PERSISTENT, + static_cast(HTTP2_STAT_MAX_SETTINGS_PER_MINUTE_EXCEEDED), RecRawStatSyncSum); + RecRegisterRawStat(http2_rsb, RECT_PROCESS, HTTP2_STAT_MAX_SETTINGS_FRAMES_PER_MINUTE_EXCEEDED_NAME, RECD_INT, RECP_PERSISTENT, + static_cast(HTTP2_STAT_MAX_SETTINGS_FRAMES_PER_MINUTE_EXCEEDED), RecRawStatSyncSum); + RecRegisterRawStat(http2_rsb, RECT_PROCESS, HTTP2_STAT_MAX_PING_FRAMES_PER_MINUTE_EXCEEDED_NAME, RECD_INT, RECP_PERSISTENT, + static_cast(HTTP2_STAT_MAX_PING_FRAMES_PER_MINUTE_EXCEEDED), RecRawStatSyncSum); + RecRegisterRawStat(http2_rsb, RECT_PROCESS, HTTP2_STAT_MAX_PRIORITY_FRAMES_PER_MINUTE_EXCEEDED_NAME, RECD_INT, RECP_PERSISTENT, + static_cast(HTTP2_STAT_MAX_PRIORITY_FRAMES_PER_MINUTE_EXCEEDED), RecRawStatSyncSum); + RecRegisterRawStat(http2_rsb, RECT_PROCESS, HTTP2_STAT_INSUFFICIENT_AVG_WINDOW_UPDATE_NAME, RECD_INT, RECP_PERSISTENT, + static_cast(HTTP2_STAT_INSUFFICIENT_AVG_WINDOW_UPDATE), RecRawStatSyncSum); } #if TS_HAS_TESTS diff --git a/proxy/http2/HTTP2.h b/proxy/http2/HTTP2.h index 515aabdc91f..7d5d2d39770 100644 --- a/proxy/http2/HTTP2.h +++ b/proxy/http2/HTTP2.h @@ -84,6 +84,12 @@ enum { HTTP2_STAT_SESSION_DIE_EOS, HTTP2_STAT_SESSION_DIE_ERROR, HTTP2_STAT_SESSION_DIE_HIGH_ERROR_RATE, + HTTP2_STAT_MAX_SETTINGS_PER_FRAME_EXCEEDED, + HTTP2_STAT_MAX_SETTINGS_PER_MINUTE_EXCEEDED, + HTTP2_STAT_MAX_SETTINGS_FRAMES_PER_MINUTE_EXCEEDED, + HTTP2_STAT_MAX_PING_FRAMES_PER_MINUTE_EXCEEDED, + HTTP2_STAT_MAX_PRIORITY_FRAMES_PER_MINUTE_EXCEEDED, + HTTP2_STAT_INSUFFICIENT_AVG_WINDOW_UPDATE, HTTP2_N_STATS // Terminal counter, NOT A STAT INDEX. }; diff --git a/proxy/http2/Http2ConnectionState.cc b/proxy/http2/Http2ConnectionState.cc index e57e4bf1138..1ca13643b6a 100644 --- a/proxy/http2/Http2ConnectionState.cc +++ b/proxy/http2/Http2ConnectionState.cc @@ -421,6 +421,7 @@ rcv_priority_frame(Http2ConnectionState &cstate, const Http2Frame &frame) cstate.increment_received_priority_frame_count(); // Close this conection if its priority frame count received exceeds a limit if (cstate.get_received_priority_frame_count() > Http2::max_priority_frames_per_minute) { + HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_MAX_PRIORITY_FRAMES_PER_MINUTE_EXCEEDED, this_ethread()); Http2StreamDebug(cstate.ua_session, stream_id, "Observed too frequent priority changes: %u priority changes within a last minute", cstate.get_received_priority_frame_count()); @@ -537,6 +538,7 @@ rcv_settings_frame(Http2ConnectionState &cstate, const Http2Frame &frame) cstate.increment_received_settings_frame_count(); // Close this conection if its SETTINGS frame count exceeds a limit if (cstate.get_received_settings_frame_count() > Http2::max_settings_frames_per_minute) { + HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_MAX_SETTINGS_FRAMES_PER_MINUTE_EXCEEDED, this_ethread()); Http2StreamDebug(cstate.ua_session, stream_id, "Observed too frequent SETTINGS frames: %u frames within a last minute", cstate.get_received_settings_frame_count()); return Http2Error(Http2ErrorClass::HTTP2_ERROR_CLASS_CONNECTION, Http2ErrorCode::HTTP2_ERROR_ENHANCE_YOUR_CALM, @@ -575,6 +577,7 @@ rcv_settings_frame(Http2ConnectionState &cstate, const Http2Frame &frame) uint32_t n_settings = 0; while (nbytes < frame.header().length) { if (n_settings >= Http2::max_settings_per_frame) { + HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_MAX_SETTINGS_PER_FRAME_EXCEEDED, this_ethread()); Http2StreamDebug(cstate.ua_session, stream_id, "Observed too many settings in a frame"); return Http2Error(Http2ErrorClass::HTTP2_ERROR_CLASS_CONNECTION, Http2ErrorCode::HTTP2_ERROR_ENHANCE_YOUR_CALM, "recv settings too many settings in a frame"); @@ -615,6 +618,7 @@ rcv_settings_frame(Http2ConnectionState &cstate, const Http2Frame &frame) cstate.increment_received_settings_count(n_settings); // Close this conection if its settings count received exceeds a limit if (cstate.get_received_settings_count() > Http2::max_settings_per_minute) { + HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_MAX_SETTINGS_PER_MINUTE_EXCEEDED, this_ethread()); Http2StreamDebug(cstate.ua_session, stream_id, "Observed too frequent setting changes: %u settings within a last minute", cstate.get_received_settings_count()); return Http2Error(Http2ErrorClass::HTTP2_ERROR_CLASS_CONNECTION, Http2ErrorCode::HTTP2_ERROR_ENHANCE_YOUR_CALM, @@ -668,6 +672,7 @@ rcv_ping_frame(Http2ConnectionState &cstate, const Http2Frame &frame) cstate.increment_received_ping_frame_count(); // Close this conection if its ping count received exceeds a limit if (cstate.get_received_ping_frame_count() > Http2::max_ping_frames_per_minute) { + HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_MAX_PING_FRAMES_PER_MINUTE_EXCEEDED, this_ethread()); Http2StreamDebug(cstate.ua_session, stream_id, "Observed too frequent PING frames: %u PING frames within a last minute", cstate.get_received_ping_frame_count()); return Http2Error(Http2ErrorClass::HTTP2_ERROR_CLASS_CONNECTION, Http2ErrorCode::HTTP2_ERROR_ENHANCE_YOUR_CALM, @@ -2001,6 +2006,7 @@ Http2ConnectionState::increment_client_rwnd(size_t amount) double sum = std::accumulate(this->_recent_rwnd_increment.begin(), this->_recent_rwnd_increment.end(), 0.0); double avg = sum / this->_recent_rwnd_increment.size(); if (avg < Http2::min_avg_window_update) { + HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_INSUFFICIENT_AVG_WINDOW_UPDATE, this_ethread()); return Http2ErrorCode::HTTP2_ERROR_ENHANCE_YOUR_CALM; } return Http2ErrorCode::HTTP2_ERROR_NO_ERROR; From 777ba8509eef3637329d43590b6e5fc6217271ac Mon Sep 17 00:00:00 2001 From: Valentin Gutierrez Date: Wed, 28 Aug 2019 13:16:33 +0800 Subject: [PATCH 16/19] Allow disabling HTTP/2 priority frames limit (cherry picked from commit f2ebbcee400c3c91aa789382d7f7243797ed733c) --- doc/admin-guide/files/records.config.en.rst | 4 +++- proxy/http2/Http2ConnectionState.cc | 11 ++++++----- 2 files changed, 9 insertions(+), 6 deletions(-) diff --git a/doc/admin-guide/files/records.config.en.rst b/doc/admin-guide/files/records.config.en.rst index f0d80c56102..004932214ff 100644 --- a/doc/admin-guide/files/records.config.en.rst +++ b/doc/admin-guide/files/records.config.en.rst @@ -3623,7 +3623,9 @@ HTTP/2 Configuration Specifies how many number of PRIORITY frames |TS| receives for a minute at maximum. Clients exceeded this limit will be immediately disconnected with an error - code of ENHANCE_YOUR_CALM. + code of ENHANCE_YOUR_CALM. If this is set to 0, the limit logic is disabled. + This limit only will be enforced if :ts:cv:`proxy.config.http2.stream_priority_enabled` + is set to 1. .. ts:cv:: CONFIG proxy.config.http2.min_avg_window_update FLOAT 2560.0 :reloadable: diff --git a/proxy/http2/Http2ConnectionState.cc b/proxy/http2/Http2ConnectionState.cc index 1ca13643b6a..869e0ee200a 100644 --- a/proxy/http2/Http2ConnectionState.cc +++ b/proxy/http2/Http2ConnectionState.cc @@ -417,10 +417,15 @@ rcv_priority_frame(Http2ConnectionState &cstate, const Http2Frame &frame) "PRIORITY frame depends on itself"); } + if (!Http2::stream_priority_enabled) { + return Http2Error(Http2ErrorClass::HTTP2_ERROR_CLASS_NONE); + } + // Update PRIORITY frame count per minute cstate.increment_received_priority_frame_count(); // Close this conection if its priority frame count received exceeds a limit - if (cstate.get_received_priority_frame_count() > Http2::max_priority_frames_per_minute) { + if (Http2::max_priority_frames_per_minute != 0 && + cstate.get_received_priority_frame_count() > Http2::max_priority_frames_per_minute) { HTTP2_INCREMENT_THREAD_DYN_STAT(HTTP2_STAT_MAX_PRIORITY_FRAMES_PER_MINUTE_EXCEEDED, this_ethread()); Http2StreamDebug(cstate.ua_session, stream_id, "Observed too frequent priority changes: %u priority changes within a last minute", @@ -429,10 +434,6 @@ rcv_priority_frame(Http2ConnectionState &cstate, const Http2Frame &frame) "recv priority too frequent priority changes"); } - if (!Http2::stream_priority_enabled) { - return Http2Error(Http2ErrorClass::HTTP2_ERROR_CLASS_NONE); - } - Http2StreamDebug(cstate.ua_session, stream_id, "PRIORITY - dep: %d, weight: %d, excl: %d, tree size: %d", priority.stream_dependency, priority.weight, priority.exclusive_flag, cstate.dependency_tree->size()); From 6079998477479c1825798fe5ddbe01b54ba10869 Mon Sep 17 00:00:00 2001 From: Masakazu Kitajo Date: Wed, 23 Oct 2019 15:58:34 +0900 Subject: [PATCH 17/19] Add a config for internal HPACK header table size limit This introduces proxy.config.http2.header_table_size_limit that enables to configure internal HPACK header table size limit currently hard coded as 64KB. (cherry picked from commit 9c05e64df3e9eb00f786a42e29bfbdb4ffa76ec1) --- doc/admin-guide/files/records.config.en.rst | 10 +++++++++- mgmt/RecordsConfig.cc | 2 ++ proxy/http2/HTTP2.cc | 11 +++++++---- proxy/http2/HTTP2.h | 1 + 4 files changed, 19 insertions(+), 5 deletions(-) diff --git a/doc/admin-guide/files/records.config.en.rst b/doc/admin-guide/files/records.config.en.rst index 004932214ff..060ee746e9e 100644 --- a/doc/admin-guide/files/records.config.en.rst +++ b/doc/admin-guide/files/records.config.en.rst @@ -3527,7 +3527,15 @@ HTTP/2 Configuration :reloadable: The maximum size of the header compression table used to decode header - blocks. + blocks. This value will be advertised as SETTINGS_HEADER_TABLE_SIZE. + +.. ts:cv:: CONFIG proxy.config.http2.header_table_size_limit INT 65536 + :reloadable: + + The maximum size of the header compression table ATS actually use when ATS + encodes headers. Setting 0 means ATS doesn't insert headers into HPACK + Dynamic Table, however, headers still can be encoded as indexable + representations. The upper limit is 65536. .. ts:cv:: CONFIG proxy.config.http2.max_header_list_size INT 4294967295 :reloadable: diff --git a/mgmt/RecordsConfig.cc b/mgmt/RecordsConfig.cc index dbcb07f1b4b..e7dc9475523 100644 --- a/mgmt/RecordsConfig.cc +++ b/mgmt/RecordsConfig.cc @@ -1346,6 +1346,8 @@ static const RecordElement RecordsConfig[] = , {RECT_CONFIG, "proxy.config.http2.min_avg_window_update", RECD_FLOAT, "2560.0", RECU_DYNAMIC, RR_NULL, RECC_NULL, nullptr, RECA_NULL} , + {RECT_CONFIG, "proxy.config.http2.header_table_size_limit", RECD_INT, "65536", RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL} + , //# Add LOCAL Records Here {RECT_LOCAL, "proxy.local.incoming_ip_to_bind", RECD_STRING, nullptr, RECU_NULL, RR_NULL, RECC_NULL, nullptr, RECA_NULL} diff --git a/proxy/http2/HTTP2.cc b/proxy/http2/HTTP2.cc index 8915ce76a70..5be510856bd 100644 --- a/proxy/http2/HTTP2.cc +++ b/proxy/http2/HTTP2.cc @@ -42,8 +42,8 @@ const unsigned HTTP2_LEN_AUTHORITY = countof(":authority") - 1; const unsigned HTTP2_LEN_PATH = countof(":path") - 1; const unsigned HTTP2_LEN_STATUS = countof(":status") - 1; -static size_t HTTP2_LEN_STATUS_VALUE_STR = 3; -static const int HTTP2_MAX_TABLE_SIZE_LIMIT = 64 * 1024; +static size_t HTTP2_LEN_STATUS_VALUE_STR = 3; +static const uint32_t HTTP2_MAX_TABLE_SIZE_LIMIT = 64 * 1024; // Statistics RecRawStatBlock *http2_rsb; @@ -597,8 +597,9 @@ Http2ErrorCode http2_encode_header_blocks(HTTPHdr *in, uint8_t *out, uint32_t out_len, uint32_t *len_written, HpackHandle &handle, int32_t maximum_table_size) { - // Limit the maximum table size to 64kB, which is the size advertised by major clients - maximum_table_size = std::min(maximum_table_size, HTTP2_MAX_TABLE_SIZE_LIMIT); + // Limit the maximum table size to the configured value or 64kB at maximum, which is the size advertised by major clients + maximum_table_size = + std::min(maximum_table_size, static_cast(std::min(Http2::header_table_size_limit, HTTP2_MAX_TABLE_SIZE_LIMIT))); // Set maximum table size only if it is different from current maximum size if (maximum_table_size == hpack_get_maximum_table_size(handle)) { maximum_table_size = -1; @@ -751,6 +752,7 @@ uint32_t Http2::max_priority_frames_per_minute = 120; float Http2::min_avg_window_update = 2560.0; uint32_t Http2::con_slow_log_threshold = 0; uint32_t Http2::stream_slow_log_threshold = 0; +uint32_t Http2::header_table_size_limit = 65536; void Http2::init() @@ -777,6 +779,7 @@ Http2::init() REC_EstablishStaticConfigFloat(min_avg_window_update, "proxy.config.http2.min_avg_window_update"); REC_EstablishStaticConfigInt32U(con_slow_log_threshold, "proxy.config.http2.connection.slow.log.threshold"); REC_EstablishStaticConfigInt32U(stream_slow_log_threshold, "proxy.config.http2.stream.slow.log.threshold"); + REC_EstablishStaticConfigInt32U(header_table_size_limit, "proxy.config.http2.header_table_size_limit"); // If any settings is broken, ATS should not start ink_release_assert(http2_settings_parameter_is_valid({HTTP2_SETTINGS_MAX_CONCURRENT_STREAMS, max_concurrent_streams_in})); diff --git a/proxy/http2/HTTP2.h b/proxy/http2/HTTP2.h index 7d5d2d39770..660ecbb4bf0 100644 --- a/proxy/http2/HTTP2.h +++ b/proxy/http2/HTTP2.h @@ -393,6 +393,7 @@ class Http2 static float min_avg_window_update; static uint32_t con_slow_log_threshold; static uint32_t stream_slow_log_threshold; + static uint32_t header_table_size_limit; static void init(); }; From c809466b5b29ac0f7a6240b9d5be44afecefa3b3 Mon Sep 17 00:00:00 2001 From: Masaori Koshiba Date: Wed, 30 Oct 2019 11:20:54 +0900 Subject: [PATCH 18/19] Replace container of HPACK dynamic table from std::vector to std::deque (cherry picked from commit 323d5b59fb84c2bb73c2679bd8924b530e26ce3a) --- proxy/http2/HPACK.cc | 20 ++++++++------------ proxy/http2/HPACK.h | 4 ++-- 2 files changed, 10 insertions(+), 14 deletions(-) diff --git a/proxy/http2/HPACK.cc b/proxy/http2/HPACK.cc index b13e7c6b127..4dcf72942d8 100644 --- a/proxy/http2/HPACK.cc +++ b/proxy/http2/HPACK.cc @@ -354,7 +354,7 @@ HpackDynamicTable::~HpackDynamicTable() const MIMEField * HpackDynamicTable::get_header_field(uint32_t index) const { - return this->_headers.at(this->_headers.size() - index - 1); + return this->_headers.at(index); } void @@ -380,8 +380,7 @@ HpackDynamicTable::add_header_field(const MIMEField *field) MIMEField *new_field = this->_mhdr->field_create(name, name_len); new_field->value_set(this->_mhdr->m_heap, this->_mhdr->m_mime, value, value_len); this->_mhdr->field_attach(new_field); - // XXX Because entire Vec instance is copied, Its too expensive! - this->_headers.push_back(new_field); + this->_headers.push_front(new_field); } } @@ -414,7 +413,7 @@ HpackDynamicTable::update_maximum_size(uint32_t new_size) uint32_t HpackDynamicTable::length() const { - return _headers.size(); + return this->_headers.size(); } bool @@ -425,23 +424,20 @@ HpackDynamicTable::_evict_overflowed_entries() return true; } - size_t count = 0; - for (auto &h : this->_headers) { + for (auto h = this->_headers.rbegin(); h != this->_headers.rend(); ++h) { int name_len, value_len; - h->name_get(&name_len); - h->value_get(&value_len); + (*h)->name_get(&name_len); + (*h)->value_get(&value_len); this->_current_size -= ADDITIONAL_OCTETS + name_len + value_len; - this->_mhdr->field_delete(h, false); - ++count; + this->_mhdr->field_delete(*h, false); + this->_headers.pop_back(); if (this->_current_size <= this->_maximum_size) { break; } } - this->_headers.erase(this->_headers.begin(), this->_headers.begin() + count); - if (this->_headers.size() == 0) { return false; } diff --git a/proxy/http2/HPACK.h b/proxy/http2/HPACK.h index f36c0c703aa..34d1f6d4359 100644 --- a/proxy/http2/HPACK.h +++ b/proxy/http2/HPACK.h @@ -28,7 +28,7 @@ #include "HTTP.h" #include "../hdrs/XPACK.h" -#include +#include // It means that any header field can be compressed/decompressed by ATS const static int HPACK_ERROR_COMPRESSION_ERROR = -1; @@ -132,7 +132,7 @@ class HpackDynamicTable MIMEHdr *_mhdr = nullptr; MIMEHdr *_mhdr_old = nullptr; - std::vector _headers; + std::deque _headers; }; // [RFC 7541] 2.3. Indexing Table From b12129dc571cbfdcee9574848e464c5f4b043138 Mon Sep 17 00:00:00 2001 From: Sudheer Vinukonda Date: Fri, 27 Sep 2019 10:15:41 -0700 Subject: [PATCH 19/19] Make sure shutdown_cont_event isn't holding any garbage references. As it seems like there could be a race condition because the handling of HTTP2_SESSION_EVENT_SHUTDOWN_INIT is going through the event loop again and therefore may come in after the Session and its associated contexts are already cleaned up thus causing an use-after-free possibility (cherry picked from commit b0685dbd4d00f303ded4727a74f06d0a7cddcd93) --- proxy/http2/Http2ConnectionState.h | 1 + 1 file changed, 1 insertion(+) diff --git a/proxy/http2/Http2ConnectionState.h b/proxy/http2/Http2ConnectionState.h index 489ea9aa2fb..17726fc1231 100644 --- a/proxy/http2/Http2ConnectionState.h +++ b/proxy/http2/Http2ConnectionState.h @@ -142,6 +142,7 @@ class Http2ConnectionState : public Continuation { if (shutdown_cont_event) { shutdown_cont_event->cancel(); + shutdown_cont_event = nullptr; } cleanup_streams();