diff --git a/doc/admin-guide/plugins/cache_range_requests.en.rst b/doc/admin-guide/plugins/cache_range_requests.en.rst index 6d11d21121a..0189122f36a 100644 --- a/doc/admin-guide/plugins/cache_range_requests.en.rst +++ b/doc/admin-guide/plugins/cache_range_requests.en.rst @@ -113,7 +113,7 @@ all requests (include partial content) will use consistent hashing method for parent selection. -X-CRR-IMS header support +X-Crr-Ims header support ------------------------ .. option:: --consider-ims @@ -125,13 +125,13 @@ special header: .. code:: - X-CRR-IMS: Tue, 19 Nov 2019 13:26:45 GMT + X-Crr-Ims: Tue, 19 Nov 2019 13:26:45 GMT -When this header is provided and a `cache hit fresh` is encoutered the +When this header is provided and a `cache hit fresh` is encountered the ``Date`` header of the object in cache is compared to this header date value. If the cache date is *less* than this IMS date then the object is marked as STALE and an appropriate If-Modified-Since or If-Match -request along with this X-CRR-IMS header is passed up to the parent. +request along with this X-Crr-Ims header is passed up to the parent. In order for this to properly work in a CDN each cache in the chain *SHOULD* also contain a remap rule with the diff --git a/doc/admin-guide/plugins/slice.en.rst b/doc/admin-guide/plugins/slice.en.rst index 8c7063d826f..e04668952d5 100644 --- a/doc/admin-guide/plugins/slice.en.rst +++ b/doc/admin-guide/plugins/slice.en.rst @@ -75,15 +75,6 @@ The slice plugin supports the following options:: Limited to any positive number. Ignored if --blockbytes provided. - --remap-host= (optional) - Uses effective url with given hostname for remapping. - Requires setting up an intermediate loopback remap rule. - -r for short - - --pace-errorlog= (optional) - Limit stitching error logs to every 'n' second(s) - -p for short - --disable-errorlog (optional) Disable writing block stitch errors to the error log. -d for short @@ -100,6 +91,37 @@ The slice plugin supports the following options:: Cannot be used with --exclude-regex -i for short + --pace-errorlog= (optional) + Limit stitching error logs to every 'n' second(s) + -p for short + + --ref-relative (optional) + Self healing mode typically uses slice 0 as the reference slice + for every request. This is very safe but also increases plugin + time and latency as the first slice is always fully processed + whether or not the original requests needs any data from slice 0. + This option uses the first slice in the request as reference + which has better performance. A downside of this mode is that + self healing won't happen if blocks in a request agree. + Normally leave this off. + -l for short + + --remap-host= (optional) + Uses effective url with given hostname for remapping. + Requires setting up an intermediate loopback remap rule. + -r for short + + --throttle (optional) + Under certain circumstances where many contiguous slices are in + RAM cache ATS will aggressively try to push these through the + slice plugin. The downside of this is that all these contiguous + slices end up being marked as fresh even if the downstream + client aborts. This option keeps track of how much data the + client has already passed down and slows down issuing new + slice requests. + Normally leave this off. + -o for short + Examples:: @plugin=slice.so @pparam=--blockbytes=1000000 @plugin=cache_range_requests.so @@ -194,21 +216,50 @@ adding in range request headers ("Range: bytes="). A special header X-Slicer-Info header is added and the pristine URL is restored. -For each of these blocks separate sequential TSHttpConnect(s) are made -back into the front end of ATS and all of the remap plugins are rerun. -Slice skips the remap due to presence of the X-Slicer-Info header and -allows cache_range_requests.so to serve the slice block back to Slice -either via cache OR parent request. - -Slice assembles a header based on the first slice block response and -sends it to the client. If necessary it then skips over bytes in -the first block and starts sending byte content, examining each -block header and sends its bytes to the client until the client -request is satisfied. - -Any extra bytes at the end of the last block are consumed by -the Slice plugin to allow cache_range_requests to finish -the block fetch to ensure the block is cached. +For each of these blocks separate sequential TSHttpConnect(s) are +made back into the front end of ATS. By default of the remap plugins +are rerun. Slice skips the remap due to presence of the X-Slicer-Info +header and allows cache_range_requests.so to serve the slice block back +to Slice either via cache OR parent request. + +Slice assembles a header based on the very first slice block response +and sends it to the client. If necessary it then skips over bytes in the +first block and starts sending byte content, examining each block header +and sends its bytes to the client until the client request is satisfied. + +Any extra bytes at the end of the last block are consumed by the the +Slice plugin to allow cache_range_requests to finish the block fetch to +ensure the block is cached. + +Self Healing +------------ + +The slice plugin uses the very first slice as a reference slice which +uses content-length and last-modified and/or etags to ensure assembled +blocks come from the same asset. In the case where a slice from a parent +is fetched which indicates that the asset has changed, the slice plugin +will attempt to self heal the asset. The `cache_range_requests` plugin +must be configured with the `--consider-ims` parameter in order for +this to work. + +Example `remap.config` configuration:: + + map http://slice/ http://parent/ @plugin=slice.so @pparam=--remap-host=cache_range_requests + map http://cache_range_requests/ http://parent/ @plugin=cache_range_requests.so @pparam=--consider-ims + +When a request is served, the slice plugin uses reference slice 0 to +build a response to the client. When subsequent slices are fetched they +are checked against this reference slice. If a mismatch occurs an IMS +request for the offending slice is made through the `cache_range_requests` +plugin using an X-Crr-Ims header. If the refetched slice still mismatches +then the client connection is aborted a crr IMS request is made for +the reference slice in an attempt to refetch it. + +Optionally (but not recommended) the plugin may be configured to use +the first slice in the request as the reference slice. This option +is faster since it does not visit any slices outside those needed to +fulfill a request. However this may still cause problems if the +requested range was calculated from a newer version of the asset. Important Notes =============== @@ -216,8 +267,8 @@ Important Notes This plugin assumes that the content requested is cacheable. Any first block server response that is not a 206 is passed directly -down to the client. If that response is a '200' only the first -portion of the response is passed back and the transaction is closed. +down to the client. Any 200 responses are passed back through to +the client. Only the first server response block is used to evaluate any "If-" conditional headers. Subsequent server slice block requests diff --git a/include/ts/experimental.h b/include/ts/experimental.h index d2ebfd0211a..52118f7d3d4 100644 --- a/include/ts/experimental.h +++ b/include/ts/experimental.h @@ -452,6 +452,16 @@ tsapi TSMBuffer TSFetchRespHdrMBufGet(TSFetchSM fetch_sm); */ tsapi TSMLoc TSFetchRespHdrMLocGet(TSFetchSM fetch_sm); +/* + * Parse a MIME header date string. + */ +tsapi time_t TSMimeParseDate(char const *const value_str, int const value_len); + +/* + * Print as a MIME header date string. + */ +tsapi TSReturnCode TSMimeFormatDate(time_t const value_time, char *const value_str, int *const value_len); + #ifdef __cplusplus } #endif /* __cplusplus */ diff --git a/plugins/cache_range_requests/cache_range_requests.cc b/plugins/cache_range_requests/cache_range_requests.cc index 41a770221ba..0ca59d9765e 100644 --- a/plugins/cache_range_requests/cache_range_requests.cc +++ b/plugins/cache_range_requests/cache_range_requests.cc @@ -29,6 +29,7 @@ #include "ts/ts.h" #include "ts/remap.h" +#include #include #include #include @@ -58,7 +59,7 @@ struct txndata { }; // Header for optional revalidation -constexpr std::string_view X_IMS_HEADER = {"X-CRR-IMS"}; +constexpr std::string_view X_IMS_HEADER = {"X-Crr-Ims"}; // pluginconfig struct (global plugin only) pluginconfig *gPluginConfig = {nullptr}; @@ -240,6 +241,7 @@ range_header_check(TSHttpTxn txnp, pluginconfig *const pc) TSMLoc const imsloc = TSMimeHdrFieldFind(hdr_buf, hdr_loc, X_IMS_HEADER.data(), X_IMS_HEADER.size()); if (TS_NULL_MLOC != imsloc) { time_t const itime = TSMimeHdrFieldValueDateGet(hdr_buf, hdr_loc, imsloc); + DEBUG_LOG("Servicing the '%.*s' header", (int)X_IMS_HEADER.size(), X_IMS_HEADER.data()); TSHandleMLocRelease(hdr_buf, hdr_loc, imsloc); if (0 < itime) { txn_state->ims_time = itime; @@ -477,6 +479,7 @@ handle_cache_lookup_complete(TSHttpTxn txnp, txndata *const txn_state) if (TS_SUCCESS == TSHttpTxnCacheLookupStatusGet(txnp, &cachestat)) { if (TS_CACHE_LOOKUP_HIT_FRESH == cachestat) { time_t const ch_time = get_date_from_cached_hdr(txnp); + DEBUG_LOG("IMS Cached header time %" PRId64 " vs IMS %" PRId64, ch_time, txn_state->ims_time); if (ch_time < txn_state->ims_time) { TSHttpTxnCacheLookupStatusSet(txnp, TS_CACHE_LOOKUP_HIT_STALE); if (TSIsDebugTagSet(PLUGIN_NAME)) { diff --git a/plugins/experimental/slice/Config.cc b/plugins/experimental/slice/Config.cc index 17b7329c656..2ff68662d6e 100644 --- a/plugins/experimental/slice/Config.cc +++ b/plugins/experimental/slice/Config.cc @@ -111,6 +111,7 @@ Config::fromArgs(int const argc, char const *const argv[]) {const_cast("disable-errorlog"), no_argument, nullptr, 'd'}, {const_cast("exclude-regex"), required_argument, nullptr, 'e'}, {const_cast("include-regex"), required_argument, nullptr, 'i'}, + {const_cast("ref-relative"), no_argument, nullptr, 'l'}, {const_cast("throttle"), no_argument, nullptr, 'o'}, {const_cast("pace-errorlog"), required_argument, nullptr, 'p'}, {const_cast("remap-host"), required_argument, nullptr, 'r'}, @@ -121,7 +122,7 @@ Config::fromArgs(int const argc, char const *const argv[]) // getopt assumes args start at '1' so this hack is needed char *const *argvp = (const_cast(argv) - 1); for (;;) { - int const opt = getopt_long(argc + 1, argvp, "b:de:i:op:r:t:", longopts, nullptr); + int const opt = getopt_long(argc + 1, argvp, "b:de:i:lop:r:t:", longopts, nullptr); if (-1 == opt) { break; } @@ -177,6 +178,10 @@ Config::fromArgs(int const argc, char const *const argv[]) DEBUG_LOG("Using regex for url include: '%s'", m_regexstr.c_str()); } } break; + case 'l': { + m_reftype = RefType::Relative; + DEBUG_LOG("Reference slice relative to request (not slice block 0)"); + } break; case 'o': { m_throttle = true; DEBUG_LOG("Enabling internal block throttling"); diff --git a/plugins/experimental/slice/Config.h b/plugins/experimental/slice/Config.h index 5edf4638f07..1f59511e8c0 100644 --- a/plugins/experimental/slice/Config.h +++ b/plugins/experimental/slice/Config.h @@ -43,6 +43,8 @@ struct Config { pcre_extra *m_regex_extra{nullptr}; bool m_throttle{false}; // internal block throttling int m_paceerrsecs{0}; // -1 disable logging, 0 no pacing, max 60s + enum RefType { First, Relative }; + RefType m_reftype{First}; // reference slice is relative to request // Convert optarg to bytes static int64_t bytesFrom(char const *const valstr); diff --git a/plugins/experimental/slice/ContentRange.h b/plugins/experimental/slice/ContentRange.h index 2412e668433..3755a96e80f 100644 --- a/plugins/experimental/slice/ContentRange.h +++ b/plugins/experimental/slice/ContentRange.h @@ -25,12 +25,13 @@ Range is converted from closed range into a half open range for. */ struct ContentRange { - int64_t m_beg = -1; - int64_t m_end = -1; // half open - int64_t m_length = -1; // full content length + int64_t m_beg{-1}; + int64_t m_end{-1}; // half open + int64_t m_length{-1}; // full content length ContentRange() {} explicit ContentRange(int64_t const begin, int64_t const end, int64_t const len) : m_beg(begin), m_end(end), m_length(len) {} + bool isValid() const { @@ -38,6 +39,7 @@ struct ContentRange { } /** parsed from a Content-Range field + * Must be null terminated. */ bool fromStringClosed(char const *const valstr); diff --git a/plugins/experimental/slice/Data.cc b/plugins/experimental/slice/Data.cc deleted file mode 100644 index aac6943d47b..00000000000 --- a/plugins/experimental/slice/Data.cc +++ /dev/null @@ -1,65 +0,0 @@ -/** @file - 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 "Data.h" - -#include -#include -#include -#include -#include - -namespace -{ -std::mutex mutex; -int64_t inplay = 0; -std::unique_ptr thread; -} // namespace - -void -monitor() -{ - std::lock_guard guard(mutex); - // while (0 < inplay) - while (true) { - mutex.unlock(); - std::this_thread::sleep_for(std::chrono::seconds(10)); - std::cerr << "Inplay: " << inplay << std::endl; - mutex.lock(); - } - // thread.release(); -} - -void -incrData() -{ - std::lock_guard const guard(mutex); - if (!thread) { - thread.reset(new std::thread(monitor)); - } - - ++inplay; -} - -void -decrData() -{ - std::lock_guard const guard(mutex); - --inplay; - assert(0 <= inplay); -} diff --git a/plugins/experimental/slice/Data.h b/plugins/experimental/slice/Data.h index 3150bd299b8..e29ad8420ea 100644 --- a/plugins/experimental/slice/Data.h +++ b/plugins/experimental/slice/Data.h @@ -28,6 +28,18 @@ struct Config; +enum BlockState { + Pending, + PendingInt, // Pending internal refectch + PendingRef, // Pending reference refetch + Active, + ActiveInt, // Active internal refetch + ActiveRef, // Active reference refetch + Done, + Passthru, // non 206 response passthru + Fail, +}; + struct Data { Data(Data const &) = delete; Data &operator=(Data const &) = delete; @@ -41,32 +53,34 @@ struct Data { TSMLoc m_urlloc{nullptr}; char m_hostname[8192]; - int m_hostlen; + int m_hostlen{0}; + + // read from slice block 0 + char m_date[33]; + int m_datelen{0}; char m_etag[8192]; - int m_etaglen; - char m_lastmodified[8192]; - int m_lastmodifiedlen; + int m_etaglen{0}; + char m_lastmodified[33]; + int m_lastmodifiedlen{0}; - TSHttpStatus m_statustype; // 200 or 206 + int64_t m_contentlen{-1}; - bool m_bail; // non 206/200 response + TSHttpStatus m_statustype{TS_HTTP_STATUS_NONE}; // 200 or 206 Range m_req_range; // converted to half open interval - int64_t m_contentlen; - int64_t m_blocknum; // block number to work on, -1 bad/stop - int64_t m_blockexpected; // body bytes expected - int64_t m_blockskip; // number of bytes to skip in this block - int64_t m_blockconsumed; // body bytes consumed + int64_t m_blocknum{-1}; // block number to work on, -1 bad/stop + int64_t m_blockexpected{0}; // body bytes expected + int64_t m_blockskip{0}; // number of bytes to skip in this block + int64_t m_blockconsumed{0}; // body bytes consumed - enum BlockState { Pending, Active, Done, Fail }; - BlockState m_blockstate; // is there an active slice block + BlockState m_blockstate{Pending}; // is there an active slice block - int64_t m_bytestosend; // header + content bytes to send - int64_t m_bytessent; // number of bytes written to the client + int64_t m_bytestosend{0}; // header + content bytes to send + int64_t m_bytessent{0}; // number of bytes written to the client - bool m_server_block_header_parsed; - bool m_server_first_header_parsed; + bool m_server_block_header_parsed{false}; + bool m_server_first_header_parsed{false}; Stage m_upstream; Stage m_dnstream; @@ -76,31 +90,12 @@ struct Data { TSHttpParser m_http_parser{nullptr}; //!< cached for reuse - explicit Data(Config *const config) - : m_config(config), - m_client_ip(), - m_urlbuf(nullptr), - m_urlloc(nullptr), - m_hostlen(0), - m_etaglen(0), - m_lastmodifiedlen(0), - m_statustype(TS_HTTP_STATUS_NONE), - m_req_range(-1, -1), - m_contentlen(-1), - m_blocknum(-1), - m_blockexpected(0), - m_blockskip(0), - m_blockconsumed(0), - m_blockstate(Pending), - m_bytestosend(0), - m_bytessent(0), - m_server_block_header_parsed(false), - m_server_first_header_parsed(false), - m_http_parser(nullptr) + explicit Data(Config *const config) : m_config(config) { + m_date[0] = '\0'; m_hostname[0] = '\0'; - m_lastmodified[0] = '\0'; m_etag[0] = '\0'; + m_lastmodified[0] = '\0'; #if defined(COLLECT_STATS) TSStatIntIncrement(stats::DataCreate, 1); #endif @@ -114,11 +109,14 @@ struct Data { if (nullptr != m_urlbuf) { if (nullptr != m_urlloc) { TSHandleMLocRelease(m_urlbuf, TS_NULL_MLOC, m_urlloc); + m_urlloc = nullptr; } TSMBufferDestroy(m_urlbuf); + m_urlbuf = nullptr; } if (nullptr != m_http_parser) { TSHttpParserDestroy(m_http_parser); + m_http_parser = nullptr; } } }; diff --git a/plugins/experimental/slice/HttpHeader.cc b/plugins/experimental/slice/HttpHeader.cc index f70c42e264c..2a66e5a20d3 100644 --- a/plugins/experimental/slice/HttpHeader.cc +++ b/plugins/experimental/slice/HttpHeader.cc @@ -20,6 +20,7 @@ #include "slice.h" +#include #include #include @@ -231,6 +232,59 @@ HttpHeader::setKeyVal(char const *const keystr, int const keylen, char const *co return status; } +bool +HttpHeader::timeForKey(char const *const keystr, int const keylen, time_t *const timeval) const +{ + TSAssert(nullptr != timeval); + + if (!isValid()) { + *timeval = 0; + return false; + } + + bool status = false; + + TSMLoc const locfield = TSMimeHdrFieldFind(m_buffer, m_lochdr, keystr, keylen); + + if (nullptr != locfield) { + *timeval = TSMimeHdrFieldValueDateGet(m_buffer, m_lochdr, locfield); + TSHandleMLocRelease(m_buffer, m_lochdr, locfield); + } else { + *timeval = 0; + } + + return status; +} + +bool +HttpHeader::setKeyTime(char const *const keystr, int const keylen, time_t const timeval) +{ + if (!isValid()) { + return false; + } + + bool status(false); + + TSMLoc locfield(TSMimeHdrFieldFind(m_buffer, m_lochdr, keystr, keylen)); + + if (nullptr == locfield) { + DEBUG_LOG("Creating header %.*s", keylen, keystr); + TSMimeHdrFieldCreateNamed(m_buffer, m_lochdr, keystr, keylen, &locfield); + } + + if (nullptr != locfield) { + if (TS_SUCCESS == TSMimeHdrFieldValueDateSet(m_buffer, m_lochdr, locfield, timeval)) { + if (TS_SUCCESS == TSMimeHdrFieldAppend(m_buffer, m_lochdr, locfield)) { + status = true; + DEBUG_LOG("Set header %.*s to %" PRId64, keylen, keystr, timeval); + } + } + TSHandleMLocRelease(m_buffer, m_lochdr, locfield); + } + + return status; +} + std::string HttpHeader::toString() const { diff --git a/plugins/experimental/slice/HttpHeader.h b/plugins/experimental/slice/HttpHeader.h index 001e5f6480a..e22b83d4bf6 100644 --- a/plugins/experimental/slice/HttpHeader.h +++ b/plugins/experimental/slice/HttpHeader.h @@ -47,6 +47,7 @@ struct HttpHeader { TSMLoc const m_lochdr; explicit HttpHeader(TSMBuffer buffer, TSMLoc lochdr) : m_buffer(buffer), m_lochdr(lochdr) {} + bool isValid() const { @@ -112,6 +113,7 @@ struct HttpHeader { // returns false if header invalid or something went wrong with removal. bool removeKey(char const *const key, int const keylen); + // retrieves header value as a char* bool valueForKey(char const *const keystr, int const keylen, char *const valstr, // <-- return string value int *const vallen, // <-- pass in capacity, returns len of string @@ -125,6 +127,12 @@ struct HttpHeader { int const index = -1 // sets all values ); + // retrieves header value as a time_t + bool timeForKey(char const *const keystr, int const keylen, time_t *const timeval) const; + + // sets header value as a time_t + bool setKeyTime(char const *const key, int const keylen, time_t const timeval); + /** dump header into provided char buffer */ std::string toString() const; diff --git a/plugins/experimental/slice/Range.h b/plugins/experimental/slice/Range.h index 8c8826d2091..ba581c6a37a 100644 --- a/plugins/experimental/slice/Range.h +++ b/plugins/experimental/slice/Range.h @@ -31,8 +31,8 @@ struct Range { public: static int64_t constexpr maxval = (std::numeric_limits::max() >> 2); - int64_t m_beg = -1; - int64_t m_end = -1; // half open + int64_t m_beg{-1}; + int64_t m_end{-1}; // half open Range() {} explicit Range(int64_t const begin, int64_t const end) : m_beg(begin), m_end(end) {} diff --git a/plugins/experimental/slice/client.cc b/plugins/experimental/slice/client.cc index 5d4bde5e690..1ad1b74f2f1 100644 --- a/plugins/experimental/slice/client.cc +++ b/plugins/experimental/slice/client.cc @@ -27,6 +27,9 @@ bool handle_client_req(TSCont contp, TSEvent event, Data *const data) { +#if defined(COLLECT_STATS) + stats::StatsRAI const rai(stats::ClientTime); +#endif switch (event) { case TS_EVENT_VCONN_READ_READY: case TS_EVENT_VCONN_READ_COMPLETE: { @@ -85,15 +88,19 @@ handle_client_req(TSCont contp, TSEvent event, Data *const data) rangebe = Range(0, Range::maxval); } - // set to the first block in range - data->m_blocknum = rangebe.firstBlockFor(data->m_config->m_blockbytes); + if (Config::RefType::First == data->m_config->m_reftype) { + data->m_blocknum = 0; + } else { + data->m_blocknum = rangebe.firstBlockFor(data->m_config->m_blockbytes); + } + data->m_req_range = rangebe; // remove ATS keys to avoid 404 loop header.removeKey(TS_MIME_FIELD_VIA, TS_MIME_LEN_VIA); header.removeKey(TS_MIME_FIELD_X_FORWARDED_FOR, TS_MIME_LEN_X_FORWARDED_FOR); - // send the first block request to server + // send block request to server if (!request_block(contp, data)) { abort(contp, data); return false; @@ -119,15 +126,28 @@ handle_client_req(TSCont contp, TSEvent event, Data *const data) void handle_client_resp(TSCont contp, TSEvent event, Data *const data) { - DEBUG_LOG("%p handle_client_resp %s", data, TSHttpEventNameLookup(event)); - #if defined(COLLECT_STATS) TSStatIntIncrement(stats::Client, 1); + stats::StatsRAI const rai(stats::ClientTime); #endif switch (event) { case TS_EVENT_VCONN_WRITE_READY: { - if (Data::BlockState::Pending == data->m_blockstate) { + switch (data->m_blockstate) { + case BlockState::Fail: + case BlockState::PendingRef: + case BlockState::ActiveRef: { + TSVIO const output_vio = data->m_dnstream.m_write.m_vio; + int64_t const output_done = TSVIONDoneGet(output_vio); + int64_t const output_sent = data->m_bytessent; + + if (output_sent == output_done) { + DEBUG_LOG("Downstream output is done, shutting down"); + shutdown(contp, data); + } + } break; + + case BlockState::Pending: { bool start_next_block = true; if (data->m_config->m_throttle) { @@ -140,11 +160,17 @@ handle_client_resp(TSCont contp, TSEvent event, Data *const data) start_next_block = false; DEBUG_LOG("%p handle_client_resp: throttling %" PRId64, data, (output_done - output_sent)); } - } - if (start_next_block) { - request_block(contp, data); + if (start_next_block) { + DEBUG_LOG("Starting next block request"); + request_block(contp, data); + } } + } break; + case BlockState::Passthru: { + } break; + default: + break; } } break; case TS_EVENT_VCONN_WRITE_COMPLETE: { diff --git a/plugins/experimental/slice/server.cc b/plugins/experimental/slice/server.cc index 5356806a52f..54b7ce19f9d 100644 --- a/plugins/experimental/slice/server.cc +++ b/plugins/experimental/slice/server.cc @@ -46,19 +46,62 @@ contentRangeFrom(HttpHeader const &header) if (!hasContentRange) { DEBUG_LOG("invalid response header, no Content-Range"); - } else if (!bcr.fromStringClosed(rangestr)) { - DEBUG_LOG("invalid response header, malformed Content-Range, %s", rangestr); + } else { + // ensure null termination + rangestr[rangelen] = '\0'; + if (!bcr.fromStringClosed(rangestr)) { + DEBUG_LOG("invalid response header, malformed Content-Range, %s", rangestr); + } } return bcr; } -bool +int64_t +contentLengthFrom(HttpHeader const &header) +{ + int64_t bytes = 0; + + char constr[1024]; + int conlen = sizeof(constr); + + // look for expected Content-Length field + bool const hasContentLength(header.valueForKey(TS_MIME_FIELD_CONTENT_LENGTH, TS_MIME_LEN_CONTENT_LENGTH, constr, &conlen)); + + if (!hasContentLength) { + DEBUG_LOG("invalid response header, no Content-Length"); + bytes = INT64_MAX; + } else { + // ensure null termination + constr[conlen] = '\0'; + char *endptr = nullptr; + bytes = std::max((int64_t)0, (int64_t)strtoll(constr, &endptr, 10)); + } + + return bytes; +} + +// Also reference server header +enum HeaderState { + Good, + Fail, + Passthru, +}; + +HeaderState handleFirstServerHeader(Data *const data, TSCont const contp) { +#if defined(COLLECT_STATS) + stats::StatsRAI const rai(stats::FirstHeaderTime); +#endif + + HeaderState state = HeaderState::Good; + HttpHeader header(data->m_resp_hdrmgr.m_buffer, data->m_resp_hdrmgr.m_lochdr); - // DEBUG_LOG("First header\n%s", header.toString().c_str()); + if (TSIsDebugTagSet(PLUGIN_NAME)) { + DEBUG_LOG("First header\n%s", header.toString().c_str()); + } data->m_dnstream.setupVioWrite(contp, INT64_MAX); @@ -71,22 +114,29 @@ handleFirstServerHeader(Data *const data, TSCont const contp) DEBUG_LOG("Initial response other than 206: %d", header.status()); // Should run TSVIONSetBytes(output_io, hlen + bodybytes); - // int const hlen = TSHttpHdrLengthGet(header.m_buffer, header.m_lochdr); - // TSVIONBytesSet(output_vio, hlen); + int64_t const hlen = TSHttpHdrLengthGet(header.m_buffer, header.m_lochdr); + int64_t const clen = contentLengthFrom(header); + DEBUG_LOG("Passthru: header: %" PRId64 " body: %" PRId64, hlen, clen); + if (clen != INT64_MAX) { + TSVIONBytesSet(output_vio, hlen + clen); + } else { + TSVIONBytesSet(output_vio, clen); + } TSHttpHdrPrint(header.m_buffer, header.m_lochdr, output_buf); - transfer_all_bytes(data); - - return false; + state = HeaderState::Passthru; + return state; } ContentRange const blockcr = contentRangeFrom(header); + // 206 with bad content range? if (!blockcr.isValid()) { static std::string const &msg502 = string502(); TSVIONBytesSet(output_vio, msg502.size()); TSIOBufferWrite(output_buf, msg502.data(), msg502.size()); TSVIOReenable(output_vio); - return false; + state = HeaderState::Fail; + return state; } // set the resource content length from block response @@ -120,13 +170,17 @@ handleFirstServerHeader(Data *const data, TSCont const contp) data->m_upstream.m_read.close(); - return false; + state = HeaderState::Fail; } + // save data header string + data->m_datelen = sizeof(data->m_date); + header.valueForKey(TS_MIME_FIELD_DATE, TS_MIME_LEN_DATE, data->m_date, &data->m_datelen); + // save weak cache header identifiers (rfc7232 section 2) - data->m_etaglen = sizeof(data->m_etag) - 1; + data->m_etaglen = sizeof(data->m_etag); header.valueForKey(TS_MIME_FIELD_ETAG, TS_MIME_LEN_ETAG, data->m_etag, &data->m_etaglen); - data->m_lastmodifiedlen = sizeof(data->m_lastmodified) - 1; + data->m_lastmodifiedlen = sizeof(data->m_lastmodified); header.valueForKey(TS_MIME_FIELD_LAST_MODIFIED, TS_MIME_LEN_LAST_MODIFIED, data->m_lastmodified, &data->m_lastmodifiedlen); // size of the first block payload @@ -149,7 +203,7 @@ handleFirstServerHeader(Data *const data, TSCont const contp) data->m_dnstream.close(); ERROR_LOG("Bad/invalid response content range"); - return false; + state = HeaderState::Fail; } header.setKeyVal(TS_MIME_FIELD_CONTENT_RANGE, TS_MIME_LEN_CONTENT_RANGE, rangestr, rangelen); @@ -173,7 +227,7 @@ handleFirstServerHeader(Data *const data, TSCont const contp) data->m_bytessent = hbytes; TSVIOReenable(output_vio); - return true; + return state; } void @@ -241,9 +295,8 @@ logSliceError(char const *const message, Data const *const data, HttpHeader cons header_resp.valueForKey(TS_MIME_FIELD_ETAG, TS_MIME_LEN_ETAG, etagstr, &etaglen); // last modified - char lmstr[1024]; - int lmlen = sizeof(lmstr); - header_resp.valueForKey(TS_MIME_FIELD_LAST_MODIFIED, TS_MIME_LEN_LAST_MODIFIED, lmstr, &lmlen); + time_t lmgot = 0; + header_resp.timeForKey(TS_MIME_FIELD_LAST_MODIFIED, TS_MIME_LEN_LAST_MODIFIED, &lmgot); // cc char ccstr[2048]; @@ -279,61 +332,151 @@ logSliceError(char const *const message, Data const *const data, HttpHeader cons " status_got=\"%d\"" " cr_got=\"%.*s\"" " etag_got=\"%.*s\"" - " lm_got=\"%.*s\"" + " lm_got=\"%" PRId64 "\"" " cc=\"%.*s\"" - " via=\"%.*s\"", + " via=\"%.*s\" - attempting to recover", secs, ms, message, (int)urlplen, urlpstr, uaslen, uasstr, rangelen, rangestr, normlen, normstr, (int)etagexplen, etagexpstr, data->m_lastmodifiedlen, data->m_lastmodified, blockbeg, blockend - 1, statusgot, crlen, crstr, - (int)etaggotlen, etaggotstr, lmlen, lmstr, cclen, ccstr, vialen, viastr); + (int)etaggotlen, etaggotstr, lmgot, cclen, ccstr, vialen, viastr); } bool handleNextServerHeader(Data *const data, TSCont const contp) { +#if defined(COLLECT_STATS) + stats::StatsRAI const rai(stats::NextHeaderTime); +#endif + // block response header HttpHeader header(data->m_resp_hdrmgr.m_buffer, data->m_resp_hdrmgr.m_lochdr); - // DEBUG_LOG("Next Header:\n%s", header.toString().c_str()); + if (TSIsDebugTagSet(PLUGIN_NAME)) { + DEBUG_LOG("Next Header:\n%s", header.toString().c_str()); + } - // only process a 206, everything else just aborts - if (TS_HTTP_STATUS_PARTIAL_CONTENT != header.status()) { - logSliceError("Non 206 internal block response", data, header); + bool same = true; + + switch (header.status()) { + case TS_HTTP_STATUS_NOT_FOUND: + // need to reissue reference slice + logSliceError("404 internal block response (asset gone)", data, header); + same = false; + break; + case TS_HTTP_STATUS_PARTIAL_CONTENT: + break; + default: + DEBUG_LOG("Non 206/404 internal block response encountered"); return false; + break; } // can't parse the content range header, abort -- might be too strict - ContentRange const blockcr = contentRangeFrom(header); - if (!blockcr.isValid() || blockcr.m_length != data->m_contentlen) { - logSliceError("Mismatch/Bad block Content-Range", data, header); - return false; - } + ContentRange blockcr; - bool same = true; + if (same) { + blockcr = contentRangeFrom(header); + if (!blockcr.isValid() || blockcr.m_length != data->m_contentlen) { + logSliceError("Mismatch/Bad block Content-Range", data, header); + same = false; + } + } - // prefer the etag but use Last-Modified if we must. - char etag[8192]; - int etaglen = sizeof(etag); - header.valueForKey(TS_MIME_FIELD_ETAG, TS_MIME_LEN_ETAG, etag, &etaglen); + if (same) { + // prefer the etag but use Last-Modified if we must. + char etag[8192]; + int etaglen = sizeof(etag); + header.valueForKey(TS_MIME_FIELD_ETAG, TS_MIME_LEN_ETAG, etag, &etaglen); - if (0 < data->m_etaglen || 0 < etaglen) { - same = data->m_etaglen == etaglen && 0 == strncmp(etag, data->m_etag, etaglen); - if (!same) { - logSliceError("Mismatch block Etag", data, header); - } - } else { - char lastmodified[8192]; - int lastmodifiedlen = sizeof(lastmodified); - header.valueForKey(TS_MIME_FIELD_LAST_MODIFIED, TS_MIME_LEN_LAST_MODIFIED, lastmodified, &lastmodifiedlen); - if (0 < data->m_lastmodifiedlen || 0 != lastmodifiedlen) { - same = data->m_lastmodifiedlen == lastmodifiedlen && 0 == strncmp(lastmodified, data->m_lastmodified, lastmodifiedlen); + if (0 < data->m_etaglen || 0 < etaglen) { + same = data->m_etaglen == etaglen && 0 == strncmp(etag, data->m_etag, etaglen); if (!same) { - logSliceError("Mismatch block Last-Modified", data, header); + logSliceError("Mismatch block Etag", data, header); + } + } else { + char lastmodified[33]; + int lastmodifiedlen = sizeof(lastmodified); + header.valueForKey(TS_MIME_FIELD_LAST_MODIFIED, TS_MIME_LEN_LAST_MODIFIED, lastmodified, &lastmodifiedlen); + if (0 < data->m_lastmodifiedlen || 0 < lastmodifiedlen) { + same = data->m_lastmodifiedlen == lastmodifiedlen && 0 == strncmp(lastmodified, data->m_lastmodified, lastmodifiedlen); + if (!same) { + logSliceError("Mismatch block Last-Modified", data, header); + } } } } - if (!same) { - data->m_upstream.close(); - return false; + // Header mismatch + if (same) { + // If we were in reference block refetch mode and the headers + // still match there is a problem + if (BlockState::ActiveRef == data->m_blockstate) { + ERROR_LOG("Reference block refetched, got the same block back again"); + return false; + } + } else { + switch (data->m_blockstate) { + case BlockState::Active: { + data->m_upstream.abort(); + + // Refetch the current interior slice + data->m_blockstate = BlockState::PendingInt; + + time_t date = 0; + header.timeForKey(TS_MIME_FIELD_DATE, TS_MIME_LEN_DATE, &date); + + // Ask for any slice newer than the cached one + time_t const dateims = date + 1; + + DEBUG_LOG("Attempting to reissue interior slice block request with IMS header time: %" PRId64, dateims); + + // add special CRR IMS header to the request + HttpHeader headerreq(data->m_req_hdrmgr.m_buffer, data->m_req_hdrmgr.m_lochdr); + if (!headerreq.setKeyTime(X_CRR_IMS_HEADER.data(), X_CRR_IMS_HEADER.size(), dateims)) { + ERROR_LOG("Failed setting '%.*s'", (int)X_CRR_IMS_HEADER.size(), X_CRR_IMS_HEADER.data()); + return false; + } + + } break; + case BlockState::ActiveInt: { + data->m_upstream.abort(); + + // New interior slice still mismatches, refetch the reference slice + data->m_blockstate = BlockState::PendingRef; + + // convert reference date header to time_t + time_t const date = TSMimeParseDate(data->m_date, data->m_datelen); + + // Ask for any slice newer than the cached one + time_t const dateims = date + 1; + + DEBUG_LOG("Attempting to reissue reference slice block request with IMS header time: %" PRId64, dateims); + + // add special CRR IMS header to the request + HttpHeader headerreq(data->m_req_hdrmgr.m_buffer, data->m_req_hdrmgr.m_lochdr); + if (!headerreq.setKeyTime(X_CRR_IMS_HEADER.data(), X_CRR_IMS_HEADER.size(), dateims)) { + ERROR_LOG("Failed setting '%.*s'", (int)X_CRR_IMS_HEADER.size(), X_CRR_IMS_HEADER.data()); + return false; + } + + // Reset for first block + if (Config::RefType::First == data->m_config->m_reftype) { + data->m_blocknum = 0; + } else { + data->m_blocknum = data->m_req_range.firstBlockFor(data->m_config->m_blockbytes); + } + + return true; + + } break; + // Refetch the reference slice + case BlockState::ActiveRef: { + // In this state the reference changed otherwise the asset is toast + // reset the content length (if content length drove the mismatch) + data->m_contentlen = blockcr.m_length; + return true; + } break; + default: + break; + } } data->m_blockexpected = blockcr.rangeSize(); @@ -347,14 +490,18 @@ handleNextServerHeader(Data *const data, TSCont const contp) void handle_server_resp(TSCont contp, TSEvent event, Data *const data) { - DEBUG_LOG("%p handle_server_resp: %s", data, TSHttpEventNameLookup(event)); - #if defined(COLLECT_STATS) TSStatIntIncrement(stats::Server, 1); + stats::StatsRAI const rai(stats::ServerTime); #endif switch (event) { case TS_EVENT_VCONN_READ_READY: { + if (data->m_blockstate == BlockState::Passthru) { + transfer_all_bytes(data); + return; + } + // has block response header been parsed?? if (!data->m_server_block_header_parsed) { int64_t consumed = 0; @@ -374,19 +521,38 @@ handle_server_resp(TSCont contp, TSEvent event, Data *const data) if (TS_PARSE_DONE == res) { if (!data->m_server_first_header_parsed) { - headerStat = handleFirstServerHeader(data, contp); + HeaderState const state = handleFirstServerHeader(data, contp); + data->m_server_first_header_parsed = true; + switch (state) { + case HeaderState::Fail: + data->m_blockstate = BlockState::Fail; + headerStat = false; + break; + case HeaderState::Passthru: { + data->m_blockstate = BlockState::Passthru; + transfer_all_bytes(data); + DEBUG_LOG("Going into a passthru state"); + return; + } break; + case HeaderState::Good: + default: + headerStat = true; + break; + } } else { headerStat = handleNextServerHeader(data, contp); } data->m_server_block_header_parsed = true; + } else if (TS_PARSE_CONT == res) { + return; } // kill the upstream and allow dnstream to clean up if (!headerStat) { data->m_upstream.abort(); - data->m_blockstate = Data::BlockState::Fail; + data->m_blockstate = BlockState::Fail; if (data->m_dnstream.m_write.isOpen()) { TSVIOReenable(data->m_dnstream.m_write.m_vio); } else { @@ -395,8 +561,41 @@ handle_server_resp(TSCont contp, TSEvent event, Data *const data) return; } - // how much to fast forward into this data block - data->m_blockskip = data->m_req_range.skipBytesForBlock(data->m_config->m_blockbytes, data->m_blocknum); + // header may have been successfully parsed but with caveats + switch (data->m_blockstate) { + // request new version of current internal slice + case BlockState::PendingInt: { + request_block(contp, data); + return; + } break; + // request new version of reference slice + case BlockState::PendingRef: { + request_block(contp, data); + return; + } break; + case BlockState::ActiveRef: { + // Mark the reference block for "skip". + int64_t const blockbytes = data->m_config->m_blockbytes; + int64_t const firstblock = data->m_req_range.firstBlockFor(blockbytes); + int64_t const blockpos = firstblock * blockbytes; + int64_t const firstblockbytes = std::min(blockbytes, data->m_contentlen - blockpos); + data->m_blockskip = firstblockbytes; + + // Check if we should abort the client + if (data->m_dnstream.isOpen()) { + TSVIO const output_vio = data->m_dnstream.m_write.m_vio; + int64_t const output_done = TSVIONDoneGet(output_vio); + int64_t const output_sent = data->m_bytessent; + if (output_done == output_sent) { + data->m_dnstream.abort(); + } + } + } break; + default: { + // how much to normally fast forward into this data block + data->m_blockskip = data->m_req_range.skipBytesForBlock(data->m_config->m_blockbytes, data->m_blocknum); + } break; + } } transfer_content_bytes(data); @@ -405,13 +604,40 @@ handle_server_resp(TSCont contp, TSEvent event, Data *const data) // fprintf(stderr, "%p: TS_EVENT_VCONN_READ_COMPLETE\n", data); } break; case TS_EVENT_VCONN_EOS: { - data->m_blockstate = Data::BlockState::Pending; + switch (data->m_blockstate) { + case BlockState::ActiveRef: + case BlockState::Passthru: { + transfer_all_bytes(data); + data->m_upstream.close(); + TSVIO const output_vio = data->m_dnstream.m_write.m_vio; + if (nullptr != output_vio) { + TSVIOReenable(output_vio); + } else { + shutdown(contp, data); + } + return; + } break; + default: + break; + } + + // corner condition, good source header + 0 length aborted content + // results in no header being read, just an EOS. + // trying to delete the upstream will crash ATS (??) + if (0 == data->m_blockexpected) { + shutdown(contp, data); // this will crash if first block + return; + } + + transfer_content_bytes(data); + data->m_upstream.close(); + data->m_blockstate = BlockState::Pending; // check for block truncation if (data->m_blockconsumed < data->m_blockexpected) { DEBUG_LOG("%p handle_server_resp truncation: %" PRId64 "\n", data, data->m_blockexpected - data->m_blockconsumed); - data->m_blockstate = Data::BlockState::Fail; + data->m_blockstate = BlockState::Fail; // shutdown(contp, data); return; } @@ -454,7 +680,7 @@ handle_server_resp(TSCont contp, TSEvent event, Data *const data) } else { data->m_upstream.close(); - data->m_blockstate = Data::BlockState::Done; + data->m_blockstate = BlockState::Done; if (!data->m_dnstream.m_read.isOpen()) { shutdown(contp, data); } diff --git a/plugins/experimental/slice/slice.cc b/plugins/experimental/slice/slice.cc index f53fdd3d248..60542fa7451 100644 --- a/plugins/experimental/slice/slice.cc +++ b/plugins/experimental/slice/slice.cc @@ -33,11 +33,16 @@ #if defined(COLLECT_STATS) namespace stats { -int DataCreate = -1; -int DataDestroy = -1; -int Reader = -1; -int Server = -1; -int Client = -1; +int DataCreate = -1; +int DataDestroy = -1; +int Reader = -1; +int Server = -1; +int Client = -1; +int RequestTime = -1; +int FirstHeaderTime = -1; +int NextHeaderTime = -1; +int ServerTime = -1; +int ClientTime = -1; } // namespace stats #endif // COLLECT_STATS @@ -48,6 +53,10 @@ Config globalConfig; bool read_request(TSHttpTxn txnp, Config *const config) { +#if defined(COLLECT_STATS) + stats::StatsRAI const rai(stats::RequestTime); +#endif + DEBUG_LOG("slice read_request"); TxnHdrMgr hdrmgr; hdrmgr.populateFrom(txnp, TSHttpTxnClientReqGet); @@ -180,7 +189,7 @@ read_request(TSHttpTxn txnp, Config *const config) // we'll intercept this GET and do it ourselves TSMutex const mutex = TSContMutexGet(reinterpret_cast(txnp)); - // TSMutex const mutex = TSMutexCreate(); + // TSMutex const mutex = TSMutexCreate(); TSCont const icontp(TSContCreate(intercept_hook, mutex)); TSContDataSet(icontp, (void *)data); TSHttpTxnIntercept(icontp, txnp); @@ -291,6 +300,31 @@ TSRemapInit(TSRemapInterface *api_info, char *errbug, int errbuf_size) stats::Client = TSStatCreate(nameclient.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); assert(0 <= stats::Client); + + std::string const namerequest = std::string(PLUGIN_NAME) + ".RequestTime"; + stats::RequestTime = TSStatCreate(namerequest.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); + + assert(0 <= stats::RequestTime); + + std::string const namefirst = std::string(PLUGIN_NAME) + ".FirstHeaderTime"; + stats::FirstHeaderTime = TSStatCreate(namefirst.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); + + assert(0 <= stats::FirstHeaderTime); + + std::string const namenext = std::string(PLUGIN_NAME) + ".NextHeaderTime"; + stats::NextHeaderTime = TSStatCreate(namenext.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); + + assert(0 <= stats::NextHeaderTime); + + std::string const nameservertime = std::string(PLUGIN_NAME) + ".ServerTime"; + stats::ServerTime = TSStatCreate(nameservertime.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); + + assert(0 <= stats::ServerTime); + + std::string const nameclienttime = std::string(PLUGIN_NAME) + ".ClientTime"; + stats::ClientTime = TSStatCreate(nameclienttime.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); + + assert(0 <= stats::ClientTime); } #endif // COLLECT_STATS diff --git a/plugins/experimental/slice/slice.h b/plugins/experimental/slice/slice.h index d4e040b32f2..fe3dba239bb 100644 --- a/plugins/experimental/slice/slice.h +++ b/plugins/experimental/slice/slice.h @@ -19,8 +19,10 @@ #pragma once #include "ts/ts.h" +#include "ts/experimental.h" #include +#include #ifndef SLICE_EXPORT #define SLICE_EXPORT extern "C" tsapi @@ -30,11 +32,17 @@ #define PLUGIN_NAME "slice" #endif +#ifndef COLLECT_STATS +#define COLLECT_STATS +#endif + +constexpr std::string_view X_CRR_IMS_HEADER = {"X-Crr-Ims"}; + #if !defined(UNITTEST) #define __FILENAME__ (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILE__) #define DEBUG_LOG(fmt, ...) \ - TSDebug(PLUGIN_NAME, "[%s:%04d] %s(): " fmt, __FILENAME__, __LINE__, __func__, \ + TSDebug(PLUGIN_NAME, "[%s:% 4d] %s(): " fmt, __FILENAME__, __LINE__, __func__, \ ##__VA_ARGS__) /* \ ; fprintf(stderr, "[%s:%04d]: " fmt "\n" \ , __FILENAME__ \ @@ -43,7 +51,7 @@ */ #define ERROR_LOG(fmt, ...) \ - TSError("[%s:%04d] %s(): " fmt, __FILENAME__, __LINE__, __func__, ##__VA_ARGS__); \ + TSError("[%s:% 4d] %s(): " fmt, __FILENAME__, __LINE__, __func__, ##__VA_ARGS__); \ TSDebug(PLUGIN_NAME, "[%s:%04d] %s(): " fmt, __FILENAME__, __LINE__, __func__, ##__VA_ARGS__) #else @@ -61,5 +69,24 @@ extern int DataDestroy; extern int Reader; extern int Server; extern int Client; +extern int RequestTime; +extern int FirstHeaderTime; +extern int NextHeaderTime; +extern int ServerTime; +extern int ClientTime; + +struct StatsRAI { + int m_statid; + TSHRTime m_timebeg; + + StatsRAI(int statid) : m_statid(statid), m_timebeg(TShrtime()) {} + + ~StatsRAI() + { + TSHRTime const timeend = TShrtime(); + TSStatIntIncrement(m_statid, timeend - m_timebeg); + } +}; + } // namespace stats #endif // COLLECT_STATS diff --git a/plugins/experimental/slice/util.cc b/plugins/experimental/slice/util.cc index f3ae7d2bcf1..cc78c2bbc19 100644 --- a/plugins/experimental/slice/util.cc +++ b/plugins/experimental/slice/util.cc @@ -51,9 +51,15 @@ request_block(TSCont contp, Data *const data) return false; } - if (Data::BlockState::Pending != data->m_blockstate) { - ERROR_LOG("request_block called with non Pending state!"); + switch (data->m_blockstate) { + case BlockState::Pending: + case BlockState::PendingInt: + case BlockState::PendingRef: + break; + default: + ERROR_LOG("request_block called with non Pending* state!"); return false; + break; } int64_t const blockbeg = (data->m_config->m_blockbytes * data->m_blocknum); @@ -90,10 +96,10 @@ request_block(TSCont contp, Data *const data) TSHttpHdrPrint(header.m_buffer, header.m_lochdr, data->m_upstream.m_write.m_iobuf); TSVIOReenable(data->m_upstream.m_write.m_vio); - /* - std::string const headerstr(header.toString()); - DEBUG_LOG("Headers\n%s", headerstr.c_str()); - */ + if (TSIsDebugTagSet(PLUGIN_NAME)) { + std::string const headerstr(header.toString()); + DEBUG_LOG("Headers\n%s", headerstr.c_str()); + } // get ready for data back from the server data->m_upstream.setupVioRead(contp, INT64_MAX); @@ -104,9 +110,25 @@ request_block(TSCont contp, Data *const data) data->m_blockexpected = 0; data->m_blockconsumed = 0; - data->m_blockstate = Data::BlockState::Active; data->m_server_block_header_parsed = false; + switch (data->m_blockstate) { + case BlockState::Pending: + data->m_blockstate = BlockState::Active; + break; + case BlockState::PendingInt: + data->m_blockstate = BlockState::ActiveInt; + header.removeKey(X_CRR_IMS_HEADER.data(), X_CRR_IMS_HEADER.size()); + break; + case BlockState::PendingRef: + data->m_blockstate = BlockState::ActiveRef; + header.removeKey(X_CRR_IMS_HEADER.data(), X_CRR_IMS_HEADER.size()); + break; + default: + ERROR_LOG("Invalid blockstate"); + break; + } + return true; } diff --git a/src/traffic_server/InkAPI.cc b/src/traffic_server/InkAPI.cc index 1efa887d9b0..4c96cc24320 100644 --- a/src/traffic_server/InkAPI.cc +++ b/src/traffic_server/InkAPI.cc @@ -3346,6 +3346,16 @@ TSMimeHdrFieldValueDateGet(TSMBuffer bufp, TSMLoc hdr, TSMLoc field) return mime_parse_date(value_str, value_str + value_len); } +time_t +TSMimeParseDate(char const *const value_str, int const value_len) +{ + if (value_str == nullptr) { + return (time_t)0; + } + + return mime_parse_date(value_str, value_str + value_len); +} + int TSMimeHdrFieldValueIntGet(TSMBuffer bufp, TSMLoc hdr, TSMLoc field, int idx) { @@ -3445,6 +3455,21 @@ TSMimeHdrFieldValueDateSet(TSMBuffer bufp, TSMLoc hdr, TSMLoc field, time_t valu return TS_SUCCESS; } +TSReturnCode +TSMimeFormatDate(time_t const value_time, char *const value_str, int *const value_length) +{ + if (value_length == nullptr) { + return TS_ERROR; + } + + if (*value_length < 33) { + return TS_ERROR; + } + + *value_length = mime_format_date(value_str, value_time); + return TS_SUCCESS; +} + TSReturnCode TSMimeHdrFieldValueIntSet(TSMBuffer bufp, TSMLoc hdr, TSMLoc field, int idx, int value) { diff --git a/tests/gold_tests/pluginTest/slice/curlsort.sh b/tests/gold_tests/pluginTest/slice/curlsort.sh deleted file mode 100755 index eabf5618ff2..00000000000 --- a/tests/gold_tests/pluginTest/slice/curlsort.sh +++ /dev/null @@ -1,33 +0,0 @@ -#!/bin/sh - -# 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. - -cmd='curl' -for arg in "$@"; do - case "$arg" in - *\'*) -# arg=`printf '%s' "$arg" | sed s/'/'\"'\"'/g"` - arg=`printf '%s' "$arg"` - ;; - *) : ;; - esac - cmd="$cmd '$arg'" -done - -cmd="$cmd -s -D /dev/stdout -o /dev/stderr" - -eval " $cmd" | sort diff --git a/tests/gold_tests/pluginTest/slice/gold/aa.gold b/tests/gold_tests/pluginTest/slice/gold/aa.gold new file mode 100644 index 00000000000..7ec9a4b774e --- /dev/null +++ b/tests/gold_tests/pluginTest/slice/gold/aa.gold @@ -0,0 +1 @@ +aa \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold/aaa.gold b/tests/gold_tests/pluginTest/slice/gold/aaa.gold new file mode 100644 index 00000000000..7c4a013e52c --- /dev/null +++ b/tests/gold_tests/pluginTest/slice/gold/aaa.gold @@ -0,0 +1 @@ +aaa \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold/bb.gold b/tests/gold_tests/pluginTest/slice/gold/bb.gold new file mode 100644 index 00000000000..b5b5773c405 --- /dev/null +++ b/tests/gold_tests/pluginTest/slice/gold/bb.gold @@ -0,0 +1 @@ +bb \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold/bbb.gold b/tests/gold_tests/pluginTest/slice/gold/bbb.gold new file mode 100644 index 00000000000..01f02e32ce8 --- /dev/null +++ b/tests/gold_tests/pluginTest/slice/gold/bbb.gold @@ -0,0 +1 @@ +bbb \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_200.stderr.gold b/tests/gold_tests/pluginTest/slice/gold/slice_200.stderr.gold index 24ad29c1a82..c2475221112 100644 --- a/tests/gold_tests/pluginTest/slice/gold/slice_200.stderr.gold +++ b/tests/gold_tests/pluginTest/slice/gold/slice_200.stderr.gold @@ -1 +1 @@ -lets go surfin now`` +lets go surfin now \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_200.stdout.gold b/tests/gold_tests/pluginTest/slice/gold/slice_200.stdout.gold deleted file mode 100644 index 50eeb38afb7..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold/slice_200.stdout.gold +++ /dev/null @@ -1,8 +0,0 @@ -`` -Cache-Control: `` -Connection: `` -Content-Length: 18 -Date: `` -Etag: "path" -HTTP/1.1 200 OK -Server: `` diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_206.stderr.gold b/tests/gold_tests/pluginTest/slice/gold/slice_206.stderr.gold index 24ad29c1a82..c2475221112 100644 --- a/tests/gold_tests/pluginTest/slice/gold/slice_206.stderr.gold +++ b/tests/gold_tests/pluginTest/slice/gold/slice_206.stderr.gold @@ -1 +1 @@ -lets go surfin now`` +lets go surfin now \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_206.stdout.gold b/tests/gold_tests/pluginTest/slice/gold/slice_206.stdout.gold deleted file mode 100644 index 0ff73438579..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold/slice_206.stdout.gold +++ /dev/null @@ -1,9 +0,0 @@ -`` -Cache-Control: `` -Connection: `` -Content-Length: 18 -Content-Range: bytes 0-17/18 -Date: `` -Etag: "path" -HTTP/1.1 206 Partial Content -Server: `` diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_first.stderr.gold b/tests/gold_tests/pluginTest/slice/gold/slice_first.stderr.gold index 10893bb0688..956bab9d26b 100644 --- a/tests/gold_tests/pluginTest/slice/gold/slice_first.stderr.gold +++ b/tests/gold_tests/pluginTest/slice/gold/slice_first.stderr.gold @@ -1 +1 @@ -lets go`` +lets go \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_first.stdout.gold b/tests/gold_tests/pluginTest/slice/gold/slice_first.stdout.gold deleted file mode 100644 index c12d4c194da..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold/slice_first.stdout.gold +++ /dev/null @@ -1,9 +0,0 @@ -`` -Cache-Control: max-age=`` -Connection: `` -Content-Length: 7 -Content-Range: bytes 0-6/18 -Date: `` -Etag: `` -HTTP/1.1 206 Partial Content -Server: `` diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_last.stderr.gold b/tests/gold_tests/pluginTest/slice/gold/slice_last.stderr.gold index 30d9d270514..a5f7a5d421b 100644 --- a/tests/gold_tests/pluginTest/slice/gold/slice_last.stderr.gold +++ b/tests/gold_tests/pluginTest/slice/gold/slice_last.stderr.gold @@ -1 +1 @@ - now`` + now \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_last.stdout.gold b/tests/gold_tests/pluginTest/slice/gold/slice_last.stdout.gold deleted file mode 100644 index 8457c952f01..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold/slice_last.stdout.gold +++ /dev/null @@ -1,9 +0,0 @@ -`` -Cache-Control: max-age=`` -Connection: `` -Content-Length: 4 -Content-Range: bytes 14-17/18 -Date: `` -Etag: `` -HTTP/1.1 206 Partial Content -Server: `` diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_mid.stderr.gold b/tests/gold_tests/pluginTest/slice/gold/slice_mid.stderr.gold index ef40e3253f5..9f2bb071ba2 100644 --- a/tests/gold_tests/pluginTest/slice/gold/slice_mid.stderr.gold +++ b/tests/gold_tests/pluginTest/slice/gold/slice_mid.stderr.gold @@ -1 +1 @@ -go surfin no`` +go surfin no \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold/slice_mid.stdout.gold b/tests/gold_tests/pluginTest/slice/gold/slice_mid.stdout.gold deleted file mode 100644 index e078833d768..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold/slice_mid.stdout.gold +++ /dev/null @@ -1,9 +0,0 @@ -`` -Cache-Control: max-age=`` -Connection: `` -Content-Length: 12 -Content-Range: bytes 5-16/18 -Date: `` -Etag: `` -HTTP/1.1 206 Partial Content -Server: `` diff --git a/tests/gold_tests/pluginTest/slice/gold_error/contents.stderr.gold b/tests/gold_tests/pluginTest/slice/gold_error/contents.stderr.gold new file mode 100644 index 00000000000..321dd5d09d6 --- /dev/null +++ b/tests/gold_tests/pluginTest/slice/gold_error/contents.stderr.gold @@ -0,0 +1 @@ +the quick \ No newline at end of file diff --git a/tests/gold_tests/pluginTest/slice/gold_error/crr.stderr.gold b/tests/gold_tests/pluginTest/slice/gold_error/crr.stderr.gold deleted file mode 100644 index fad05754105..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold_error/crr.stderr.gold +++ /dev/null @@ -1 +0,0 @@ -the quick`` diff --git a/tests/gold_tests/pluginTest/slice/gold_error/crr.stdout.gold b/tests/gold_tests/pluginTest/slice/gold_error/crr.stdout.gold deleted file mode 100644 index 7109c04a13f..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold_error/crr.stdout.gold +++ /dev/null @@ -1,9 +0,0 @@ -`` -Cache-Control: `` -Connection: `` -Content-Length: 19 -Date: `` -Etag: `` -HTTP/1.1 200 OK -Server: `` -Via: `` diff --git a/tests/gold_tests/pluginTest/slice/gold_error/etag.stderr.gold b/tests/gold_tests/pluginTest/slice/gold_error/etag.stderr.gold deleted file mode 100644 index fad05754105..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold_error/etag.stderr.gold +++ /dev/null @@ -1 +0,0 @@ -the quick`` diff --git a/tests/gold_tests/pluginTest/slice/gold_error/etag.stdout.gold b/tests/gold_tests/pluginTest/slice/gold_error/etag.stdout.gold deleted file mode 100644 index 7109c04a13f..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold_error/etag.stdout.gold +++ /dev/null @@ -1,9 +0,0 @@ -`` -Cache-Control: `` -Connection: `` -Content-Length: 19 -Date: `` -Etag: `` -HTTP/1.1 200 OK -Server: `` -Via: `` diff --git a/tests/gold_tests/pluginTest/slice/gold_error/lm.stderr.gold b/tests/gold_tests/pluginTest/slice/gold_error/lm.stderr.gold deleted file mode 100644 index fad05754105..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold_error/lm.stderr.gold +++ /dev/null @@ -1 +0,0 @@ -the quick`` diff --git a/tests/gold_tests/pluginTest/slice/gold_error/lm.stdout.gold b/tests/gold_tests/pluginTest/slice/gold_error/lm.stdout.gold deleted file mode 100644 index 20bd1a54127..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold_error/lm.stdout.gold +++ /dev/null @@ -1,9 +0,0 @@ -`` -Cache-Control: `` -Connection: `` -Content-Length: 19 -Date: `` -HTTP/1.1 200 OK -Last-Modified: `` -Server: `` -Via: `` diff --git a/tests/gold_tests/pluginTest/slice/gold_error/non206.stderr.gold b/tests/gold_tests/pluginTest/slice/gold_error/non206.stderr.gold deleted file mode 100644 index fad05754105..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold_error/non206.stderr.gold +++ /dev/null @@ -1 +0,0 @@ -the quick`` diff --git a/tests/gold_tests/pluginTest/slice/gold_error/non206.stdout.gold b/tests/gold_tests/pluginTest/slice/gold_error/non206.stdout.gold deleted file mode 100644 index f381661d6a6..00000000000 --- a/tests/gold_tests/pluginTest/slice/gold_error/non206.stdout.gold +++ /dev/null @@ -1,10 +0,0 @@ -`` -Cache-Control: `` -Connection: `` -Content-Length: 19 -Date: `` -Etag: `` -HTTP/1.1 200 OK -Last-Modified: `` -Server: `` -Via: `` diff --git a/tests/gold_tests/pluginTest/slice/slice.test.py b/tests/gold_tests/pluginTest/slice/slice.test.py index 81e1f563f5b..fa4c2031bd8 100644 --- a/tests/gold_tests/pluginTest/slice/slice.test.py +++ b/tests/gold_tests/pluginTest/slice/slice.test.py @@ -34,12 +34,12 @@ server = Test.MakeOriginServer("server") # Define ATS and configure -ts = Test.MakeATSProcess("ts", command="traffic_manager", select_ports=True) +ts = Test.MakeATSProcess("ts", command="traffic_server") # default root request_header_chk = {"headers": "GET / HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: ats\r\n" + "\r\n", "timestamp": "1469733493.993", "body": "", @@ -55,12 +55,12 @@ server.addResponse("sessionlog.json", request_header_chk, response_header_chk) -#block_bytes = 7 +block_bytes = 7 body = "lets go surfin now" request_header = {"headers": "GET /path HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: origin\r\n" + "\r\n", "timestamp": "1469733493.993", "body": "", @@ -78,106 +78,99 @@ server.addResponse("sessionlog.json", request_header, response_header) -ts.Setup.CopyAs('curlsort.sh', Test.RunDirectory) -curl_and_args = 'sh curlsort.sh -H "Host: www.example.com"' +curl_and_args = 'curl -s -D /dev/stdout -o /dev/stderr -x http://127.0.0.1:{}'.format(ts.Variables.port) # set up whole asset fetch into cache -ts.Disk.remap_config.AddLine( - 'map / http://127.0.0.1:{}'.format(server.Variables.Port) -) +ts.Disk.remap_config.AddLines([ + 'map http://preload/ http://127.0.0.1:{}'.format(server.Variables.Port), + 'map http://slice/ http://127.0.0.1:{}'.format(server.Variables.Port) + + ' @plugin=slice.so @pparam=--blockbytes-test={}'.format(block_bytes) +]) # minimal configuration ts.Disk.records_config.update({ - 'proxy.config.diags.debug.enabled': 1, - 'proxy.config.diags.debug.tags': 'slice', +# 'proxy.config.diags.debug.enabled': 1, +# 'proxy.config.diags.debug.tags': 'slice', 'proxy.config.http.cache.http': 1, 'proxy.config.http.wait_for_cache': 1, - 'proxy.config.http.insert_age_in_response': 0, - 'proxy.config.http.response_via_str': 3, }) # 0 Test - Prefetch entire asset into cache tr = Test.AddTestRun("Fetch first slice range") -tr.Processes.Default.StartBefore(server) -tr.Processes.Default.StartBefore(Test.Processes.ts) -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/path'.format(ts.Variables.port) -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold/slice_200.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold/slice_200.stderr.gold" +ps = tr.Processes.Default +ps.StartBefore(server, ready=When.PortOpen(server.Variables.Port)) +ps.StartBefore(Test.Processes.ts, ready=When.PortOpen(ts.Variables.port)) +ps.Command = curl_and_args + ' http://preload/path' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/slice_200.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("200 OK", "expected 200 OK response") tr.StillRunningAfter = ts -block_bytes = 7 - -# 1 - Reconfigure remap.config with slice plugin -tr = Test.AddTestRun("Load Slice plugin") -remap_config_path = ts.Disk.remap_config.Name -tr.Disk.File(remap_config_path, typename="ats:config").AddLines([ - 'map / http://127.0.0.1:{}'.format(server.Variables.Port) + - ' @plugin=slice.so @pparam=--blockbytes-test={}'.format(block_bytes) -]) - -tr.StillRunningAfter = ts -tr.StillRunningAfter = server -tr.Processes.Default.Command = 'traffic_ctl config reload' -# Need to copy over the environment so traffic_ctl knows where to find the unix domain socket -tr.Processes.Default.Env = ts.Env -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.TimeOut = 5 -tr.TimeOut = 5 - -# 2 Test - First complete slice +# 1 Test - First complete slice tr = Test.AddTestRun("Fetch first slice range") -tr.DelayStart = 5 -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/path'.format(ts.Variables.port) + ' -r 0-6' -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold/slice_first.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold/slice_first.stderr.gold" +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/path' + ' -r 0-6' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/slice_first.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("206 Partial Content", "expected 206 response") +ps.Streams.stdout.Content += Testers.ContainsExpression("Content-Range: bytes 0-6/18", "mismatch byte content response") tr.StillRunningAfter = ts -# 3 Test - Last slice auto +# 2 Test - Last slice auto tr = Test.AddTestRun("Last slice -- 14-") -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/path'.format(ts.Variables.port) + ' -r 14-' -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold/slice_last.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold/slice_last.stderr.gold" +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/path' + ' -r 14-' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/slice_last.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("206 Partial Content", "expected 206 response") +ps.Streams.stdout.Content += Testers.ContainsExpression("Content-Range: bytes 14-17/18", "mismatch byte content response") tr.StillRunningAfter = ts -# 4 Test - Last slice exact +# 3 Test - Last slice exact tr = Test.AddTestRun("Last slice 14-17") -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/path'.format(ts.Variables.port) + ' -r 14-17' -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold/slice_last.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold/slice_last.stderr.gold" +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/path' + ' -r 14-17' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/slice_last.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("206 Partial Content", "expected 206 response") +ps.Streams.stdout.Content += Testers.ContainsExpression("Content-Range: bytes 14-17/18", "mismatch byte content response") tr.StillRunningAfter = ts -# 5 Test - Last slice truncated +# 4 Test - Last slice truncated tr = Test.AddTestRun("Last truncated slice 14-20") -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/path'.format(ts.Variables.port) + ' -r 14-20' -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold/slice_last.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold/slice_last.stderr.gold" +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/path' + ' -r 14-20' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/slice_last.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("206 Partial Content", "expected 206 response") +ps.Streams.stdout.Content += Testers.ContainsExpression("Content-Range: bytes 14-17/18", "mismatch byte content response") tr.StillRunningAfter = ts -# 6 Test - Whole asset via slices +# 5 Test - Whole asset via slices tr = Test.AddTestRun("Whole asset via slices") -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/path'.format(ts.Variables.port) -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold/slice_200.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold/slice_200.stderr.gold" +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/path' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/slice_200.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("200 OK", "expected 200 OK response") tr.StillRunningAfter = ts -# 7 Test - Whole asset via range +# 6 Test - Whole asset via range tr = Test.AddTestRun("Whole asset via range") -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/path'.format(ts.Variables.port) + ' -r 0-' -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold/slice_206.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold/slice_206.stderr.gold" +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/path' + ' -r 0-' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/slice_206.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("206 Partial Content", "expected 206 response") +ps.Streams.stdout.Content += Testers.ContainsExpression("Content-Range: bytes 0-17/18", "mismatch byte content response") tr.StillRunningAfter = ts -# 8 Test - Non aligned slice request +# 7 Test - Non aligned slice request tr = Test.AddTestRun("Non aligned slice request") -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/path'.format(ts.Variables.port) + ' -r 5-16' -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold/slice_mid.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold/slice_mid.stderr.gold" +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/path' + ' -r 5-16' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/slice_mid.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("206 Partial Content", "expected 206 response") +ps.Streams.stdout.Content += Testers.ContainsExpression("Content-Range: bytes 5-16/18", "mismatch byte content response") tr.StillRunningAfter = ts diff --git a/tests/gold_tests/pluginTest/slice/slice_error.test.py b/tests/gold_tests/pluginTest/slice/slice_error.test.py index 0ae06f1f23c..8b0f841fa57 100644 --- a/tests/gold_tests/pluginTest/slice/slice_error.test.py +++ b/tests/gold_tests/pluginTest/slice/slice_error.test.py @@ -34,14 +34,14 @@ server = Test.MakeOriginServer("server", lookup_key="{%Range}{PATH}") # Define ATS and configure -ts = Test.MakeATSProcess("ts", command="traffic_manager", select_ports=True) +ts = Test.MakeATSProcess("ts", command="traffic_server") body = "the quick brown fox" # len 19 # default root request_header_chk = {"headers": "GET / HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: ats\r\n" + "Range: bytes=0-\r\n" + "\r\n", "timestamp": "1469733493.993", @@ -70,7 +70,7 @@ request_header_etag0 = {"headers": "GET /etag HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: ats\r\n" + "Range: bytes={}\r\n".format(range0) + "X-Slicer-Info: full content request\r\n" + "\r\n", @@ -93,7 +93,7 @@ request_header_etag1 = {"headers": "GET /etag HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: ats\r\n" + "Range: bytes={}\r\n".format(range1) + "X-Slicer-Info: full content request\r\n" + "\r\n", @@ -118,7 +118,7 @@ request_header_lm0 = {"headers": "GET /lastmodified HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: ats\r\n" + "Range: bytes={}\r\n".format(range0) + "X-Slicer-Info: full content request\r\n" + "\r\n", @@ -141,7 +141,7 @@ request_header_lm1 = {"headers": "GET /lastmodified HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: ats\r\n" + "Range: bytes={}\r\n".format(range1) + "X-Slicer-Info: full content request\r\n" + "\r\n", @@ -166,7 +166,7 @@ request_header_n206_0 = {"headers": "GET /non206 HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: ats\r\n" + "Range: bytes={}\r\n".format(range0) + "X-Slicer-Info: full content request\r\n" + "\r\n", @@ -188,11 +188,31 @@ server.addResponse("sessionlog.json", request_header_n206_0, response_header_n206_0) +request_header_n206_1 = {"headers": + "GET /non206 HTTP/1.1\r\n" + + "Host: ats\r\n" + + "Range: bytes={}\r\n".format(range1) + + "X-Slicer-Info: full content request\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +response_header_n206_1 = {"headers": + "HTTP/1.1 502 Bad Gateway\r\n" + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body1, +} + +server.addResponse("sessionlog.json", request_header_n206_1, response_header_n206_1) + # mismatch content-range request_header_crr0 = {"headers": "GET /crr HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: ats\r\n" + "Range: bytes={}\r\n".format(range0) + "X-Slicer-Info: full content request\r\n" + "\r\n", @@ -215,7 +235,7 @@ request_header_crr1 = {"headers": "GET /crr HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + + "Host: ats\r\n" + "Range: bytes={}\r\n".format(range1) + "X-Slicer-Info: full content request\r\n" + "\r\n", @@ -236,8 +256,33 @@ server.addResponse("sessionlog.json", request_header_crr1, response_header_crr1) -ts.Setup.CopyAs('curlsort.sh', Test.RunDirectory) -curl_and_args = 'sh curlsort.sh -H "Host: www.example.com"' +# 404 internal block + +request_header_internal404_0 = {"headers": + "GET /internal404 HTTP/1.1\r\n" + + "Host: ats\r\n" + + "Range: bytes={}\r\n".format(range0) + + "X-Slicer-Info: full content request\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +response_header_internal404_0 = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Connection: close\r\n" + + 'Etag: "etag"\r\n' + + "Last-Modified: Tue, 08 May 2018 15:49:41 GMT\r\n" + + "Content-Range: bytes {}/{}\r\n".format(range0, len(body)) + + "Cache-Control: max-age=500\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body0, +} + +server.addResponse("sessionlog.json", request_header_internal404_0, response_header_internal404_0) + +curl_and_args = 'curl -s -D /dev/stdout -o /dev/stderr -x http://127.0.0.1:{}'.format(ts.Variables.port) # set up whole asset fetch into cache ts.Disk.remap_config.AddLine( @@ -247,76 +292,81 @@ # minimal configuration ts.Disk.records_config.update({ - 'proxy.config.diags.debug.enabled': 0, - 'proxy.config.diags.debug.tags': 'slice', +# 'proxy.config.diags.debug.enabled': 1, +# 'proxy.config.diags.debug.tags': 'slice', 'proxy.config.http.cache.http': 0, 'proxy.config.http.wait_for_cache': 0, - 'proxy.config.http.insert_age_in_response': 0, - 'proxy.config.http.insert_request_via_str': 0, - 'proxy.config.http.insert_response_via_str': 3, }) # Override builtin error check as these cases will fail # taken from the slice plug code -ts.Disk.diags_log.Content = Testers.ContainsExpression('reason="Mismatch block Etag"', "Mismatch block etag") -ts.Disk.diags_log.Content += Testers.ContainsExpression('reason="Mismatch block Last-Modified"', "Mismatch block Last-Modified") -ts.Disk.diags_log.Content += Testers.ContainsExpression('reason="Non 206 internal block response"', "Non 206 internal block response") -ts.Disk.diags_log.Content += Testers.ContainsExpression('reason="Mismatch/Bad block Content-Range"', "Mismatch/Bad block Content-Range") +ts.Disk.diags_log.Content = Testers.ContainsExpression('reason="Mismatch block Etag', "Mismatch block etag") +ts.Disk.diags_log.Content += Testers.ContainsExpression('reason="Mismatch block Last-Modified', "Mismatch block Last-Modified") +ts.Disk.diags_log.Content += Testers.ContainsExpression('reason="Mismatch/Bad block Content-Range', "Mismatch/Bad block Content-Range") +ts.Disk.diags_log.Content += Testers.ContainsExpression('reason="404 internal block response', "404 internal block response") # 0 Test - Etag mismatch test tr = Test.AddTestRun("Etag test") -tr.Processes.Default.StartBefore(server) -tr.Processes.Default.StartBefore(Test.Processes.ts) -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/etag'.format(ts.Variables.port) -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold_error/etag.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold_error/etag.stderr.gold" +ps = tr.Processes.Default +ps.StartBefore(server, ready=When.PortOpen(server.Variables.Port)) +ps.StartBefore(Test.Processes.ts, ready=When.PortOpen(ts.Variables.port)) +ps.Command = curl_and_args + ' http://ats/etag' +#ps.ReturnCode = 0 # curl will return fail status +ps.Streams.stdout.Content = Testers.ContainsExpression("200 OK", "expected 200 OK response") +ps.Streams.stderr = "gold_error/contents.stderr.gold" tr.StillRunningAfter = ts # 1 Check - diags.log message tr = Test.AddTestRun("Etag error check") -tr.Processes.Default.Command = "grep 'Mismatch block Etag' {}".format(ts.Disk.diags_log.Name) -tr.Processes.Default.ReturnCode = 0 +ps = tr.Processes.Default +ps.Command = "grep 'Mismatch block Etag' {}".format(ts.Disk.diags_log.Name) +ps.ReturnCode = 0 tr.StillRunningAfter = ts # 2 Test - Last Modified mismatch test tr = Test.AddTestRun("Last-Modified test") -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/lastmodified'.format(ts.Variables.port) -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold_error/lm.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold_error/lm.stderr.gold" +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://ats/lastmodified' +#ps.ReturnCode = 0 # curl will return fail status +ps.Streams.stderr = "gold_error/contents.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("200 OK", "expected 200 OK response") tr.StillRunningAfter = ts # 3 Check - diags.log message tr = Test.AddTestRun("Last-Modified error check") -tr.Processes.Default.Command = "grep 'Mismatch block Last-Modified' {}".format(ts.Disk.diags_log.Name) -tr.Processes.Default.ReturnCode = 0 +ps = tr.Processes.Default +ps.Command = "grep 'Mismatch block Last-Modified' {}".format(ts.Disk.diags_log.Name) +ps.ReturnCode = 0 tr.StillRunningAfter = ts -# 4 Test - Non 206 mismatch test -tr = Test.AddTestRun("Non 206 test") -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/non206'.format(ts.Variables.port) -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold_error/non206.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold_error/non206.stderr.gold" +# 4 Test - Block content-range +tr = Test.AddTestRun("Content-Range test") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://ats/crr' +#ps.ReturnCode = 0 # curl will return fail status +ps.Streams.stderr = "gold_error/contents.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("200 OK", "expected 200 OK response") tr.StillRunningAfter = ts -# 3 Check - diags.log message -tr = Test.AddTestRun("Non 206 error check") -tr.Processes.Default.Command = "grep 'Non 206 internal block response' {}".format(ts.Disk.diags_log.Name) -tr.Processes.Default.ReturnCode = 0 +# 5 Check - diags.log message +tr = Test.AddTestRun("Content-Range error check") +ps = tr.Processes.Default +ps.Command = "grep 'Mismatch/Bad block Content-Range' {}".format(ts.Disk.diags_log.Name) +ps.ReturnCode = 0 tr.StillRunningAfter = ts -# 4 Test - Block content-range -tr = Test.AddTestRun("Content-Range test") -tr.Processes.Default.Command = curl_and_args + ' http://127.0.0.1:{}/crr'.format(ts.Variables.port) -tr.Processes.Default.ReturnCode = 0 -tr.Processes.Default.Streams.stdout = "gold_error/crr.stdout.gold" -tr.Processes.Default.Streams.stderr = "gold_error/crr.stderr.gold" +# 6 Test - 404 internal test +tr = Test.AddTestRun("Internal 404 test") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://ats/internal404' +#ps.ReturnCode = 0 # curl will return fail status +ps.Streams.stderr = "gold_error/contents.stderr.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("200 OK", "expected 200 OK response") tr.StillRunningAfter = ts -# 3 Check - diags.log message -tr = Test.AddTestRun("Content-Range error check") -tr.Processes.Default.Command = "grep 'Mismatch/Bad block Content-Range' {}".format(ts.Disk.diags_log.Name) -tr.Processes.Default.ReturnCode = 0 +# 7 Check - diags.log message +tr = Test.AddTestRun("Internal 404 check") +ps = tr.Processes.Default +ps.Command = "grep '404 internal block response' {}".format(ts.Disk.diags_log.Name) +ps.ReturnCode = 0 tr.StillRunningAfter = ts diff --git a/tests/gold_tests/pluginTest/slice/slice_regex.test.py b/tests/gold_tests/pluginTest/slice/slice_regex.test.py index f1a14b52952..6ca86a8196f 100644 --- a/tests/gold_tests/pluginTest/slice/slice_regex.test.py +++ b/tests/gold_tests/pluginTest/slice/slice_regex.test.py @@ -34,7 +34,7 @@ server = Test.MakeOriginServer("server") # Define ATS and configure -ts = Test.MakeATSProcess("ts", command="traffic_manager", select_ports=True) +ts = Test.MakeATSProcess("ts", command="traffic_server") # default root request_header_chk = {"headers": @@ -124,8 +124,8 @@ # minimal configuration ts.Disk.records_config.update({ - 'proxy.config.diags.debug.enabled': 1, - 'proxy.config.diags.debug.tags': 'slice', +# 'proxy.config.diags.debug.enabled': 1, +# 'proxy.config.diags.debug.tags': 'slice', 'proxy.config.http.cache.http': 0, 'proxy.config.http.wait_for_cache': 0, 'proxy.config.http.insert_age_in_response': 0, diff --git a/tests/gold_tests/pluginTest/slice/slice_selfhealing.test.py b/tests/gold_tests/pluginTest/slice/slice_selfhealing.test.py new file mode 100644 index 00000000000..c4583ef28f9 --- /dev/null +++ b/tests/gold_tests/pluginTest/slice/slice_selfhealing.test.py @@ -0,0 +1,391 @@ +''' +''' +# 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. + +Test.Summary = ''' +Slice selfhealing test +''' + +## Test description: +# Preload the cache with the entire asset to be range requested. +# Reload remap rule with slice plugin +# Request content through the slice plugin + +Test.SkipUnless( + Condition.PluginExists('slice.so'), + Condition.PluginExists('cache_range_requests.so'), + Condition.PluginExists('xdebug.so'), +) +Test.ContinueOnFail = False + +# configure origin server +server = Test.MakeOriginServer("server", lookup_key="{%uuid}") + +# Define ATS and configure +ts = Test.MakeATSProcess("ts", command="traffic_server") + +# default root +req_header_chk = {"headers": + "GET / HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: none\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +res_header_chk = {"headers": + "HTTP/1.1 200 OK\r\n" + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +server.addResponse("sessionlog.json", req_header_chk, res_header_chk) + +# set up slice plugin with remap host into cache_range_requests +ts.Disk.remap_config.AddLines([ + 'map http://slice/ http://127.0.0.1:{}/'.format(server.Variables.Port) + + ' @plugin=slice.so @pparam=--blockbytes-test=3 @pparam=--remap-host=cache_range_requests', + 'map http://cache_range_requests/ http://127.0.0.1:{}/'.format(server.Variables.Port) + + ' @plugin=cache_range_requests.so @pparam=--consider-ims', +]) + +ts.Disk.plugin_config.AddLine('xdebug.so') + +# minimal configuration +ts.Disk.records_config.update({ + 'proxy.config.http.cache.http': 1, + 'proxy.config.http.wait_for_cache': 1, +# 'proxy.config.diags.debug.enabled': 1, +# 'proxy.config.diags.debug.tags': 'cache_range_requests|slice', +}) + +curl_and_args = 'curl -s -D /dev/stdout -o /dev/stderr -x localhost:{}'.format(ts.Variables.port) + ' -H "x-debug: x-cache"' + +# Test case: 2nd slice out of date (refetch and continue) + +req_header_2ndold1 = {"headers": + "GET /second HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: etagold-1\r\n" + + "Range: bytes=3-5\r\n" + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +res_header_2ndold1 = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=5000\r\n" + + "Connection: close\r\n" + + "Content-Range: bytes 3-4/5\r\n" + + 'Etag: "etagold"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": "aa" +} + +server.addResponse("sessionlog.json", req_header_2ndold1, res_header_2ndold1) + +req_header_2ndnew0 = {"headers": + "GET /second HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: etagnew-0\r\n" + + "Range: bytes=0-2\r\n" + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +res_header_2ndnew0 = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=5000\r\n" + + "Connection: close\r\n" + + "Content-Range: bytes 0-2/5\r\n" + + 'Etag: "etagnew"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": "bbb" +} + +server.addResponse("sessionlog.json", req_header_2ndnew0, res_header_2ndnew0) + +req_header_2ndnew1 = {"headers": + "GET /second HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: etagnew-1\r\n" + + "Range: bytes=3-5\r\n" + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +res_header_2ndnew1 = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=5000\r\n" + + "Connection: close\r\n" + + "Content-Range: bytes 3-4/5\r\n" + + 'Etag: "etagnew"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": "bb" +} + +server.addResponse("sessionlog.json", req_header_2ndnew1, res_header_2ndnew1) + +# 0 Test - Preload reference etagnew-0 +tr = Test.AddTestRun("Preload reference etagnew-0") +ps = tr.Processes.Default +ps.StartBefore(server, ready=When.PortOpen(server.Variables.Port)) +ps.StartBefore(Test.Processes.ts, ready=When.PortOpen(ts.Variables.port)) +ps.Command = curl_and_args + ' http://cache_range_requests/second -r 0-2 -H "uuid: etagnew-0"' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/bbb.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("etagnew", "expected etagnew") +tr.StillRunningAfter = ts + +# 1 Test - Preload reference etagold-1 +tr = Test.AddTestRun("Preload slice etagold-1") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://cache_range_requests/second -r 3-5 -H "uuid: etagold-1"' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/aa.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("etagold", "expected etagold") +tr.StillRunningAfter = ts + +# 2 Test - Request second slice via slice plugin, with instructions to fetch new 2nd slice +tr = Test.AddTestRun("Request 2nd slice (expect refetch)") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/second -r 3- -H "uuid: etagnew-1"' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/bb.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("etagnew", "expected etagnew") +tr.StillRunningAfter = ts + +# 3 Test - Request fullly healed asset via slice plugin +tr = Test.AddTestRun("Request full healed slice") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/second' +ps.ReturnCode = 0 +ps.Streams.stderr.Content = Testers.ContainsExpression("bbbbb", "expected bbbbb content") +ps.Streams.stdout.Content = Testers.ContainsExpression("etagnew", "expected etagnew") +tr.StillRunningAfter = ts + +# Test case: reference slice out of date (abort connection, heal reference) + +req_header_refold0 = {"headers": + "GET /reference HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: etagold-0\r\n" + + "Range: bytes=0-2\r\n" + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +res_header_refold0 = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=5000\r\n" + + "Connection: close\r\n" + + "Content-Range: bytes 0-2/5\r\n" + + 'Etag: "etagold"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": "aaa" +} + +server.addResponse("sessionlog.json", req_header_refold0, res_header_refold0) + +req_header_refnew0 = {"headers": + "GET /reference HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: etagnew-0\r\n" + + "Range: bytes=0-2\r\n" + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +res_header_refnew0 = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=5000\r\n" + + "Connection: close\r\n" + + "Content-Range: bytes 0-2/5\r\n" + + 'Etag: "etagnew"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": "bbb" +} + +server.addResponse("sessionlog.json", req_header_refnew0, res_header_refnew0) + +req_header_refnew1 = {"headers": + "GET /reference HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: etagnew-1\r\n" + + "Range: bytes=3-5\r\n" + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +res_header_refnew1 = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=5000\r\n" + + "Connection: close\r\n" + + "Content-Range: bytes 3-4/5\r\n" + + 'Etag: "etagnew"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": "bb" +} + +server.addResponse("sessionlog.json", req_header_refnew1, res_header_refnew1) + +# 4 Test - Preload reference etagold-0 +tr = Test.AddTestRun("Preload reference etagold-0") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://cache_range_requests/reference -r 0-2 -H "uuid: etagold-0"' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/aaa.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("etagold", "expected etagold") +tr.StillRunningAfter = ts + +# 5 Test - Preload reference etagnew-1 +tr = Test.AddTestRun("Preload slice etagnew-1") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://cache_range_requests/reference -r 3-5 -H "uuid: etagnew-1"' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/bb.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("etagnew", "expected etagnew") +tr.StillRunningAfter = ts + +# 6 Test - Request reference slice via slice plugin, with instructions to fetch new 2nd slice -- this will send the old header, but abort and refetch it +tr = Test.AddTestRun("Request 2nd slice (expect abort)") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/reference -r 3- -H "uuid: etagnew-0" -w "SENT: \'%{size_download}\'"' +# ps.ReturnCode = 0 # curl will fail here +ps.Streams.stdout.Content = Testers.ContainsExpression("etagold", "expected etagold") +ps.Streams.stdout.Content += Testers.ContainsExpression("SENT: '0'", "expected empty payload") +tr.StillRunningAfter = ts + +# 7 Test - Request full healed asset via slice plugin +tr = Test.AddTestRun("Request full healed slice") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/reference' +ps.ReturnCode = 0 +ps.Streams.stderr.Content = Testers.ContainsExpression("bbbbb", "expected bbbbb content") +ps.Streams.stdout.Content = Testers.ContainsExpression("etagnew", "expected etagnew") +tr.StillRunningAfter = ts + +# Request results in 200, not 206 (server not support range requests) + +req_header_200 = {"headers": + "GET /code200 HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: code200\r\n" + + "Range: bytes=3-5\r\n" + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +res_header_200 = {"headers": + "HTTP/1.1 200 OK\r\n" + + "Cache-Control: max-age=5000\r\n" + + "Connection: close\r\n" + + 'Etag: "etag"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": "ccccc" +} + +server.addResponse("sessionlog.json", req_header_200, res_header_200) + +# 8 test - Request through slice but get a 200 back +tr = Test.AddTestRun("Request gets a 200") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/code200 -r 3-5 -H "uuid: code200"' +ps.ReturnCode = 0 +ps.Streams.stderr.Content = Testers.ContainsExpression("ccccc", "expected full ccccc content") +ps.Streams.stdout.Content = Testers.ContainsExpression("200 OK", "expected 200") +tr.StillRunningAfter = ts + +# Test for asset gone + +# Preload +req_header_assetgone0 = {"headers": + "GET /assetgone HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: assetgone-0\r\n" + + "Range: bytes=0-2\r\n" + "\r\n", + "timestamp": "1469733493.993", + "body": "", +} + +res_header_assetgone0 = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=5000\r\n" + + "Connection: close\r\n" + + "Content-Range: bytes 0-2/5\r\n" + + 'Etag: "etag"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": "aaa" +} + +server.addResponse("sessionlog.json", req_header_assetgone0, res_header_assetgone0) + +# 9 test - Preload reference slice +tr = Test.AddTestRun("Preload reference assetgone-0") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/assetgone -r 0-2 -H "uuid: assetgone-0"' +ps.ReturnCode = 0 +ps.Streams.stderr = "gold/aaa.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("etag", "expected etag") +tr.StillRunningAfter = ts + +# 10 test - Fetch full asset, 2nd slice should trigger 404 response +tr = Test.AddTestRun("Fetch full asset") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/assetgone' +#ps.ReturnCode = 0 # curl will return non zero +ps.Streams.stderr = "gold/aaa.gold" +ps.Streams.stdout.Content = Testers.ContainsExpression("etag", "expected etag") +ps.Streams.stdout.Content += Testers.ContainsExpression("Content-Length: 5", "expected header of content-length 5") +tr.StillRunningAfter = ts + +# 11 test - Fetch full asset again, full blown 404 +tr = Test.AddTestRun("Fetch full asset, 404") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/assetgone' +#ps.ReturnCode = 0 # curl will return non zero +ps.Streams.stdout.Content = Testers.ContainsExpression("404 Not Found", "Expected 404") +tr.StillRunningAfter = ts + +# Over riding the built in ERROR check since we expect to see logSliceErrors +ts.Disk.diags_log.Content = Testers.ContainsExpression("logSliceError", "logSliceErrors generated")