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 b131178eba6..e04668952d5 100644 --- a/doc/admin-guide/plugins/slice.en.rst +++ b/doc/admin-guide/plugins/slice.en.rst @@ -75,19 +75,52 @@ 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 + --disable-errorlog (optional) + Disable writing block stitch errors to the error log. + -d for short + + --exclude-regex= (optional) + If provided, only slice what matches. + If not provided will always slice + Cannot be used with --include-regex + -e for short + + --include-regex= (optional) + If provided, only slice what matches. + If not provided will always slice + Cannot be used with --exclude-regex + -i 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 + --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:: @@ -122,6 +155,16 @@ After modifying :file:`remap.config`, restart or reload traffic server (sudo traffic_ctl config reload) or (sudo traffic_ctl server restart) to activate the new configuration values. +Don't slice txt files:: + + slice.so --exclude-regex=\\.txt + slice.so -e \\.txt + +Slice only mp4 files:: + + slice.so --include-regex=\\.mp4 + slice.so -i \\.mp4 + Debug Options ------------- @@ -136,11 +179,12 @@ Under normal logging these slice block errors tend to show up as:: crc value ERR_READ_ERROR By default more detailed stitching errors are written to ``diags.log``. -Examples are as follows:: -ERROR: [slice.cc: 288] logSliceError(): 1555705573.639 reason="Non 206 internal block response" uri="http://ats_ep/someasset.mp4" uas="curl" req_range="bytes=1000000-" norm_range="bytes 1000000-52428799/52428800" etag_exp="%221603934496%22" lm_exp="Fri, 19 Apr 2019 18:53:20 GMT" blk_range="21000000-21999999" status_got="206" cr_got="" etag_got="%221603934496%22" lm_got="" cc="no-store" via="" +.. topic:: Example -ERROR: [server.cc: 288] logSliceError(): 1572370000.219 reason="Mismatch block Etag" uri="http://ats_ep/someasset.mp4" uas="curl" req_range="bytes=1092779033-1096299354" norm_range="bytes 1092779033-1096299354/2147483648" etag_exp="%223719843648%22" lm_exp="Tue, 29 Oct 2019 14:40:00 GMT" blk_range="1095000000-1095999999" status_got="206" cr_got="bytes 1095000000-1095999999/2147483648" etag_got="%223719853648%22" lm_got="Tue, 29 Oct 2019 17:26:40 GMT" cc="max-age=10000" via="" + ERROR: [slice.cc: 288] logSliceError(): 1555705573.639 reason="Non 206 internal block response" uri="http://ats_ep/someasset.mp4" uas="curl" req_range="bytes=1000000-" norm_range="bytes 1000000-52428799/52428800" etag_exp="%221603934496%22" lm_exp="Fri, 19 Apr 2019 18:53:20 GMT" blk_range="21000000-21999999" status_got="206" cr_got="" etag_got="%221603934496%22" lm_got="" cc="no-store" via="" + + ERROR: [server.cc: 288] logSliceError(): 1572370000.219 reason="Mismatch block Etag" uri="http://ats_ep/someasset.mp4" uas="curl" req_range="bytes=1092779033-1096299354" norm_range="bytes 1092779033-1096299354/2147483648" etag_exp="%223719843648%22" lm_exp="Tue, 29 Oct 2019 14:40:00 GMT" blk_range="1095000000-1095999999" status_got="206" cr_got="bytes 1095000000-1095999999/2147483648" etag_got="%223719853648%22" lm_got="Tue, 29 Oct 2019 17:26:40 GMT" cc="max-age=10000" via="" Whether or how often these detailed log entries are written are configurable plugin options. @@ -172,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 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 =============== @@ -194,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 b6cfd35e63e..fd37efff1ba 100644 --- a/include/ts/experimental.h +++ b/include/ts/experimental.h @@ -426,6 +426,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/experimental/cache_range_requests/cache_range_requests.cc b/plugins/experimental/cache_range_requests/cache_range_requests.cc index 22f415155f3..cf2e04fc7c7 100644 --- a/plugins/experimental/cache_range_requests/cache_range_requests.cc +++ b/plugins/experimental/cache_range_requests/cache_range_requests.cc @@ -21,7 +21,7 @@ * This plugin looks for range requests and then creates a new * cache key url so that each individual range requests is written * to the cache as a individual object so that subsequent range - * requests are read accross different disk drives reducing I/O + * requests are read across different disk drives reducing I/O * wait and load averages when there are large numbers of range * requests. */ @@ -29,14 +29,19 @@ #include "ts/ts.h" #include "ts/remap.h" +#include #include #include #include +#include +#include #define PLUGIN_NAME "cache_range_requests" #define DEBUG_LOG(fmt, ...) TSDebug(PLUGIN_NAME, "[%s:%d] %s(): " fmt, __FILE__, __LINE__, __func__, ##__VA_ARGS__) #define ERROR_LOG(fmt, ...) TSError("[%s:%d] %s(): " fmt, __FILE__, __LINE__, __func__, ##__VA_ARGS__) +namespace +{ typedef enum parent_select_mode { PS_DEFAULT, // Default ATS parent selection mode PS_CACHEKEY_URL, // Set parent selection url to cache_key url @@ -44,36 +49,46 @@ typedef enum parent_select_mode { struct pluginconfig { parent_select_mode_t ps_mode{PS_DEFAULT}; + bool consider_ims_header{false}; bool modify_cache_key{true}; }; struct txndata { - char *range_value; + std::string range_value; + time_t ims_time{0}; }; -static int handle_read_request_header(TSCont, TSEvent, void *); -static void range_header_check(TSHttpTxn txnp, struct pluginconfig *pc); -static void handle_send_origin_request(TSCont, TSHttpTxn, struct txndata *); -static void handle_client_send_response(TSHttpTxn, struct txndata *); -static void handle_server_read_response(TSHttpTxn, struct txndata *); -static int remove_header(TSMBuffer, TSMLoc, const char *, int); -static bool set_header(TSMBuffer, TSMLoc, const char *, int, const char *, int); -static int transaction_handler(TSCont, TSEvent, void *); -static struct pluginconfig *create_pluginconfig(int argc, char *const argv[]); -static void delete_pluginconfig(struct pluginconfig *); +// Header for optional revalidation +constexpr std::string_view X_IMS_HEADER = {"X-Crr-Ims"}; // pluginconfig struct (global plugin only) -static struct pluginconfig *gPluginConfig = nullptr; +pluginconfig *gPluginConfig = {nullptr}; + +int handle_read_request_header(TSCont, TSEvent, void *); +void range_header_check(TSHttpTxn, pluginconfig *const); +void handle_send_origin_request(TSCont, TSHttpTxn, txndata *const); +void handle_client_send_response(TSHttpTxn, txndata *const); +void handle_server_read_response(TSHttpTxn, txndata *const); +int remove_header(TSMBuffer, TSMLoc, const char *, int); +bool set_header(TSMBuffer, TSMLoc, const char *, int, const char *, int); +int transaction_handler(TSCont, TSEvent, void *); +struct pluginconfig *create_pluginconfig(int argc, char *const argv[]); +void delete_pluginconfig(pluginconfig *const); /** * Creates pluginconfig data structure * Sets default parent url selection mode * Walk plugin argument list and updates config */ -static struct pluginconfig * +pluginconfig * create_pluginconfig(int argc, char *const argv[]) { - struct pluginconfig *pc = new pluginconfig; + DEBUG_LOG("Number of arguments: %d", argc); + for (int index = 0; index < argc; ++index) { + DEBUG_LOG("args[%d] = %s", index, argv[index]); + } + + pluginconfig *const pc = new pluginconfig; if (nullptr == pc) { ERROR_LOG("Can't allocate pluginconfig"); @@ -82,6 +97,7 @@ create_pluginconfig(int argc, char *const argv[]) static const struct option longopts[] = { {const_cast("ps-cachekey"), no_argument, nullptr, 'p'}, + {const_cast("consider-ims"), no_argument, nullptr, 'c'}, {const_cast("no-modify-cachekey"), no_argument, nullptr, 'n'}, {nullptr, 0, nullptr, 0}, }; @@ -101,12 +117,15 @@ create_pluginconfig(int argc, char *const argv[]) DEBUG_LOG("Plugin modifies parent selection key"); pc->ps_mode = PS_CACHEKEY_URL; } break; + case 'c': { + DEBUG_LOG("Plugin considers the '%.*s' header", (int)X_IMS_HEADER.size(), X_IMS_HEADER.data()); + pc->consider_ims_header = true; + } break; case 'n': { DEBUG_LOG("Plugin doesn't modify cache key"); pc->modify_cache_key = false; } break; default: { - DEBUG_LOG("Unknown option: '%c'", opt); } break; } } @@ -121,23 +140,21 @@ create_pluginconfig(int argc, char *const argv[]) } /** - * Destroy pluginconfig data stucture. + * Destroy pluginconfig data structure. */ -static void -delete_pluginconfig(struct pluginconfig *pc) +void +delete_pluginconfig(pluginconfig *const pc) { if (nullptr != pc) { DEBUG_LOG("Delete struct pluginconfig"); delete pc; - pc = nullptr; } } /** * Entry point when used as a global plugin. - * */ -static int +int handle_read_request_header(TSCont txn_contp, TSEvent event, void *edata) { TSHttpTxn txnp = static_cast(edata); @@ -158,35 +175,36 @@ handle_read_request_header(TSCont txn_contp, TSEvent event, void *edata) * 3. Schedules TS_HTTP_SEND_REQUEST_HDR_HOOK, TS_HTTP_SEND_RESPONSE_HDR_HOOK, * and TS_HTTP_TXN_CLOSE_HOOK for further processing. */ -static void -range_header_check(TSHttpTxn txnp, struct pluginconfig *pc) +void +range_header_check(TSHttpTxn txnp, pluginconfig *const pc) { char cache_key_url[8192] = {0}; char *req_url; int length, url_length, cache_key_url_length; - struct txndata *txn_state; - TSMBuffer hdr_bufp; - TSMLoc req_hdrs = nullptr; - TSMLoc loc = nullptr; + txndata *txn_state; + TSMBuffer hdr_buf; + TSMLoc hdr_loc = nullptr; + TSMLoc loc = nullptr; TSCont txn_contp; - if (TS_SUCCESS == TSHttpTxnClientReqGet(txnp, &hdr_bufp, &req_hdrs)) { - loc = TSMimeHdrFieldFind(hdr_bufp, req_hdrs, TS_MIME_FIELD_RANGE, TS_MIME_LEN_RANGE); + if (TS_SUCCESS == TSHttpTxnClientReqGet(txnp, &hdr_buf, &hdr_loc)) { + loc = TSMimeHdrFieldFind(hdr_buf, hdr_loc, TS_MIME_FIELD_RANGE, TS_MIME_LEN_RANGE); if (TS_NULL_MLOC != loc) { - const char *hdr_value = TSMimeHdrFieldValueStringGet(hdr_bufp, req_hdrs, loc, 0, &length); + const char *hdr_value = TSMimeHdrFieldValueStringGet(hdr_buf, hdr_loc, loc, 0, &length); + TSHandleMLocRelease(hdr_buf, hdr_loc, loc); + if (!hdr_value || length <= 0) { DEBUG_LOG("Not a range request."); } else { - if (nullptr == (txn_contp = TSContCreate((TSEventFunc)transaction_handler, nullptr))) { + if (nullptr == (txn_contp = TSContCreate(static_cast(transaction_handler), nullptr))) { ERROR_LOG("failed to create the transaction handler continuation."); } else { - txn_state = (struct txndata *)TSmalloc(sizeof(struct txndata)); - txn_state->range_value = TSstrndup(hdr_value, length); - DEBUG_LOG("length: %d, txn_state->range_value: %s", length, txn_state->range_value); - txn_state->range_value[length] = '\0'; // workaround for bug in core - + txn_state = new txndata; + std::string &rv = txn_state->range_value; + rv.assign(hdr_value, length); + DEBUG_LOG("length: %d, txn_state->range_value: %s", length, rv.c_str()); req_url = TSHttpTxnEffectiveUrlStringGet(txnp, &url_length); - cache_key_url_length = snprintf(cache_key_url, 8192, "%s-%s", req_url, txn_state->range_value); + cache_key_url_length = snprintf(cache_key_url, 8192, "%s-%s", req_url, rv.c_str()); DEBUG_LOG("Rewriting cache URL for %s to %s", req_url, cache_key_url); if (req_url != nullptr) { TSfree(req_url); @@ -209,18 +227,31 @@ range_header_check(TSHttpTxn txnp, struct pluginconfig *pc) if (PS_CACHEKEY_URL == pc->ps_mode) { const char *start = cache_key_url; const char *end = cache_key_url + cache_key_url_length; - if (TS_SUCCESS == TSUrlCreate(hdr_bufp, &ps_loc) && - TS_PARSE_DONE == TSUrlParse(hdr_bufp, ps_loc, &start, end) && // This should always succeed. - TS_SUCCESS == TSHttpTxnParentSelectionUrlSet(txnp, hdr_bufp, ps_loc)) { + if (TS_SUCCESS == TSUrlCreate(hdr_buf, &ps_loc) && + TS_PARSE_DONE == TSUrlParse(hdr_buf, ps_loc, &start, end) && // This should always succeed. + TS_SUCCESS == TSHttpTxnParentSelectionUrlSet(txnp, hdr_buf, ps_loc)) { DEBUG_LOG("Set Parent Selection URL to cache_key_url: %s", cache_key_url); - TSHandleMLocRelease(hdr_bufp, TS_NULL_MLOC, ps_loc); + TSHandleMLocRelease(hdr_buf, TS_NULL_MLOC, ps_loc); + } + } + } + + // optionally consider an X-CRR-IMS header + if (pc->consider_ims_header) { + 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; } } } } // remove the range request header. - if (remove_header(hdr_bufp, req_hdrs, TS_MIME_FIELD_RANGE, TS_MIME_LEN_RANGE) > 0) { + if (remove_header(hdr_buf, hdr_loc, TS_MIME_FIELD_RANGE, TS_MIME_LEN_RANGE) > 0) { DEBUG_LOG("Removed the Range: header from the request."); } @@ -229,13 +260,18 @@ range_header_check(TSHttpTxn txnp, struct pluginconfig *pc) TSHttpTxnHookAdd(txnp, TS_HTTP_SEND_RESPONSE_HDR_HOOK, txn_contp); TSHttpTxnHookAdd(txnp, TS_HTTP_TXN_CLOSE_HOOK, txn_contp); DEBUG_LOG("Added TS_HTTP_SEND_REQUEST_HDR_HOOK, TS_HTTP_SEND_RESPONSE_HDR_HOOK, and TS_HTTP_TXN_CLOSE_HOOK"); + + if (0 < txn_state->ims_time) { + TSHttpTxnHookAdd(txnp, TS_HTTP_CACHE_LOOKUP_COMPLETE_HOOK, txn_contp); + DEBUG_LOG("Also Added TS_HTTP_CACHE_LOOKUP_COMPLETE_HOOK"); + } } } - TSHandleMLocRelease(hdr_bufp, req_hdrs, loc); + // TSHandleMLocRelease(hdr_buf, hdr_loc, loc); } else { DEBUG_LOG("no range request header."); } - TSHandleMLocRelease(hdr_bufp, TS_NULL_MLOC, req_hdrs); + TSHandleMLocRelease(hdr_buf, TS_NULL_MLOC, hdr_loc); } else { DEBUG_LOG("failed to retrieve the server request"); } @@ -245,41 +281,44 @@ range_header_check(TSHttpTxn txnp, struct pluginconfig *pc) * Restores the range request header if the request must be * satisfied from the origin and schedules the TS_READ_RESPONSE_HDR_HOOK. */ -static void -handle_send_origin_request(TSCont contp, TSHttpTxn txnp, struct txndata *txn_state) +void +handle_send_origin_request(TSCont contp, TSHttpTxn txnp, txndata *const txn_state) { - TSMBuffer hdr_bufp; - TSMLoc req_hdrs = nullptr; + TSMBuffer hdr_buf; + TSMLoc hdr_loc = nullptr; - if (TS_SUCCESS == TSHttpTxnServerReqGet(txnp, &hdr_bufp, &req_hdrs) && txn_state->range_value != nullptr) { - if (set_header(hdr_bufp, req_hdrs, TS_MIME_FIELD_RANGE, TS_MIME_LEN_RANGE, txn_state->range_value, - strlen(txn_state->range_value))) { - DEBUG_LOG("Added range header: %s", txn_state->range_value); + std::string const &rv = txn_state->range_value; + + if (TS_SUCCESS == TSHttpTxnServerReqGet(txnp, &hdr_buf, &hdr_loc) && !rv.empty()) { + if (set_header(hdr_buf, hdr_loc, TS_MIME_FIELD_RANGE, TS_MIME_LEN_RANGE, rv.data(), rv.length())) { + DEBUG_LOG("Added range header: %s", rv.c_str()); TSHttpTxnHookAdd(txnp, TS_HTTP_READ_RESPONSE_HDR_HOOK, contp); } } - TSHandleMLocRelease(hdr_bufp, TS_NULL_MLOC, req_hdrs); + TSHandleMLocRelease(hdr_buf, TS_NULL_MLOC, hdr_loc); } /** * Changes the response code back to a 206 Partial content before * replying to the client that requested a range. */ -static void -handle_client_send_response(TSHttpTxn txnp, struct txndata *txn_state) +void +handle_client_send_response(TSHttpTxn txnp, txndata *const txn_state) { bool partial_content_reason = false; char *p; int length; - TSMBuffer response, hdr_bufp; - TSMLoc resp_hdr, req_hdrs = nullptr; + TSMBuffer resp_buf = nullptr; + TSMBuffer req_buf = nullptr; + TSMLoc resp_loc = nullptr; + TSMLoc req_loc = nullptr; - TSReturnCode result = TSHttpTxnClientRespGet(txnp, &response, &resp_hdr); + TSReturnCode result = TSHttpTxnClientRespGet(txnp, &resp_buf, &resp_loc); DEBUG_LOG("result: %d", result); if (TS_SUCCESS == result) { - TSHttpStatus status = TSHttpHdrStatusGet(response, resp_hdr); + TSHttpStatus status = TSHttpHdrStatusGet(resp_buf, resp_loc); // a cached result will have a TS_HTTP_OK with a 'Partial Content' reason - if ((p = (char *)TSHttpHdrReasonGet(response, resp_hdr, &length)) != nullptr) { + if ((p = const_cast(TSHttpHdrReasonGet(resp_buf, resp_loc, &length))) != nullptr) { if ((length == 15) && (0 == strncasecmp(p, "Partial Content", length))) { partial_content_reason = true; } @@ -287,23 +326,23 @@ handle_client_send_response(TSHttpTxn txnp, struct txndata *txn_state) DEBUG_LOG("%d %.*s", status, length, p); if (TS_HTTP_STATUS_OK == status && partial_content_reason) { DEBUG_LOG("Got TS_HTTP_STATUS_OK."); - TSHttpHdrStatusSet(response, resp_hdr, TS_HTTP_STATUS_PARTIAL_CONTENT); + TSHttpHdrStatusSet(resp_buf, resp_loc, TS_HTTP_STATUS_PARTIAL_CONTENT); DEBUG_LOG("Set response header to TS_HTTP_STATUS_PARTIAL_CONTENT."); } } + std::string const &rv = txn_state->range_value; // add the range request header back in so that range requests may be logged. - if (TS_SUCCESS == TSHttpTxnClientReqGet(txnp, &hdr_bufp, &req_hdrs) && txn_state->range_value != nullptr) { - if (set_header(hdr_bufp, req_hdrs, TS_MIME_FIELD_RANGE, TS_MIME_LEN_RANGE, txn_state->range_value, - strlen(txn_state->range_value))) { - DEBUG_LOG("added range header: %s", txn_state->range_value); + if (TS_SUCCESS == TSHttpTxnClientReqGet(txnp, &req_buf, &req_loc) && !rv.empty()) { + if (set_header(req_buf, req_loc, TS_MIME_FIELD_RANGE, TS_MIME_LEN_RANGE, rv.data(), rv.length())) { + DEBUG_LOG("added range header: %s", rv.c_str()); } else { DEBUG_LOG("set_header() failed."); } } else { DEBUG_LOG("failed to get Request Headers"); } - TSHandleMLocRelease(response, TS_NULL_MLOC, resp_hdr); - TSHandleMLocRelease(hdr_bufp, TS_NULL_MLOC, req_hdrs); + TSHandleMLocRelease(resp_buf, TS_NULL_MLOC, resp_loc); + TSHandleMLocRelease(req_buf, TS_NULL_MLOC, req_loc); } /** @@ -311,20 +350,20 @@ handle_client_send_response(TSHttpTxn txnp, struct txndata *txn_state) * the response code from a 206 Partial content to a 200 OK so that * the response will be written to cache. */ -static void -handle_server_read_response(TSHttpTxn txnp, struct txndata *txn_state) +void +handle_server_read_response(TSHttpTxn txnp, txndata *const txn_state) { - TSMBuffer response; - TSMLoc resp_hdr; + TSMBuffer resp_buf = nullptr; + TSMLoc resp_loc = nullptr; TSHttpStatus status; - if (TS_SUCCESS == TSHttpTxnServerRespGet(txnp, &response, &resp_hdr)) { - status = TSHttpHdrStatusGet(response, resp_hdr); + if (TS_SUCCESS == TSHttpTxnServerRespGet(txnp, &resp_buf, &resp_loc)) { + status = TSHttpHdrStatusGet(resp_buf, resp_loc); if (TS_HTTP_STATUS_PARTIAL_CONTENT == status) { DEBUG_LOG("Got TS_HTTP_STATUS_PARTIAL_CONTENT."); - TSHttpHdrStatusSet(response, resp_hdr, TS_HTTP_STATUS_OK); + TSHttpHdrStatusSet(resp_buf, resp_loc, TS_HTTP_STATUS_OK); DEBUG_LOG("Set response header to TS_HTTP_STATUS_OK."); - bool cacheable = TSHttpTxnIsCacheable(txnp, nullptr, response); + bool cacheable = TSHttpTxnIsCacheable(txnp, nullptr, resp_buf); DEBUG_LOG("range is cacheable: %d", cacheable); } else if (TS_HTTP_STATUS_OK == status) { DEBUG_LOG("The origin does not support range requests, attempting to disable cache write."); @@ -335,7 +374,7 @@ handle_server_read_response(TSHttpTxn txnp, struct txndata *txn_state) } } } - TSHandleMLocRelease(response, TS_NULL_MLOC, resp_hdr); + TSHandleMLocRelease(resp_buf, TS_NULL_MLOC, resp_loc); } /** @@ -344,18 +383,18 @@ handle_server_read_response(TSHttpTxn txnp, struct txndata *txn_state) * * From background_fetch.cc */ -static int -remove_header(TSMBuffer bufp, TSMLoc hdr_loc, const char *header, int len) +int +remove_header(TSMBuffer buf, TSMLoc hdr_loc, const char *header, int len) { - TSMLoc field = TSMimeHdrFieldFind(bufp, hdr_loc, header, len); + TSMLoc field = TSMimeHdrFieldFind(buf, hdr_loc, header, len); int cnt = 0; while (field) { - TSMLoc tmp = TSMimeHdrFieldNextDup(bufp, hdr_loc, field); + TSMLoc tmp = TSMimeHdrFieldNextDup(buf, hdr_loc, field); ++cnt; - TSMimeHdrFieldDestroy(bufp, hdr_loc, field); - TSHandleMLocRelease(bufp, hdr_loc, field); + TSMimeHdrFieldDestroy(buf, hdr_loc, field); + TSHandleMLocRelease(buf, hdr_loc, field); field = tmp; } @@ -369,25 +408,25 @@ remove_header(TSMBuffer bufp, TSMLoc hdr_loc, const char *header, int len) * * From background_fetch.cc */ -static bool -set_header(TSMBuffer bufp, TSMLoc hdr_loc, const char *header, int len, const char *val, int val_len) +bool +set_header(TSMBuffer buf, TSMLoc hdr_loc, const char *header, int len, const char *val, int val_len) { - if (!bufp || !hdr_loc || !header || len <= 0 || !val || val_len <= 0) { + if (!buf || !hdr_loc || !header || len <= 0 || !val || val_len <= 0) { return false; } DEBUG_LOG("header: %s, len: %d, val: %s, val_len: %d", header, len, val, val_len); bool ret = false; - TSMLoc field_loc = TSMimeHdrFieldFind(bufp, hdr_loc, header, len); + TSMLoc field_loc = TSMimeHdrFieldFind(buf, hdr_loc, header, len); if (!field_loc) { // No existing header, so create one - if (TS_SUCCESS == TSMimeHdrFieldCreateNamed(bufp, hdr_loc, header, len, &field_loc)) { - if (TS_SUCCESS == TSMimeHdrFieldValueStringSet(bufp, hdr_loc, field_loc, -1, val, val_len)) { - TSMimeHdrFieldAppend(bufp, hdr_loc, field_loc); + if (TS_SUCCESS == TSMimeHdrFieldCreateNamed(buf, hdr_loc, header, len, &field_loc)) { + if (TS_SUCCESS == TSMimeHdrFieldValueStringSet(buf, hdr_loc, field_loc, -1, val, val_len)) { + TSMimeHdrFieldAppend(buf, hdr_loc, field_loc); ret = true; } - TSHandleMLocRelease(bufp, hdr_loc, field_loc); + TSHandleMLocRelease(buf, hdr_loc, field_loc); } } else { TSMLoc tmp = nullptr; @@ -396,14 +435,14 @@ set_header(TSMBuffer bufp, TSMLoc hdr_loc, const char *header, int len, const ch while (field_loc) { if (first) { first = false; - if (TS_SUCCESS == TSMimeHdrFieldValueStringSet(bufp, hdr_loc, field_loc, -1, val, val_len)) { + if (TS_SUCCESS == TSMimeHdrFieldValueStringSet(buf, hdr_loc, field_loc, -1, val, val_len)) { ret = true; } } else { - TSMimeHdrFieldDestroy(bufp, hdr_loc, field_loc); + TSMimeHdrFieldDestroy(buf, hdr_loc, field_loc); } - tmp = TSMimeHdrFieldNextDup(bufp, hdr_loc, field_loc); - TSHandleMLocRelease(bufp, hdr_loc, field_loc); + tmp = TSMimeHdrFieldNextDup(buf, hdr_loc, field_loc); + TSHandleMLocRelease(buf, hdr_loc, field_loc); field_loc = tmp; } } @@ -411,6 +450,93 @@ set_header(TSMBuffer bufp, TSMLoc hdr_loc, const char *header, int len, const ch return ret; } +time_t +get_date_from_cached_hdr(TSHttpTxn txn) +{ + TSMBuffer buf; + TSMLoc hdr_loc, date_loc; + time_t date = 0; + + if (TSHttpTxnCachedRespGet(txn, &buf, &hdr_loc) == TS_SUCCESS) { + date_loc = TSMimeHdrFieldFind(buf, hdr_loc, TS_MIME_FIELD_DATE, TS_MIME_LEN_DATE); + if (date_loc != TS_NULL_MLOC) { + date = TSMimeHdrFieldValueDateGet(buf, hdr_loc, date_loc); + TSHandleMLocRelease(buf, hdr_loc, date_loc); + } + TSHandleMLocRelease(buf, TS_NULL_MLOC, hdr_loc); + } + + return date; +} + +/** + * Handle a special IMS request. + */ +void +handle_cache_lookup_complete(TSHttpTxn txnp, txndata *const txn_state) +{ + int cachestat; + 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 %jd vs IMS %jd", static_cast(ch_time), + static_cast(txn_state->ims_time)); + if (ch_time < txn_state->ims_time) { + TSHttpTxnCacheLookupStatusSet(txnp, TS_CACHE_LOOKUP_HIT_STALE); + if (TSIsDebugTagSet(PLUGIN_NAME)) { + int url_len = 0; + char *const req_url = TSHttpTxnEffectiveUrlStringGet(txnp, &url_len); + if (nullptr != req_url) { + std::string const &rv = txn_state->range_value; + DEBUG_LOG("Forced revalidate %.*s-%s", url_len, req_url, rv.c_str()); + + TSfree(req_url); + } + } + } + } + } +} + +/** + * Transaction event handler. + */ +int +transaction_handler(TSCont contp, TSEvent event, void *edata) +{ + TSHttpTxn txnp = static_cast(edata); + txndata *const txn_state = static_cast(TSContDataGet(contp)); + + switch (event) { + case TS_EVENT_HTTP_READ_RESPONSE_HDR: + handle_server_read_response(txnp, txn_state); + break; + case TS_EVENT_HTTP_SEND_REQUEST_HDR: + handle_send_origin_request(contp, txnp, txn_state); + break; + case TS_EVENT_HTTP_SEND_RESPONSE_HDR: + handle_client_send_response(txnp, txn_state); + break; + case TS_EVENT_HTTP_CACHE_LOOKUP_COMPLETE: + handle_cache_lookup_complete(txnp, txn_state); + break; + case TS_EVENT_HTTP_TXN_CLOSE: + if (txn_state != nullptr) { + TSContDataSet(contp, nullptr); + delete txn_state; + } + TSContDestroy(contp); + break; + default: + TSAssert(!"Unexpected event"); + break; + } + TSHttpTxnReenable(txnp, TS_EVENT_HTTP_CONTINUE); + return 0; +} + +} // namespace + /** * Remap initialization. */ @@ -447,7 +573,7 @@ TSRemapNewInstance(int argc, char *argv[], void **ih, char * /*errbuf */, int /* char *const *plugin_argv = const_cast(argv); // Parse the argument list. - *ih = (struct pluginconfig *)create_pluginconfig(argc - 2, plugin_argv + 2); + *ih = static_cast(create_pluginconfig(argc - 2, plugin_argv + 2)); if (*ih == nullptr) { ERROR_LOG("Can't create pluginconfig"); @@ -462,7 +588,7 @@ TSRemapNewInstance(int argc, char *argv[], void **ih, char * /*errbuf */, int /* void TSRemapDeleteInstance(void *ih) { - struct pluginconfig *pc = (struct pluginconfig *)ih; + pluginconfig *const pc = static_cast(ih); if (nullptr != pc) { delete_pluginconfig(pc); @@ -475,7 +601,7 @@ TSRemapDeleteInstance(void *ih) TSRemapStatus TSRemapDoRemap(void *ih, TSHttpTxn txnp, TSRemapRequestInfo * /* rri */) { - struct pluginconfig *pc = (struct pluginconfig *)ih; + pluginconfig *const pc = static_cast(ih); range_header_check(txnp, pc); @@ -502,53 +628,16 @@ TSPluginInit(int argc, const char *argv[]) } if (nullptr == gPluginConfig) { - if (argc > 1) { - // Skip ahead of first param (name of traffic server plugin shared object) + if (1 < argc) { char *const *plugin_argv = const_cast(argv); gPluginConfig = create_pluginconfig(argc - 1, plugin_argv + 1); } } - if (nullptr == (txnp_cont = TSContCreate((TSEventFunc)handle_read_request_header, nullptr))) { + if (nullptr == (txnp_cont = TSContCreate(static_cast(handle_read_request_header), nullptr))) { ERROR_LOG("failed to create the transaction continuation handler."); return; } else { TSHttpHookAdd(TS_HTTP_READ_REQUEST_HDR_HOOK, txnp_cont); } } - -/** - * Transaction event handler. - */ -static int -transaction_handler(TSCont contp, TSEvent event, void *edata) -{ - TSHttpTxn txnp = static_cast(edata); - struct txndata *txn_state = (struct txndata *)TSContDataGet(contp); - - switch (event) { - case TS_EVENT_HTTP_READ_RESPONSE_HDR: - handle_server_read_response(txnp, txn_state); - break; - case TS_EVENT_HTTP_SEND_REQUEST_HDR: - handle_send_origin_request(contp, txnp, txn_state); - break; - case TS_EVENT_HTTP_SEND_RESPONSE_HDR: - handle_client_send_response(txnp, txn_state); - break; - case TS_EVENT_HTTP_TXN_CLOSE: - if (txn_state != nullptr && txn_state->range_value != nullptr) { - TSfree(txn_state->range_value); - } - if (txn_state != nullptr) { - TSfree(txn_state); - } - TSContDestroy(contp); - break; - default: - TSAssert(!"Unexpected event"); - break; - } - TSHttpTxnReenable(txnp, TS_EVENT_HTTP_CONTINUE); - return 0; -} diff --git a/plugins/experimental/slice/Config.cc b/plugins/experimental/slice/Config.cc index fb04ebb27b8..54df2f1428b 100644 --- a/plugins/experimental/slice/Config.cc +++ b/plugins/experimental/slice/Config.cc @@ -26,6 +26,20 @@ #include "ts/experimental.h" +Config::~Config() +{ + if (nullptr != m_regex_extra) { +#ifndef PCRE_STUDY_JIT_COMPILE + pcre_free(m_regex_extra); +#else + pcre_free_study(m_regex_extra); +#endif + } + if (nullptr != m_regex) { + pcre_free(m_regex); + } +} + int64_t Config::bytesFrom(char const *const valstr) { @@ -94,18 +108,21 @@ Config::fromArgs(int const argc, char const *const argv[]) // standard parsing constexpr struct option longopts[] = { {const_cast("blockbytes"), required_argument, nullptr, 'b'}, - {const_cast("blockbytes-test"), required_argument, nullptr, 't'}, - {const_cast("remap-host"), required_argument, nullptr, 'r'}, - {const_cast("pace-errorlog"), required_argument, nullptr, 'p'}, {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'}, + {const_cast("blockbytes-test"), required_argument, nullptr, 't'}, {nullptr, 0, nullptr, 0}, }; // 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:t:r:p:do", longopts, nullptr); + int const opt = getopt_long(argc + 1, argvp, "b:de:i:lop:r:t:", longopts, nullptr); if (-1 == opt) { break; } @@ -122,6 +139,65 @@ Config::fromArgs(int const argc, char const *const argv[]) ERROR_LOG("Invalid blockbytes: %s", optarg); } } break; + case 'd': { + m_paceerrsecs = -1; + } break; + case 'e': { + if (None != m_regex_type) { + ERROR_LOG("Regex already specified!"); + break; + } + + const char *errptr; + int erroffset; + m_regexstr = optarg; + m_regex = pcre_compile(m_regexstr.c_str(), 0, &errptr, &erroffset, nullptr); + if (nullptr == m_regex) { + ERROR_LOG("Invalid regex: '%s'", m_regexstr.c_str()); + } else { + m_regex_type = Exclude; + m_regex_extra = pcre_study(m_regex, 0, &errptr); + DEBUG_LOG("Using regex for url exclude: '%s'", m_regexstr.c_str()); + } + } break; + case 'i': { + if (None != m_regex_type) { + ERROR_LOG("Regex already specified!"); + break; + } + + const char *errptr; + int erroffset; + m_regexstr = optarg; + m_regex = pcre_compile(m_regexstr.c_str(), 0, &errptr, &erroffset, nullptr); + if (nullptr == m_regex) { + ERROR_LOG("Invalid regex: '%s'", m_regexstr.c_str()); + } else { + m_regex_type = Include; + m_regex_extra = pcre_study(m_regex, 0, &errptr); + 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"); + } break; + case 'p': { + int const secsread = atoi(optarg); + if (0 < secsread) { + m_paceerrsecs = std::min(secsread, 60); + } else { + ERROR_LOG("Ignoring pace-errlog argument"); + } + } break; + case 'r': { + m_remaphost = optarg; + DEBUG_LOG("Using loopback remap host override: %s", m_remaphost.c_str()); + } break; case 't': { if (0 == blockbytes) { int64_t const bytesread = bytesFrom(optarg); @@ -135,25 +211,6 @@ Config::fromArgs(int const argc, char const *const argv[]) DEBUG_LOG("Skipping blockbytes-test in favor of blockbytes"); } } break; - case 'r': - m_remaphost = optarg; - DEBUG_LOG("Using loopback remap host override: %s", m_remaphost.c_str()); - break; - case 'p': { - int const secsread = atoi(optarg); - if (0 < secsread) { - m_paceerrsecs = std::min(secsread, 60); - } else { - ERROR_LOG("Ignoring pace-errlog argument"); - } - } break; - case 'd': - m_paceerrsecs = -1; - break; - case 'o': - m_throttle = true; - DEBUG_LOG("Enabling internal block throttling"); - break; default: break; } @@ -204,3 +261,26 @@ Config::canLogError() return true; } + +bool +Config::matchesRegex(char const *const url, int const urllen) const +{ + bool matches = true; + + switch (m_regex_type) { + case Exclude: { + if (0 <= pcre_exec(m_regex, m_regex_extra, url, urllen, 0, 0, nullptr, 0)) { + matches = false; + } + } break; + case Include: { + if (pcre_exec(m_regex, m_regex_extra, url, urllen, 0, 0, nullptr, 0) < 0) { + matches = false; + } + } break; + default: + break; + } + + return matches; +} diff --git a/plugins/experimental/slice/Config.h b/plugins/experimental/slice/Config.h index 42de33d1bef..1f59511e8c0 100644 --- a/plugins/experimental/slice/Config.h +++ b/plugins/experimental/slice/Config.h @@ -20,6 +20,12 @@ #include "slice.h" +#ifdef HAVE_PCRE_PCRE_H +#include +#else +#include +#endif + #include // Data Structures and Classes @@ -30,18 +36,38 @@ struct Config { int64_t m_blockbytes{blockbytesdefault}; std::string m_remaphost; // remap host to use for loopback slice GET - bool m_throttle{false}; // internal block throttling - int m_paceerrsecs{0}; // -1 disable logging, 0 no pacing, max 60s + std::string m_regexstr; // regex string for things to slice (default all) + enum RegexType { None, Include, Exclude }; + RegexType m_regex_type{None}; + pcre *m_regex{nullptr}; + 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); + // clean up pcre if applicable + ~Config(); + // Parse from args, ast one wins bool fromArgs(int const argc, char const *const argv[]); // Check if the error should can be logged, if sucessful may update m_nexttime bool canLogError(); + // Check if regex supplied + bool + hasRegex() const + { + return None != m_regex_type; + } + + // If no null reg, true, otherwise check against regex + bool matchesRegex(char const *const url, int const urllen) const; + private: TSHRTime m_nextlogtime{0}; // next time to log in ns std::mutex m_mutex; 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.h b/plugins/experimental/slice/Data.h index 3150bd299b8..f8cdd641ee3 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; @@ -36,37 +48,42 @@ struct Data { sockaddr_storage m_client_ip; + // transaction pointer + TSHttpTxn m_txnp{nullptr}; + // for pristine/effective url coming in TSMBuffer m_urlbuf{nullptr}; 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,49 +93,27 @@ 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'; -#if defined(COLLECT_STATS) - TSStatIntIncrement(stats::DataCreate, 1); -#endif + m_lastmodified[0] = '\0'; } ~Data() { -#if defined(COLLECT_STATS) - TSStatIntIncrement(stats::DataDestroy, 1); -#endif 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 99137018066..d98d112a3f7 100644 --- a/plugins/experimental/slice/HttpHeader.cc +++ b/plugins/experimental/slice/HttpHeader.cc @@ -20,6 +20,7 @@ #include "slice.h" +#include #include #include @@ -54,18 +55,20 @@ HttpHeader::setStatus(TSHttpStatus const newstatus) } char * -HttpHeader ::urlString(int *const urllen) const +HttpHeader::urlString(int *const urllen) const { char *urlstr = nullptr; TSAssert(nullptr != urllen); TSMLoc locurl = nullptr; TSReturnCode const rcode = TSHttpHdrUrlGet(m_buffer, m_lochdr, &locurl); - if (TS_SUCCESS == rcode && nullptr != locurl) { - urlstr = TSUrlStringGet(m_buffer, locurl, urllen); + if (nullptr != locurl) { + if (TS_SUCCESS == rcode) { + urlstr = TSUrlStringGet(m_buffer, locurl, urllen); + } else { + *urllen = 0; + } TSHandleMLocRelease(m_buffer, m_lochdr, locurl); - } else { - *urllen = 0; } return urlstr; @@ -229,81 +232,90 @@ HttpHeader::setKeyVal(char const *const keystr, int const keylen, char const *co return status; } -std::string -HttpHeader::toString() const +bool +HttpHeader::timeForKey(char const *const keystr, int const keylen, time_t *const timeval) const { - std::string res; + TSAssert(nullptr != timeval); if (!isValid()) { - return ""; + *timeval = 0; + return false; } - TSHttpType const htype(type()); - - switch (htype) { - case TS_HTTP_TYPE_REQUEST: { - res.append(method()); + bool status = false; - int urllen = 0; - char *const urlstr = urlString(&urllen); - if (nullptr != urlstr) { - res.append(" "); - res.append(urlstr, urllen); - TSfree(urlstr); - } else { - res.append(" UnknownURL"); - } + TSMLoc const locfield = TSMimeHdrFieldFind(m_buffer, m_lochdr, keystr, keylen); - res.append(" HTTP/unparsed"); - } break; + if (nullptr != locfield) { + *timeval = TSMimeHdrFieldValueDateGet(m_buffer, m_lochdr, locfield); + TSHandleMLocRelease(m_buffer, m_lochdr, locfield); + } else { + *timeval = 0; + } - case TS_HTTP_TYPE_RESPONSE: { - char bufstr[1024]; - /* - int const version = TSHttpHdrVersionGet(m_buffer, m_lochdr); - snprintf(bufstr, 1023, "%d ", version); - res.append(bufstr); - */ - res.append("HTTP/unparsed"); + return status; +} - int const status = TSHttpHdrStatusGet(m_buffer, m_lochdr); - snprintf(bufstr, 1023, " %d ", status); - res.append(bufstr); +bool +HttpHeader::setKeyTime(char const *const keystr, int const keylen, time_t const timeval) +{ + if (!isValid()) { + return false; + } - int reasonlen = 0; - char const *const hreason = reason(&reasonlen); + bool status(false); - res.append(hreason, reasonlen); - } break; + TSMLoc locfield(TSMimeHdrFieldFind(m_buffer, m_lochdr, keystr, keylen)); - default: - case TS_HTTP_TYPE_UNKNOWN: - res.append("UNKNOWN"); - break; + if (nullptr == locfield) { + DEBUG_LOG("Creating header %.*s", keylen, keystr); + TSMimeHdrFieldCreateNamed(m_buffer, m_lochdr, keystr, keylen, &locfield); } - res.append("\r\n"); - - int const numhdrs = TSMimeHdrFieldsCount(m_buffer, m_lochdr); + 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 %jd", keylen, keystr, static_cast(timeval)); + } + } + TSHandleMLocRelease(m_buffer, m_lochdr, locfield); + } - for (int indexhdr = 0; indexhdr < numhdrs; ++indexhdr) { - TSMLoc const locfield = TSMimeHdrFieldGet(m_buffer, m_lochdr, indexhdr); + return status; +} - int keylen = 0; - char const *const keystr = TSMimeHdrFieldNameGet(m_buffer, m_lochdr, locfield, &keylen); +std::string +HttpHeader::toString() const +{ + std::string res; - res.append(keystr, keylen); - res.append(": "); - int vallen = 0; - char const *const valstr = TSMimeHdrFieldValueStringGet(m_buffer, m_lochdr, locfield, -1, &vallen); + if (isValid()) { + TSIOBuffer const iobufp = TSIOBufferCreate(); + TSHttpHdrPrint(m_buffer, m_lochdr, iobufp); + TSIOBufferReader const reader = TSIOBufferReaderAlloc(iobufp); + + if (nullptr != reader) { + TSIOBufferBlock block = TSIOBufferReaderStart(reader); + bool done = false; + while (!done && nullptr != block) { + int64_t avail = 0; + char const *blockptr = TSIOBufferBlockReadStart(block, reader, &avail); + if (0 < avail) { + res.append(blockptr, avail); + } + block = TSIOBufferBlockNext(block); + } - res.append(valstr, vallen); - res.append("\r\n"); + TSIOBufferReaderFree(reader); + } - TSHandleMLocRelease(m_buffer, m_lochdr, locfield); + TSIOBufferDestroy(iobufp); } - res.append("\r\n"); + if (res.empty()) { + res = ""; + } return res; } diff --git a/plugins/experimental/slice/HttpHeader.h b/plugins/experimental/slice/HttpHeader.h index fa3f6cf0549..8d05db9c57d 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/Makefile.inc b/plugins/experimental/slice/Makefile.inc index 21f6166f5aa..be376ca1c64 100644 --- a/plugins/experimental/slice/Makefile.inc +++ b/plugins/experimental/slice/Makefile.inc @@ -49,6 +49,8 @@ experimental_slice_test_content_range_SOURCES = \ experimental/slice/unit-tests/test_content_range.cc \ experimental/slice/ContentRange.cc +experimental_slice_test_content_range_LDADD = @LIBPCRE@ + check_PROGRAMS += experimental/slice/test_range experimental_slice_test_range_CPPFLAGS = $(AM_CPPFLAGS) -I$(abs_top_srcdir)/tests/include -DUNITTEST @@ -56,9 +58,13 @@ experimental_slice_test_range_SOURCES = \ experimental/slice/unit-tests/test_range.cc \ experimental/slice/Range.cc +experimental_slice_test_range_LDADD = @LIBPCRE@ + check_PROGRAMS += experimental/slice/test_config experimental_slice_test_config_CPPFLAGS = $(AM_CPPFLAGS) -I$(abs_top_srcdir)/tests/include -DUNITTEST experimental_slice_test_config_SOURCES = \ experimental/slice/unit-tests/test_config.cc \ experimental/slice/Config.cc + +experimental_slice_test_config_LDADD = @LIBPCRE@ diff --git a/plugins/experimental/slice/Range.cc b/plugins/experimental/slice/Range.cc index b52e8b66e40..67360540bcf 100644 --- a/plugins/experimental/slice/Range.cc +++ b/plugins/experimental/slice/Range.cc @@ -156,7 +156,7 @@ int64_t Range::lastBlockFor(int64_t const blocksize) const { if (0 < blocksize && isValid()) { - return std::max((int64_t)0, (m_end - 1) / blocksize); + return std::max(static_cast(0), (m_end - 1) / blocksize); } else { return -1; } diff --git a/plugins/experimental/slice/Range.h b/plugins/experimental/slice/Range.h index 8c8826d2091..44ef1dea2cf 100644 --- a/plugins/experimental/slice/Range.h +++ b/plugins/experimental/slice/Range.h @@ -29,10 +29,10 @@ struct Range { public: - static int64_t constexpr maxval = (std::numeric_limits::max() >> 2); + 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/Stage.h b/plugins/experimental/slice/Stage.h index a2d7c4fdc6f..47ae28a96df 100644 --- a/plugins/experimental/slice/Stage.h +++ b/plugins/experimental/slice/Stage.h @@ -34,9 +34,6 @@ struct Channel { { if (nullptr != m_reader) { TSIOBufferReaderFree(m_reader); -#if defined(COLLECT_STATS) - TSStatIntDecrement(stats::Reader, 1); -#endif } if (nullptr != m_iobuf) { TSIOBufferDestroy(m_iobuf); @@ -67,9 +64,6 @@ struct Channel { if (nullptr == m_iobuf) { m_iobuf = TSIOBufferCreate(); m_reader = TSIOBufferReaderAlloc(m_iobuf); -#if defined(COLLECT_STATS) - TSStatIntIncrement(stats::Reader, 1); -#endif } else { int64_t const drained = drainReader(); if (0 < drained) { @@ -87,9 +81,6 @@ struct Channel { if (nullptr == m_iobuf) { m_iobuf = TSIOBufferCreate(); m_reader = TSIOBufferReaderAlloc(m_iobuf); -#if defined(COLLECT_STATS) - TSStatIntIncrement(stats::Reader, 1); -#endif } else { int64_t const drained = drainReader(); if (0 < drained) { diff --git a/plugins/experimental/slice/client.cc b/plugins/experimental/slice/client.cc index 6d8d44c92ed..d5cbd52f132 100644 --- a/plugins/experimental/slice/client.cc +++ b/plugins/experimental/slice/client.cc @@ -85,15 +85,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 +123,23 @@ 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); -#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 +152,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_sent - output_done)); } - } - 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/response.cc b/plugins/experimental/slice/response.cc index 410b1507dfe..53cf59e047d 100644 --- a/plugins/experimental/slice/response.cc +++ b/plugins/experimental/slice/response.cc @@ -48,8 +48,8 @@ bodyString416() } // Form a 502 response, preliminary -std::string const & -string502() +std::string +string502(int const httpver) { static std::string msg; static std::mutex mutex; @@ -68,10 +68,13 @@ string502() bodystr.append("\n"); bodystr.append("\n"); + char hverstr[64]; + int const hlen = + snprintf(hverstr, sizeof(hverstr), "HTTP/%d.%d 502 Bad Gateway\r\n", TS_HTTP_MAJOR(httpver), TS_HTTP_MINOR(httpver)); + msg.append(hverstr, hlen); + char clenstr[1024]; int const clen = snprintf(clenstr, sizeof(clenstr), "%lu", bodystr.size()); - - msg.append("HTTP/1.1 502 Bad Gateway\r\n"); msg.append("Content-Length: "); msg.append(clenstr, clen); msg.append("\r\n"); @@ -87,6 +90,7 @@ void form416HeaderAndBody(HttpHeader &header, int64_t const contentlen, std::string const &bodystr) { header.removeKey(TS_MIME_FIELD_LAST_MODIFIED, TS_MIME_LEN_LAST_MODIFIED); + header.removeKey(TS_MIME_FIELD_EXPIRES, TS_MIME_LEN_EXPIRES); header.removeKey(TS_MIME_FIELD_ETAG, TS_MIME_LEN_ETAG); header.removeKey(TS_MIME_FIELD_ACCEPT_RANGES, TS_MIME_LEN_ACCEPT_RANGES); diff --git a/plugins/experimental/slice/response.h b/plugins/experimental/slice/response.h index 925db65f725..c116d22e21c 100644 --- a/plugins/experimental/slice/response.h +++ b/plugins/experimental/slice/response.h @@ -21,7 +21,7 @@ #include "HttpHeader.h" #include -std::string const &string502(); +std::string string502(int const httpver); std::string const &bodyString416(); diff --git a/plugins/experimental/slice/server.cc b/plugins/experimental/slice/server.cc index 25d21472109..c7311da74c8 100644 --- a/plugins/experimental/slice/server.cc +++ b/plugins/experimental/slice/server.cc @@ -46,19 +46,56 @@ 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(static_cast(0), static_cast(strtoll(constr, &endptr, 10))); + } + + return bytes; +} + +// Also reference server header +enum HeaderState { + Good, + Fail, + Passthru, +}; + +HeaderState handleFirstServerHeader(Data *const data, TSCont const contp) { 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 +108,27 @@ 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 bytes: 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; + return HeaderState::Passthru; } ContentRange const blockcr = contentRangeFrom(header); - // 206 with bad content range? + + // 206 with bad content range -- should NEVER happen. if (!blockcr.isValid()) { - static std::string const &msg502 = string502(); + std::string const msg502 = string502(header.version()); TSVIONBytesSet(output_vio, msg502.size()); TSIOBufferWrite(output_buf, msg502.data(), msg502.size()); TSVIOReenable(output_vio); - return false; + return HeaderState::Fail; } // set the resource content length from block response @@ -117,16 +159,18 @@ handleFirstServerHeader(Data *const data, TSCont const contp) TSHttpHdrPrint(header.m_buffer, header.m_lochdr, output_buf); TSIOBufferWrite(output_buf, bodystr.data(), bodystr.size()); TSVIOReenable(output_vio); - data->m_upstream.m_read.close(); - - return false; + return 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 +193,7 @@ handleFirstServerHeader(Data *const data, TSCont const contp) data->m_dnstream.close(); ERROR_LOG("Bad/invalid response content range"); - return false; + return HeaderState::Fail; } header.setKeyVal(TS_MIME_FIELD_CONTENT_RANGE, TS_MIME_LEN_CONTENT_RANGE, rangestr, rangelen); @@ -173,7 +217,7 @@ handleFirstServerHeader(Data *const data, TSCont const contp) data->m_bytessent = hbytes; TSVIOReenable(output_vio); - return true; + return HeaderState::Good; } void @@ -241,9 +285,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,12 +322,12 @@ 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=\"%jd\"" " 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, static_cast(lmgot), cclen, ccstr, vialen, viastr); } bool @@ -292,48 +335,134 @@ handleNextServerHeader(Data *const data, TSCont const contp) { // 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: %jd", static_cast(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: %jd", static_cast(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 +476,13 @@ 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); -#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; @@ -365,17 +493,34 @@ handle_server_resp(TSCont contp, TSEvent event, Data *const data) TSVIONDoneSet(input_vio, TSVIONDoneGet(input_vio) + consumed); // the server response header didn't fit into the input buffer. + // wait for more data from upstream if (TS_PARSE_CONT == res) { return; } - // very first server response header bool headerStat = false; 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); } @@ -386,7 +531,7 @@ handle_server_resp(TSCont contp, TSEvent event, Data *const data) // 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 +540,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 +583,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 +659,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 0109f20b93b..dcb63b8595c 100644 --- a/plugins/experimental/slice/slice.cc +++ b/plugins/experimental/slice/slice.cc @@ -27,20 +27,8 @@ #include "ts/ts.h" #include -#include #include -#if defined(COLLECT_STATS) -namespace stats -{ -int DataCreate = -1; -int DataDestroy = -1; -int Reader = -1; -int Server = -1; -int Client = -1; -} // namespace stats -#endif // COLLECT_STATS - namespace { Config globalConfig; @@ -58,11 +46,27 @@ read_request(TSHttpTxn txnp, Config *const config) if (!header.hasKey(SLICER_MIME_FIELD_INFO, SLICER_MIME_LEN_INFO)) { // check if any previous plugin has monkeyed with the transaction status TSHttpStatus const txnstat = TSHttpTxnStatusGet(txnp); - if (0 != (int)txnstat) { - DEBUG_LOG("slice: txn status change detected (%d), skipping plugin\n", (int)txnstat); + if (0 != static_cast(txnstat)) { + DEBUG_LOG("txn status change detected (%d), skipping plugin\n", (int)txnstat); return false; } + if (config->hasRegex()) { + int urllen = 0; + char *const urlstr = TSHttpTxnEffectiveUrlStringGet(txnp, &urllen); + if (nullptr != urlstr) { + bool const shouldslice = config->matchesRegex(urlstr, urllen); + if (!shouldslice) { + DEBUG_LOG("request failed regex, not slicing: '%.*s'", urllen, urlstr); + TSfree(urlstr); + return false; + } + + DEBUG_LOG("request passed regex, slicing: '%.*s'", urllen, urlstr); + TSfree(urlstr); + } + } + // turn off any and all transaction caching (shouldn't matter) TSHttpTxnServerRespNoStoreSet(txnp, 1); TSHttpTxnRespCacheableSet(txnp, 0); @@ -78,6 +82,8 @@ read_request(TSHttpTxn txnp, Config *const config) TSAssert(nullptr != config); Data *const data = new Data(config); + data->m_txnp = txnp; + // set up feedback connect if (AF_INET == ip->sa_family) { memcpy(&data->m_client_ip, ip, sizeof(sockaddr_in)); @@ -99,8 +105,8 @@ read_request(TSHttpTxn txnp, Config *const config) // is the plugin configured to use a remap host? std::string const &newhost = config->m_remaphost; if (newhost.empty()) { - TSMBuffer urlbuf; - TSMLoc urlloc; + TSMBuffer urlbuf = nullptr; + TSMLoc urlloc = nullptr; TSReturnCode rcode = TSHttpTxnPristineUrlGet(txnp, &urlbuf, &urlloc); if (TS_SUCCESS == rcode) { @@ -164,10 +170,15 @@ 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(); TSCont const icontp(TSContCreate(intercept_hook, mutex)); TSContDataSet(icontp, (void *)data); + + // Skip remap and remap rule requirement + TSSkipRemappingSet(txnp, 1); + + // Grab the transaction TSHttpTxnIntercept(icontp, txnp); + return true; } else { DEBUG_LOG("slice passing GET request through to next plugin"); @@ -241,43 +252,6 @@ TSReturnCode TSRemapInit(TSRemapInterface *api_info, char *errbug, int errbuf_size) { DEBUG_LOG("slice remap initializing."); - -#if defined(COLLECT_STATS) - static bool init = false; - static std::mutex mutex; - - std::lock_guard lock(mutex); - - if (!init) { - init = true; - - std::string const namedatacreate = std::string(PLUGIN_NAME) + ".DataCreate"; - stats::DataCreate = TSStatCreate(namedatacreate.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); - - assert(0 <= stats::DataCreate); - - std::string const namedatadestroy = std::string(PLUGIN_NAME) + ".DataDestroy"; - stats::DataDestroy = TSStatCreate(namedatadestroy.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); - - assert(0 <= stats::DataDestroy); - - std::string const namereader = std::string(PLUGIN_NAME) + ".Reader"; - stats::Reader = TSStatCreate(namereader.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); - - assert(0 <= stats::Reader); - - std::string const nameserver = std::string(PLUGIN_NAME) + ".Server"; - stats::Server = TSStatCreate(nameserver.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); - - assert(0 <= stats::Server); - - std::string const nameclient = std::string(PLUGIN_NAME) + ".Client"; - stats::Client = TSStatCreate(nameclient.c_str(), TS_RECORDDATATYPE_INT, TS_STAT_NON_PERSISTENT, TS_STAT_SYNC_SUM); - - assert(0 <= stats::Client); - } -#endif // COLLECT_STATS - return TS_SUCCESS; } diff --git a/plugins/experimental/slice/slice.h b/plugins/experimental/slice/slice.h index d4e040b32f2..bd58818d033 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,20 +32,15 @@ #define PLUGIN_NAME "slice" #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__, \ - ##__VA_ARGS__) /* \ - ; fprintf(stderr, "[%s:%04d]: " fmt "\n" \ - , __FILENAME__ \ - , __LINE__ \ - , ##__VA_ARGS__) \ - */ +#define DEBUG_LOG(fmt, ...) TSDebug(PLUGIN_NAME, "[%s:% 4d] %s(): " fmt, __FILENAME__, __LINE__, __func__, ##__VA_ARGS__) #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 @@ -52,14 +49,3 @@ #define ERROR_LOG(fmt, ...) #endif - -#if defined(COLLECT_STATS) -namespace stats -{ -extern int DataCreate; -extern int DataDestroy; -extern int Reader; -extern int Server; -extern int Client; -} // namespace stats -#endif // COLLECT_STATS diff --git a/plugins/experimental/slice/util.cc b/plugins/experimental/slice/util.cc index f3ae7d2bcf1..04516d4c12a 100644 --- a/plugins/experimental/slice/util.cc +++ b/plugins/experimental/slice/util.cc @@ -25,6 +25,8 @@ void shutdown(TSCont const contp, Data *const data) { DEBUG_LOG("shutting down transaction"); + data->m_upstream.close(); + data->m_dnstream.close(); TSContDataSet(contp, nullptr); delete data; TSContDestroy(contp); @@ -34,9 +36,9 @@ void abort(TSCont const contp, Data *const data) { DEBUG_LOG("aborting transaction"); - TSContDataSet(contp, nullptr); data->m_upstream.abort(); data->m_dnstream.abort(); + TSContDataSet(contp, nullptr); delete data; TSContDestroy(contp); } @@ -51,9 +53,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); @@ -78,7 +86,7 @@ request_block(TSCont contp, Data *const data) } // create virtual connection back into ATS - TSVConn const upvc = TSHttpConnectWithPluginId((sockaddr *)&data->m_client_ip, PLUGIN_NAME, 0); + TSVConn const upvc = TSHttpConnectWithPluginId(reinterpret_cast(&data->m_client_ip), PLUGIN_NAME, 0); int const hlen = TSHttpHdrLengthGet(header.m_buffer, header.m_lochdr); @@ -90,10 +98,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 +112,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 005735d3101..b574f1d31e7 100644 --- a/src/traffic_server/InkAPI.cc +++ b/src/traffic_server/InkAPI.cc @@ -3236,6 +3236,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) { @@ -3335,6 +3345,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/cache_range_requests/cache_range_requests.test.py b/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests.test.py index b25290583d2..d6887636216 100644 --- a/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests.test.py +++ b/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests.test.py @@ -16,13 +16,11 @@ # See the License for the specific language governing permissions and # limitations under the License. -import os - Test.Summary = ''' Basic cache_range_requests plugin test ''' -## Test description: +# Test description: # Preload the cache with the entire asset to be range requested. # Reload remap rule with cache_range_requests plugin # Request content through the cache_range_requests plugin @@ -42,45 +40,45 @@ # default root req_chk = {"headers": - "GET / HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "uuid: none\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET / HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: none\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_chk = {"headers": - "HTTP/1.1 200 OK\r\n" + - "Connection: close\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "HTTP/1.1 200 OK\r\n" + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } server.addResponse("sessionlog.json", req_chk, res_chk) body = "lets go surfin now" req_full = {"headers": - "GET /path HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Accept: */*\r\n" + - "uuid: full\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET /path HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "Accept: */*\r\n" + + "uuid: full\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_full = {"headers": - "HTTP/1.1 200 OK\r\n" + - "Cache-Control: max-age=500\r\n" + - "Connection: close\r\n" + - 'Etag: "path"\r\n' + - "\r\n", - "timestamp": "1469733493.993", - "body": body -} + "HTTP/1.1 200 OK\r\n" + + "Cache-Control: max-age=500\r\n" + + "Connection: close\r\n" + + 'Etag: "path"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": body + } server.addResponse("sessionlog.json", req_full, res_full) @@ -90,116 +88,135 @@ inner_str = "7-15" req_inner = {"headers": - "GET /path HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Accept: */*\r\n" + - "Range: bytes={}\r\n".format(inner_str) + - "uuid: inner\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET /path HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "Accept: */*\r\n" + + "Range: bytes={}\r\n".format(inner_str) + + "uuid: inner\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_inner = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Accept-Ranges: bytes\r\n" + - "Cache-Control: max-age=500\r\n" + - "Content-Range: bytes {0}/{1}\r\n".format(inner_str, bodylen) + - "Connection: close\r\n" + - 'Etag: "path"\r\n' + - "\r\n", - "timestamp": "1469733493.993", - "body": body[7:15] -} + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=500\r\n" + + "Content-Range: bytes {0}/{1}\r\n".format(inner_str, bodylen) + + "Connection: close\r\n" + + 'Etag: "path"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": body[7:15] + } server.addResponse("sessionlog.json", req_inner, res_inner) frange_str = "0-" req_frange = {"headers": - "GET /path HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Accept: */*\r\n" + - "Range: bytes={}\r\n".format(frange_str) + - "uuid: frange\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET /path HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "Accept: */*\r\n" + + "Range: bytes={}\r\n".format(frange_str) + + "uuid: frange\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_frange = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Accept-Ranges: bytes\r\n" + - "Cache-Control: max-age=500\r\n" + - "Content-Range: bytes 0-{0}/{0}\r\n".format(bodylen) + - "Connection: close\r\n" + - 'Etag: "path"\r\n' + - "\r\n", - "timestamp": "1469733493.993", - "body": body -} + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=500\r\n" + + "Content-Range: bytes 0-{0}/{0}\r\n".format(bodylen) + + "Connection: close\r\n" + + 'Etag: "path"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": body + } server.addResponse("sessionlog.json", req_frange, res_frange) last_str = "-5" req_last = {"headers": - "GET /path HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Accept: */*\r\n" + - "Range: bytes={}\r\n".format(last_str) + - "uuid: last\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET /path HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "Accept: */*\r\n" + + "Range: bytes={}\r\n".format(last_str) + + "uuid: last\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_last = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Accept-Ranges: bytes\r\n" + - "Cache-Control: max-age=200\r\n" + - "Content-Range: bytes {0}-{1}/{1}\r\n".format(bodylen - 5, bodylen) + - "Connection: close\r\n" + - 'Etag: "path"\r\n' + - "\r\n", - "timestamp": "1469733493.993", - "body": body[-5:] -} + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=200\r\n" + + "Content-Range: bytes {0}-{1}/{1}\r\n".format(bodylen - 5, bodylen) + + "Connection: close\r\n" + + 'Etag: "path"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": body[-5:] + } server.addResponse("sessionlog.json", req_last, res_last) pselect_str = "1-10" req_pselect = {"headers": - "GET /path HTTP/1.1\r\n" + - "Host: parentselect\r\n" + - "Accept: */*\r\n" + - "Range: bytes={}\r\n".format(pselect_str) + - "uuid: pselect\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET /path HTTP/1.1\r\n" + + "Host: parentselect\r\n" + + "Accept: */*\r\n" + + "Range: bytes={}\r\n".format(pselect_str) + + "uuid: pselect\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_pselect = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Accept-Ranges: bytes\r\n" + - "Cache-Control: max-age=200\r\n" + - "Content-Range: bytes {}/19\r\n".format(pselect_str) + - "Connection: close\r\n" + - 'Etag: "path"\r\n' + - "\r\n", - "timestamp": "1469733493.993", - "body": body[1:10] -} + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=200\r\n" + + "Content-Range: bytes {}/19\r\n".format(pselect_str) + + "Connection: close\r\n" + + 'Etag: "path"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": body[1:10] + } server.addResponse("sessionlog.json", req_pselect, res_pselect) +req_psd = {"headers": + "GET /path HTTP/1.1\r\n" + + "Host: psd\r\n" + + "Accept: */*\r\n" + + "Range: bytes={}\r\n".format(pselect_str) + + "uuid: pselect\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } + +server.addResponse("sessionlog.json", req_psd, res_pselect) + # cache range requests plugin remap ts.Disk.remap_config.AddLines([ - 'map http://www.example.com http://127.0.0.1:{}'.format(server.Variables.Port) + + 'map http://www.example.com http://127.0.0.1:{}'.format(server.Variables.Port) + ' @plugin=cache_range_requests.so', - 'map http://parentselect http://127.0.0.1:{}'.format(server.Variables.Port) + + + # parent select cache key option + 'map http://parentselect http://127.0.0.1:{}'.format(server.Variables.Port) + + ' @plugin=cache_range_requests.so @pparam=--ps-cachekey', + + # deprecated + 'map http://psd http://127.0.0.1:{}'.format(server.Variables.Port) + ' @plugin=cache_range_requests.so @pparam=ps_mode:cache_key_url', ]) @@ -208,10 +225,8 @@ # minimal configuration ts.Disk.records_config.update({ - 'proxy.config.diags.debug.enabled': 1, - 'proxy.config.diags.debug.tags': 'cache_range_requests', - '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', }) curl_and_args = 'curl -s -D /dev/stdout -o /dev/stderr -x localhost:{} -H "x-debug: x-cache"'.format(ts.Variables.port) @@ -220,7 +235,7 @@ tr = Test.AddTestRun("full asset cache miss bypass") 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.StartBefore(Test.Processes.ts) ps.Command = curl_and_args + ' http://www.example.com/path -H "uuid: full"' ps.ReturnCode = 0 ps.Streams.stderr = "gold/full.stderr.gold" @@ -310,39 +325,5 @@ tr.StillRunningAfter = ts -curl_and_args = 'curl -s -D /dev/stdout -o /dev/stderr -x localhost:{} -H "x-debug: x-parentselection-key"'.format(ts.Variables.port) - -''' -# 9 Test - cache_key_url request -tr = Test.AddTestRun("cache_key_url request") -ps = tr.Processes.Default -ps.Command = curl_and_args + ' http://parentselect/path -r {} -H "uuid: pselect"'.format(pselect_str) -ps.ReturnCode = 0 -ps.Streams.stdout.Content = Testers.ContainsExpression( - "X-ParentSelection-Key: .*-bytes=", - "expected bytes in parent selection key", -) -tr.StillRunningAfter = ts -tr.StillRunningAfter = server - -# 10 Test - non cache_key_url request ... no X-ParentSelection-Key -tr = Test.AddTestRun("non cache_key_url request") -ps = tr.Processes.Default -ps.Command = curl_and_args + ' http://www.example.com/path -r {} -H "uuid: inner"'.format(inner_str) -ps.ReturnCode = 0 -ps.Streams.stdout.Content = Testers.ExcludesExpression("X-ParentSelection-Key", "parent select key shouldn't show up") -tr.StillRunningAfter = ts -tr.StillRunningAfter = server - -# 11 Test - cache_key_url request -- deprecated -tr = Test.AddTestRun("cache_key_url request - dprecated") -ps = tr.Processes.Default -ps.Command = curl_and_args + ' http://psd/path -r {} -H "uuid: pselect"'.format(pselect_str) -ps.ReturnCode = 0 -ps.Streams.stdout.Content = Testers.ContainsExpression( - "X-ParentSelection-Key: .*-bytes=", - "expected bytes in parent selection key", -) -tr.StillRunningAfter = ts -tr.StillRunningAfter = server -''' +curl_and_args = 'curl -s -D /dev/stdout -o /dev/stderr -x localhost:{} -H "x-debug: x-parentselection-key"'.format( + ts.Variables.port) diff --git a/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests_cachekey.test.py b/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests_cachekey.test.py index 2622694a04e..fc0ca7087ec 100644 --- a/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests_cachekey.test.py +++ b/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests_cachekey.test.py @@ -16,14 +16,11 @@ # See the License for the specific language governing permissions and # limitations under the License. -import os -import time - Test.Summary = ''' cache_range_requests with cachekey ''' -## Test description: +# Test description: # Preload the cache with the entire asset to be range requested. # Reload remap rule with cache_range_requests plugin # Request content through the cache_range_requests plugin @@ -44,21 +41,21 @@ # default root req_chk = {"headers": - "GET / HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "uuid: none\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET / HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "uuid: none\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_chk = {"headers": - "HTTP/1.1 200 OK\r\n" + - "Connection: close\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "HTTP/1.1 200 OK\r\n" + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } server.addResponse("sessionlog.json", req_chk, res_chk) @@ -67,90 +64,90 @@ # this request should work req_full = {"headers": - "GET /path HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Accept: */*\r\n" + - "uuid: full\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET /path HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "Accept: */*\r\n" + + "uuid: full\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_full = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Accept-Ranges: bytes\r\n" + - 'Etag: "foo"\r\n' + - "Cache-Control: public, max-age=500\r\n" + - "Connection: close\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": body -} + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + 'Etag: "foo"\r\n' + + "Cache-Control: public, max-age=500\r\n" + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body + } server.addResponse("sessionlog.json", req_full, res_full) # this request should work req_good = {"headers": - "GET /path HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Accept: */*\r\n" + - "Range: bytes=0-\r\n" + - "uuid: range_full\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET /path HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "Accept: */*\r\n" + + "Range: bytes=0-\r\n" + + "uuid: range_full\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_good = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Accept-Ranges: bytes\r\n" + - 'Etag: "foo"\r\n' + - "Cache-Control: public, max-age=500\r\n" + - "Content-Range: bytes 0-{0}/{0}\r\n".format(bodylen) + - "Connection: close\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": body -} + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + 'Etag: "foo"\r\n' + + "Cache-Control: public, max-age=500\r\n" + + "Content-Range: bytes 0-{0}/{0}\r\n".format(bodylen) + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body + } server.addResponse("sessionlog.json", req_good, res_good) # this request should fail with a cache_range_requests asset req_fail = {"headers": - "GET /path HTTP/1.1\r\n" + - "Host: www.fail.com\r\n" + - "Accept: */*\r\n" + - "Range: bytes=0-\r\n" + - "uuid: range_fail\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "" -} + "GET /path HTTP/1.1\r\n" + + "Host: www.fail.com\r\n" + + "Accept: */*\r\n" + + "Range: bytes=0-\r\n" + + "uuid: range_fail\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } res_fail = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Accept-Ranges: bytes\r\n" + - 'Etag: "foo"\r\n' + - "Cache-Control: public, max-age=500\r\n" + - "Content-Range: bytes 0-{0}/{0}\r\n".format(bodylen) + - "Connection: close\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": body -} + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + 'Etag: "foo"\r\n' + + "Cache-Control: public, max-age=500\r\n" + + "Content-Range: bytes 0-{0}/{0}\r\n".format(bodylen) + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body + } server.addResponse("sessionlog.json", req_fail, res_fail) # cache range requests plugin remap, working config ts.Disk.remap_config.AddLine( - 'map http://www.example.com http://127.0.0.1:{}'.format(server.Variables.Port) + + 'map http://www.example.com http://127.0.0.1:{}'.format(server.Variables.Port) + ' @plugin=cachekey.so @pparam=--include-headers=Range' + ' @plugin=cache_range_requests.so @pparam=--no-modify-cachekey', ) # improperly configured cache_range_requests with cachekey ts.Disk.remap_config.AddLine( - 'map http://www.fail.com http://127.0.0.1:{}'.format(server.Variables.Port) + + 'map http://www.fail.com http://127.0.0.1:{}'.format(server.Variables.Port) + ' @plugin=cachekey.so @pparam=--static-prefix=foo' ' @plugin=cache_range_requests.so', ) @@ -160,10 +157,8 @@ # minimal configuration ts.Disk.records_config.update({ - 'proxy.config.diags.debug.enabled': 1, - 'proxy.config.diags.debug.tags': 'cache_range_requests', - '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', }) curl_and_args = 'curl -s -D /dev/stdout -o /dev/stderr -x localhost:{} -H "x-debug: x-cache"'.format(ts.Variables.port) @@ -172,7 +167,7 @@ tr = Test.AddTestRun("full asset fetch") 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.StartBefore(Test.Processes.ts) ps.Command = curl_and_args + ' http://www.example.com/path -H "uuid: full"' ps.ReturnCode = 0 ps.Streams.stdout.Content = Testers.ContainsExpression("X-Cache: miss", "expected cache miss for load") @@ -195,4 +190,5 @@ ts.Disk.diags_log.Content = Testers.ContainsExpression("ERROR", "error condition hit") ts.Disk.diags_log.Content = Testers.ContainsExpression("failed to change the cache url", "ensure failure for misconfiguration") -ts.Disk.diags_log.Content = Testers.ContainsExpression("Disabling cache for this transaction to avoid cache poisoning", "ensure transaction caching disabled") +ts.Disk.diags_log.Content = Testers.ContainsExpression( + "Disabling cache for this transaction to avoid cache poisoning", "ensure transaction caching disabled") diff --git a/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests_ims.test.py b/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests_ims.test.py new file mode 100644 index 00000000000..29d8c5da20a --- /dev/null +++ b/tests/gold_tests/pluginTest/cache_range_requests/cache_range_requests_ims.test.py @@ -0,0 +1,139 @@ +''' +''' +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import time + +Test.Summary = ''' +cache_range_requests X-Crr-Ims plugin test +''' + +# Test description: +# Preload the cache with the entire asset to be range requested. +# Reload remap rule with cache_range_requests plugin +# Request content through the cache_range_requests plugin + +Test.SkipUnless( + Condition.PluginExists('cache_range_requests.so'), + Condition.PluginExists('xdebug.so'), +) +Test.ContinueOnFail = False +Test.testName = "cache_range_requests_ims" + +# Define and configure ATS +ts = Test.MakeATSProcess("ts", command="traffic_server") + +# Define and configure origin server +server = Test.MakeOriginServer("server") + +# default root +req_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_chk = {"headers": + "HTTP/1.1 200 OK\r\n" + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } + +server.addResponse("sessionlog.json", req_chk, res_chk) + +body = "lets go surfin now" +bodylen = len(body) + +req_full = {"headers": + "GET /path HTTP/1.1\r\n" + + "Host: www.example.com\r\n" + + "Accept: */*\r\n" + + "Range: bytes=0-\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "" + } + +res_full = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Accept-Ranges: bytes\r\n" + + "Cache-Control: max-age=500\r\n" + + "Content-Range: bytes 0-{0}/{0}\r\n".format(bodylen) + + "Connection: close\r\n" + + 'Etag: "772102f4-56f4bc1e6d417"\r\n' + + "\r\n", + "timestamp": "1469733493.993", + "body": body + } + +server.addResponse("sessionlog.json", req_full, res_full) + +# cache range requests plugin remap +ts.Disk.remap_config.AddLine( + 'map http://www.example.com http://127.0.0.1:{}'.format(server.Variables.Port) + + ' @plugin=cache_range_requests.so @pparam=--consider-ims', +) + +# cache debug +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', +}) + +curl_and_args = 'curl -s -D /dev/stdout -o /dev/stderr -x localhost:{} -H "x-debug: x-cache"'.format(ts.Variables.port) + +# 0 Test - Fetch whole asset into cache +tr = Test.AddTestRun("0- range cache load") +ps = tr.Processes.Default +ps.StartBefore(server, ready=When.PortOpen(server.Variables.Port)) +ps.StartBefore(Test.Processes.ts) +ps.Command = curl_and_args + ' http://www.example.com/path -r 0-' +ps.ReturnCode = 0 +ps.Streams.stdout.Content = Testers.ContainsExpression("X-Cache: miss", "expected cache miss for load") +tr.StillRunningAfter = ts + + +# set up the IMS date field (go in the future) RFC 2616 +futuretime = time.time() + 100 # seconds +futurestr = time.strftime("%a, %d %b %Y %H:%M:%S GMT", time.gmtime(futuretime)) + +# test inner range +# 1 Test - Fetch range into cache +tr = Test.AddTestRun("0- cache hit check") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://www.example.com/path -r 0-'.format(futurestr) +ps.ReturnCode = 0 +ps.Streams.stdout.Content = Testers.ContainsExpression("X-Cache: hit", "expected cache hit") +tr.StillRunningAfter = ts + +# 2 Test - Ensure X-Crr-Ims header results in hit-stale +tr = Test.AddTestRun("0- range X-Crr-Ims check") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://www.example.com/path -r 0- -H "X-Crr-Ims: {}"'.format(futurestr) +ps.ReturnCode = 0 +ps.Streams.stdout.Content = Testers.ContainsExpression("X-Cache: hit-stale", "expected cache hit-stale") +tr.StillRunningAfter = ts 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..d4c7913507b 100644 --- a/tests/gold_tests/pluginTest/slice/slice.test.py +++ b/tests/gold_tests/pluginTest/slice/slice.test.py @@ -20,7 +20,7 @@ Basic slice plugin test ''' -## Test description: +# 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 @@ -34,150 +34,151 @@ 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" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET / HTTP/1.1\r\n" + + "Host: ats\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", + } response_header_chk = {"headers": - "HTTP/1.1 200 OK\r\n" + - "Connection: close\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "HTTP/1.1 200 OK\r\n" + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", + } 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" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET /path HTTP/1.1\r\n" + + "Host: origin\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", + } response_header = {"headers": - "HTTP/1.1 200 OK\r\n" + - "Connection: close\r\n" + - 'Etag: "path"\r\n' + - "Cache-Control: max-age=500\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": body, -} + "HTTP/1.1 200 OK\r\n" + + "Connection: close\r\n" + + 'Etag: "path"\r\n' + + "Cache-Control: max-age=500\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body, + } 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.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, + 'proxy.config.http.wait_for_cache': 1, + 'proxy.config.http.cache.http': 1, + 'proxy.config.diags.debug.enabled': 0, + 'proxy.config.diags.debug.tags': 'slice', }) # 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) +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 + +# 8 Test - special case, begin inside last slice block but outside asset len +tr = Test.AddTestRun("Invalid end range request, 416") +beg = len(body) + 1 +end = beg + block_bytes +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://slice/path' + ' -r {}-{}'.format(beg, end) +ps.Streams.stdout.Content = Testers.ContainsExpression("416 Requested Range Not Satisfiable", "expected 416 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..e6ec304ff92 100644 --- a/tests/gold_tests/pluginTest/slice/slice_error.test.py +++ b/tests/gold_tests/pluginTest/slice/slice_error.test.py @@ -20,7 +20,7 @@ Slice plugin error.log test ''' -## Test description: +# 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 @@ -34,27 +34,27 @@ 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 +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" + - "Range: bytes=0-\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET / HTTP/1.1\r\n" + + "Host: ats\r\n" + + "Range: bytes=0-\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", + } response_header_chk = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Connection: close\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": body, -} + "HTTP/1.1 206 Partial Content\r\n" + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body, + } server.addResponse("sessionlog.json", request_header_chk, response_header_chk) @@ -69,254 +69,303 @@ # Mismatch etag request_header_etag0 = {"headers": - "GET /etag HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Range: bytes={}\r\n".format(range0) + - "X-Slicer-Info: full content request\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET /etag 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_etag0 = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Connection: close\r\n" + - 'Etag: "etag0"\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, -} + "HTTP/1.1 206 Partial Content\r\n" + + "Connection: close\r\n" + + 'Etag: "etag0"\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_etag0, response_header_etag0) request_header_etag1 = {"headers": - "GET /etag HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Range: bytes={}\r\n".format(range1) + - "X-Slicer-Info: full content request\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET /etag 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_etag1 = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Connection: close\r\n" + - 'Etag: "etag1"\r\n' + - "Content-Range: bytes {}/{}\r\n".format(range1, len(body)) + - "Cache-Control: max-age=500\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": body1, -} + "HTTP/1.1 206 Partial Content\r\n" + + "Connection: close\r\n" + + 'Etag: "etag1"\r\n' + + "Content-Range: bytes {}/{}\r\n".format(range1, len(body)) + + "Cache-Control: max-age=500\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body1, + } server.addResponse("sessionlog.json", request_header_etag1, response_header_etag1) # mismatch Last-Modified request_header_lm0 = {"headers": - "GET /lastmodified HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Range: bytes={}\r\n".format(range0) + - "X-Slicer-Info: full content request\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET /lastmodified 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_lm0 = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Connection: close\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, -} + "HTTP/1.1 206 Partial Content\r\n" + + "Connection: close\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_lm0, response_header_lm0) request_header_lm1 = {"headers": - "GET /lastmodified HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Range: bytes={}\r\n".format(range1) + - "X-Slicer-Info: full content request\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET /lastmodified 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_lm1 = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Connection: close\r\n" + - "Last-Modified: Tue, 08 Apr 2019 18:00:00 GMT\r\n" + - "Content-Range: bytes {}/{}\r\n".format(range1, len(body)) + - "Cache-Control: max-age=500\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": body1, -} + "HTTP/1.1 206 Partial Content\r\n" + + "Connection: close\r\n" + + "Last-Modified: Tue, 08 Apr 2019 18:00:00 GMT\r\n" + + "Content-Range: bytes {}/{}\r\n".format(range1, len(body)) + + "Cache-Control: max-age=500\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body1, + } server.addResponse("sessionlog.json", request_header_lm1, response_header_lm1) # non 206 slice block request_header_n206_0 = {"headers": - "GET /non206 HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Range: bytes={}\r\n".format(range0) + - "X-Slicer-Info: full content request\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET /non206 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_n206_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, -} + "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_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" + - "Range: bytes={}\r\n".format(range0) + - "X-Slicer-Info: full content request\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET /crr 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_crr0 = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Connection: close\r\n" + - "Etag: crr\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, -} + "HTTP/1.1 206 Partial Content\r\n" + + "Connection: close\r\n" + + "Etag: crr\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_crr0, response_header_crr0) request_header_crr1 = {"headers": - "GET /crr HTTP/1.1\r\n" + - "Host: www.example.com\r\n" + - "Range: bytes={}\r\n".format(range1) + - "X-Slicer-Info: full content request\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": "", -} + "GET /crr 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_crr1 = {"headers": - "HTTP/1.1 206 Partial Content\r\n" + - "Connection: close\r\n" + - "Etag: crr\r\n" + - "Content-Range: bytes {}/{}\r\n".format(range1, len(body) - 1) + - "Cache-Control: max-age=500\r\n" + - "\r\n", - "timestamp": "1469733493.993", - "body": body1, -} + "HTTP/1.1 206 Partial Content\r\n" + + "Connection: close\r\n" + + "Etag: crr\r\n" + + "Content-Range: bytes {}/{}\r\n".format(range1, len(body) - 1) + + "Cache-Control: max-age=500\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body1, + } 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( - 'map / http://127.0.0.1:{}'.format(server.Variables.Port) + + 'map / http://127.0.0.1:{}'.format(server.Variables.Port) + ' @plugin=slice.so @pparam=--blockbytes-test={}'.format(blockbytes) ) # minimal configuration ts.Disk.records_config.update({ - 'proxy.config.diags.debug.enabled': 0, - '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, + # 'proxy.config.diags.debug.enabled': 1, + # 'proxy.config.diags.debug.tags': 'slice', }) # 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) +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 new file mode 100644 index 00000000000..110987ddd95 --- /dev/null +++ b/tests/gold_tests/pluginTest/slice/slice_regex.test.py @@ -0,0 +1,167 @@ +''' +''' +# 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 regex plugin 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'), +) +Test.ContinueOnFail = False + +# configure origin server +server = Test.MakeOriginServer("server") + +# Define ATS and configure. +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" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", + } + +response_header_chk = {"headers": + "HTTP/1.1 200 OK\r\n" + + "Connection: close\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", + } + +server.addResponse("sessionlog.json", request_header_chk, response_header_chk) + +#block_bytes = 7 +body = "lets go surfin now" + +request_header_txt = {"headers": + "GET /slice.txt HTTP/1.1\r\n" + + "Host: slice\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": "", + } + +response_header_txt = {"headers": + "HTTP/1.1 200 OK\r\n" + + "Connection: close\r\n" + + 'Etag: "path"\r\n' + + "Cache-Control: max-age=500\r\n" + + "X-Info: notsliced\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body, + } + +server.addResponse("sessionlog.json", request_header_txt, response_header_txt) + +request_header_mp4 = {"headers": + "GET /slice.mp4 HTTP/1.1\r\n" + + "Host: sliced\r\n" + + "Range: bytes=0-99\r\n" + "\r\n", + "timestamp": "1469733493.993", + "body": "", + } + +response_header_mp4 = {"headers": + "HTTP/1.1 206 Partial Content\r\n" + + "Connection: close\r\n" + + 'Etag: "path"\r\n' + + "Content-Range: bytes 0-{}/{}\r\n".format(len(body) - 1, len(body)) + + "Cache-Control: max-age=500\r\n" + + "X-Info: sliced\r\n" + + "\r\n", + "timestamp": "1469733493.993", + "body": body, + } + +server.addResponse("sessionlog.json", request_header_mp4, response_header_mp4) + +curl_and_args = 'curl -s -D /dev/stdout -o /dev/stderr -x localhost:{} -H "x-debug: x-cache"'.format(ts.Variables.port) + +block_bytes = 100 + +# set up whole asset fetch into cache +ts.Disk.remap_config.AddLines([ + 'map http://exclude/ http://127.0.0.1:{}/'.format(server.Variables.Port) + + ' @plugin=slice.so' + + ' @pparam=--blockbytes-test={}'.format(block_bytes) + + ' @pparam=--exclude-regex=\\.txt' + ' @pparam=--remap-host=sliced', + 'map http://include/ http://127.0.0.1:{}/'.format(server.Variables.Port) + + ' @plugin=slice.so' + + ' @pparam=--blockbytes-test={}'.format(block_bytes) + + ' @pparam=--include-regex=\\.mp4' + ' @pparam=--remap-host=sliced', + 'map http://sliced/ http://127.0.0.1:{}/'.format(server.Variables.Port), +]) + + +# minimal configuration +ts.Disk.records_config.update({ + # 'proxy.config.diags.debug.enabled': 1, + # 'proxy.config.diags.debug.tags': 'slice', + 'proxy.config.http.insert_age_in_response': 0, + 'proxy.config.http.response_via_str': 0, +}) + +# 0 Test - Exclude: ensure txt passes through +tr = Test.AddTestRun("Exclude - asset passed through") +ps = tr.Processes.Default +ps.StartBefore(server, ready=When.PortOpen(server.Variables.Port)) +ps.StartBefore(Test.Processes.ts) +ps.Command = curl_and_args + ' http://exclude/slice.txt' +ps.ReturnCode = 0 +ps.Streams.stdout.Content = Testers.ContainsExpression("X-Info: notsliced", "expected not sliced header") +tr.StillRunningAfter = ts + +# 1 Test - Exclude mp4 gets sliced +tr = Test.AddTestRun("Exclude - asset is sliced") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://exclude/slice.mp4' +ps.ReturnCode = 0 +ps.Streams.stdout.Content = Testers.ContainsExpression("X-Info: sliced", "expected sliced header") +tr.StillRunningAfter = ts +tr.StillRunningAfter = ts + +# 2 Test - Exclude: ensure txt passes through +tr = Test.AddTestRun("Include - asset passed through") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://include/slice.txt' +ps.ReturnCode = 0 +ps.Streams.stdout.Content = Testers.ContainsExpression("X-Info: notsliced", "expected not sliced header") +tr.StillRunningAfter = ts + +# 3 Test - Exclude mp4 gets sliced +tr = Test.AddTestRun("Include - asset is sliced") +ps = tr.Processes.Default +ps.Command = curl_and_args + ' http://include/slice.mp4' +ps.ReturnCode = 0 +ps.Streams.stdout.Content = Testers.ContainsExpression("X-Info: sliced", "expected sliced header") +tr.StillRunningAfter = ts +tr.StillRunningAfter = ts 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..ef16456400b --- /dev/null +++ b/tests/gold_tests/pluginTest/slice/slice_selfhealing.test.py @@ -0,0 +1,392 @@ +''' +''' +# 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') + +ts.Disk.records_config.update({ + 'proxy.config.http.wait_for_cache': 1, + 'proxy.config.http.cache.http': 1, + 'proxy.config.diags.debug.enabled': 0, + '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) +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")