This is an automated email from the ASF dual-hosted git repository.
eze pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/trafficserver.git
The following commit(s) were added to refs/heads/master by this push:
new 671e639 Add more information to diags.log error message for block
stitching errors.
671e639 is described below
commit 671e63994bffc2da6c0b2a89612707f9baf03c1d
Author: Brian Olsen <[email protected]>
AuthorDate: Wed Apr 10 17:58:35 2019 +0000
Add more information to diags.log error message for block stitching errors.
---
plugins/experimental/slice/HttpHeader.cc | 36 ++-
plugins/experimental/slice/HttpHeader.h | 12 +-
plugins/experimental/slice/Range.cc | 8 +-
plugins/experimental/slice/client.cc | 6 +-
plugins/experimental/slice/response.cc | 9 +-
plugins/experimental/slice/server.cc | 139 +++++++--
.../pluginTest/slice/gold_error/crr.stderr.gold | 1 +
.../pluginTest/slice/gold_error/crr.stdout.gold | 9 +
.../pluginTest/slice/gold_error/etag.stderr.gold | 1 +
.../pluginTest/slice/gold_error/etag.stdout.gold | 9 +
.../pluginTest/slice/gold_error/lm.stderr.gold | 1 +
.../pluginTest/slice/gold_error/lm.stdout.gold | 9 +
.../pluginTest/slice/gold_error/non206.stderr.gold | 1 +
.../pluginTest/slice/gold_error/non206.stdout.gold | 10 +
.../pluginTest/slice/slice_error.test.py | 326 +++++++++++++++++++++
15 files changed, 532 insertions(+), 45 deletions(-)
diff --git a/plugins/experimental/slice/HttpHeader.cc
b/plugins/experimental/slice/HttpHeader.cc
index 0f1a78f..bcf649b 100644
--- a/plugins/experimental/slice/HttpHeader.cc
+++ b/plugins/experimental/slice/HttpHeader.cc
@@ -53,6 +53,24 @@ HttpHeader::setStatus(TSHttpStatus const newstatus)
return TS_SUCCESS == TSHttpHdrStatusSet(m_buffer, m_lochdr, newstatus);
}
+char *
+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);
+ TSHandleMLocRelease(m_buffer, m_lochdr, locurl);
+ } else {
+ *urllen = 0;
+ }
+
+ return urlstr;
+}
+
bool
HttpHeader::setUrl(TSMBuffer const bufurl, TSMLoc const locurl)
{
@@ -102,6 +120,10 @@ HttpHeader::getCharPtr(CharPtrGetFunc func, int *const
len) const
}
}
+ if (nullptr == res && nullptr != len) {
+ *len = 0;
+ }
+
return res;
}
@@ -144,6 +166,7 @@ bool
HttpHeader::valueForKey(char const *const keystr, int const keylen, char
*const valstr, int *const vallen, int const index) const
{
if (!isValid()) {
+ *vallen = 0;
return false;
}
@@ -171,9 +194,6 @@ HttpHeader::valueForKey(char const *const keystr, int const
keylen, char *const
*vallen = 0;
}
- if (!status) {
- }
-
return status;
}
@@ -224,16 +244,12 @@ HttpHeader::toString() const
case TS_HTTP_TYPE_REQUEST: {
res.append(method());
- TSMLoc locurl = nullptr;
- TSReturnCode const rcode = TSHttpHdrUrlGet(m_buffer, m_lochdr, &locurl);
- if (TS_SUCCESS == rcode && nullptr != locurl) {
- int urllen = 0;
- char *const urlstr = TSUrlStringGet(m_buffer, locurl, &urllen);
+ int urllen = 0;
+ char *const urlstr = urlString(&urllen);
+ if (nullptr != urlstr) {
res.append(" ");
res.append(urlstr, urllen);
TSfree(urlstr);
-
- TSHandleMLocRelease(m_buffer, m_lochdr, locurl);
} else {
res.append(" UnknownURL");
}
diff --git a/plugins/experimental/slice/HttpHeader.h
b/plugins/experimental/slice/HttpHeader.h
index 3572761..bfd9c4d 100644
--- a/plugins/experimental/slice/HttpHeader.h
+++ b/plugins/experimental/slice/HttpHeader.h
@@ -71,6 +71,16 @@ struct HttpHeader {
return getCharPtr(TSHttpHdrMethodGet, len);
}
+ // request method version
+ int
+ version() const
+ {
+ return TSHttpHdrVersionGet(m_buffer, m_lochdr);
+ }
+
+ // Returns string representation of the url. Caller gets ownership!
+ char *urlString(int *const urllen) const;
+
// host
char const *
hostname(int *const len) const
@@ -95,7 +105,7 @@ struct HttpHeader {
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
- int const index = -1 // sets all values
+ int const index = -1 // retrieves all values
) const;
/**
diff --git a/plugins/experimental/slice/Range.cc
b/plugins/experimental/slice/Range.cc
index 1a7e968..c9a9d4d 100644
--- a/plugins/experimental/slice/Range.cc
+++ b/plugins/experimental/slice/Range.cc
@@ -57,10 +57,10 @@ Range::fromStringClosed(char const *const rangestr)
}
// rip out any whitespace
- static int const RLEN = 1024;
- char rangebuf[RLEN];
- char *pbuf = rangebuf;
- while ('\0' != *pstr && (pbuf - rangebuf) < RLEN) {
+ char rangebuf[1024];
+ int const rangelen = sizeof(rangebuf);
+ char *pbuf = rangebuf;
+ while ('\0' != *pstr && (pbuf - rangebuf) < rangelen) {
if (!isblank(*pstr)) {
*pbuf++ = *pstr;
}
diff --git a/plugins/experimental/slice/client.cc
b/plugins/experimental/slice/client.cc
index d52887e..75bbe8e 100644
--- a/plugins/experimental/slice/client.cc
+++ b/plugins/experimental/slice/client.cc
@@ -38,7 +38,7 @@ requestBlock(TSCont contp, Data *const data)
Range blockbe(blockbeg, blockbeg + data->m_blockbytes_config);
char rangestr[1024];
- int rangelen = 1023;
+ int rangelen = sizeof(rangestr);
bool const rpstat = blockbe.toStringClosed(rangestr, &rangelen);
TSAssert(rpstat);
@@ -114,7 +114,7 @@ handle_client_req(TSCont contp, TSEvent event, Data *const
data)
Range rangebe;
char rangestr[1024];
- int rangelen = 1024;
+ int rangelen = sizeof(rangestr);
bool const hasRange = header.valueForKey(TS_MIME_FIELD_RANGE,
TS_MIME_LEN_RANGE, rangestr, &rangelen,
0); // <-- first range only
if (hasRange) {
@@ -135,7 +135,7 @@ handle_client_req(TSCont contp, TSEvent event, Data *const
data)
}
} else {
DEBUG_LOG("Full content request");
- static char const *const valstr = "full content request";
+ static char const *const valstr = "-";
static size_t const vallen = strlen(valstr);
header.setKeyVal(SLICER_MIME_FIELD_INFO, strlen(SLICER_MIME_FIELD_INFO),
valstr, vallen);
data->m_statustype = TS_HTTP_STATUS_OK;
diff --git a/plugins/experimental/slice/response.cc
b/plugins/experimental/slice/response.cc
index 4b9f101..410b150 100644
--- a/plugins/experimental/slice/response.cc
+++ b/plugins/experimental/slice/response.cc
@@ -68,9 +68,8 @@ string502()
bodystr.append("</body>\n");
bodystr.append("</html>\n");
- static int const CLEN = 1024;
- char clenstr[CLEN];
- int const clen = snprintf(clenstr, CLEN, "%lu", bodystr.size());
+ 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: ");
@@ -96,9 +95,7 @@ form416HeaderAndBody(HttpHeader &header, int64_t const
contentlen, std::string c
header.setReason(reason, strlen(reason));
char bufstr[256];
- int buflen = snprintf
- // (bufstr, 255, "%" PRId64, bodystr.size());
- (bufstr, 255, "%lu", bodystr.size());
+ int buflen = snprintf(bufstr, sizeof(bufstr), "%lu", bodystr.size());
header.setKeyVal(TS_MIME_FIELD_CONTENT_LENGTH, TS_MIME_LEN_CONTENT_LENGTH,
bufstr, buflen);
static char const *const ctypestr = "text/html";
diff --git a/plugins/experimental/slice/server.cc
b/plugins/experimental/slice/server.cc
index f2f4dee..9371469 100644
--- a/plugins/experimental/slice/server.cc
+++ b/plugins/experimental/slice/server.cc
@@ -22,6 +22,8 @@
#include "response.h"
#include "transfer.h"
+#include "ts/experimental.h"
+
#include <cinttypes>
namespace
@@ -42,9 +44,8 @@ contentRangeFrom(HttpHeader const &header)
/* Pull content length off the response header
and manipulate it into a client response header
*/
- static int const RLEN = 1024;
- char rangestr[RLEN];
- int rangelen = RLEN - 1;
+ char rangestr[1024];
+ int rangelen = sizeof(rangestr);
// look for expected Content-Range field
bool const hasContentRange(header.valueForKey(TS_MIME_FIELD_CONTENT_RANGE,
TS_MIME_LEN_CONTENT_RANGE, rangestr, &rangelen));
@@ -63,11 +64,13 @@ 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());
+
data->m_dnstream.setupVioWrite(contp);
// only process a 206, everything else gets a pass through
if (TS_HTTP_STATUS_PARTIAL_CONTENT != header.status()) {
- DEBUG_LOG("Non 206 response from parent: %d", header.status());
+ DEBUG_LOG("Initial reponse other than 206: %d", header.status());
data->m_bail = true;
TSHttpHdrPrint(header.m_buffer, header.m_lochdr,
data->m_dnstream.m_write.m_iobuf);
@@ -138,7 +141,7 @@ handleFirstServerHeader(Data *const data, TSCont const
contp)
respcr.m_length = data->m_contentlen;
char rangestr[1024];
- int rangelen = 1023;
+ int rangelen = sizeof(rangestr);
bool const crstat = respcr.toStringClosed(rangestr, &rangelen);
// corner case, return 500 ??
@@ -163,7 +166,7 @@ handleFirstServerHeader(Data *const data, TSCont const
contp)
}
char bufstr[1024];
- int const buflen = snprintf(bufstr, 1023, "%" PRId64, bodybytes);
+ int const buflen = snprintf(bufstr, sizeof(bufstr), "%" PRId64, bodybytes);
header.setKeyVal(TS_MIME_FIELD_CONTENT_LENGTH, TS_MIME_LEN_CONTENT_LENGTH,
bufstr, buflen);
// add the response header length to the total bytes to send
@@ -180,29 +183,124 @@ handleFirstServerHeader(Data *const data, TSCont const
contp)
return true;
}
+void
+logSliceError(char const *const message, Data const *const data, HttpHeader
const &header_resp)
+{
+ HttpHeader const header_req(data->m_req_hdrmgr.m_buffer,
data->m_req_hdrmgr.m_lochdr);
+
+ TSHRTime const timenowus = TShrtime();
+ int64_t const msecs = timenowus / 1000000;
+ int64_t const secs = msecs / 1000;
+ int64_t const ms = msecs % 1000;
+
+ // Gather information on the request, must delete urlstr
+ int urllen = 0;
+ char *const urlstr = header_req.urlString(&urllen);
+
+ char urlpstr[16384];
+ size_t urlplen = sizeof(urlpstr);
+ TSStringPercentEncode(urlstr, urllen, urlpstr, urlplen, &urlplen, nullptr);
+
+ if (nullptr != urlstr) {
+ TSfree(urlstr);
+ }
+
+ // uas
+ char uasstr[8192];
+ int uaslen = sizeof(uasstr);
+ header_req.valueForKey(TS_MIME_FIELD_USER_AGENT, TS_MIME_LEN_USER_AGENT,
uasstr, &uaslen);
+
+ // raw range request
+ char rangestr[1024];
+ int rangelen = sizeof(rangestr);
+ header_req.valueForKey(SLICER_MIME_FIELD_INFO,
strlen(SLICER_MIME_FIELD_INFO), rangestr, &rangelen);
+
+ // Normalized range request
+ ContentRange const crange(data->m_req_range.m_beg, data->m_req_range.m_end,
data->m_contentlen);
+ char normstr[1024];
+ int normlen = sizeof(normstr);
+ crange.toStringClosed(normstr, &normlen);
+
+ // block range request
+ int64_t const blockbeg = data->m_blocknum * data->m_blockbytes_config;
+ int64_t const blockend = std::min(blockbeg + data->m_blockbytes_config,
data->m_contentlen);
+
+ // Block response data
+ TSHttpStatus const statusgot = header_resp.status();
+
+ // content range
+ char crstr[1024];
+ int crlen = sizeof(crstr);
+ header_resp.valueForKey(TS_MIME_FIELD_CONTENT_RANGE,
TS_MIME_LEN_CONTENT_RANGE, crstr, &crlen);
+
+ // etag
+ char etagstr[1024];
+ int etaglen = sizeof(etagstr);
+ 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);
+
+ // cc
+ char ccstr[2048];
+ int cclen = sizeof(ccstr);
+ header_resp.valueForKey(TS_MIME_FIELD_CACHE_CONTROL,
TS_MIME_LEN_CACHE_CONTROL, ccstr, &cclen);
+
+ // via tag
+ char viastr[8192];
+ int vialen = sizeof(viastr);
+ header_resp.valueForKey(TS_MIME_FIELD_VIA, TS_MIME_LEN_VIA, viastr, &vialen);
+
+ char etagexpstr[1024];
+ size_t etagexplen = sizeof(etagexpstr);
+ TSStringPercentEncode(data->m_etag, data->m_etaglen, etagexpstr, etagexplen,
&etagexplen, nullptr);
+
+ char etaggotstr[1024];
+ size_t etaggotlen = sizeof(etaggotstr);
+ TSStringPercentEncode(etagstr, etaglen, etaggotstr, etaggotlen, &etaggotlen,
nullptr);
+
+ TSError("[%s] %" PRId64 ".%" PRId64 " reason=\"%s\""
+ " uri=\"%.*s\""
+ " uas=\"%.*s\""
+ " req_range=\"%.*s\""
+ " norm_range=\"%.*s\""
+
+ " etag_exp=\"%.*s\""
+ " lm_exp=\"%.*s\""
+
+ " blk_range=\"%" PRId64 "-%" PRId64 "\""
+
+ " status_got=\"%d\""
+ " cr_got=\"%.*s\""
+ " etag_got=\"%.*s\""
+ " lm_got=\"%.*s\""
+ " cc=\"%.*s\""
+ " via=\"%.*s\"",
+ PLUGIN_NAME, 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);
+}
+
bool
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());
// only process a 206, everything else just aborts
if (TS_HTTP_STATUS_PARTIAL_CONTENT != header.status()) {
- ERROR_LOG("Non 206 internal block response from parent: %d",
header.status());
+ logSliceError("Non 206 internal block response", data, header);
data->m_bail = true;
return false;
}
// can't parse the content range header, abort -- might be too strict
ContentRange const blockcr = contentRangeFrom(header);
- if (!blockcr.isValid()) {
- ERROR_LOG("Unable to parse internal block Content-Range header");
- data->m_bail = true;
- return false;
- }
-
- // make sure the block comes from the same asset as the first block
- if (data->m_contentlen != blockcr.m_length) {
- ERROR_LOG("Mismatch in slice block Content-Range Len %" PRId64 " and %"
PRId64, data->m_contentlen, blockcr.m_length);
+ if (!blockcr.isValid() || blockcr.m_length != data->m_contentlen) {
+ logSliceError("Mismatch/Bad block Content-Range", data, header);
data->m_bail = true;
return false;
}
@@ -211,23 +309,22 @@ handleNextServerHeader(Data *const data, TSCont const
contp)
// prefer the etag but use Last-Modified if we must.
char etag[8192];
- int etaglen = sizeof(etag) - 1;
+ 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) {
- ERROR_LOG("Mismatch in slice block ETAG '%.*s' and '%.*s'",
data->m_etaglen, data->m_etag, etaglen, etag);
+ logSliceError("Mismatch block Etag", data, header);
}
} else {
char lastmodified[8192];
- int lastmodifiedlen = sizeof(lastmodified) - 1;
+ 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) {
- ERROR_LOG("Mismatch in slice block Last-Modified '%.*s' and '%.*s'",
data->m_lastmodifiedlen, data->m_lastmodified,
- lastmodifiedlen, lastmodified);
+ logSliceError("Mismatch block Last-Modified", data, header);
}
}
}
diff --git a/tests/gold_tests/pluginTest/slice/gold_error/crr.stderr.gold
b/tests/gold_tests/pluginTest/slice/gold_error/crr.stderr.gold
new file mode 100644
index 0000000..fad0575
--- /dev/null
+++ b/tests/gold_tests/pluginTest/slice/gold_error/crr.stderr.gold
@@ -0,0 +1 @@
+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
new file mode 100644
index 0000000..955a424
--- /dev/null
+++ b/tests/gold_tests/pluginTest/slice/gold_error/crr.stdout.gold
@@ -0,0 +1,9 @@
+``
+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
new file mode 100644
index 0000000..fad0575
--- /dev/null
+++ b/tests/gold_tests/pluginTest/slice/gold_error/etag.stderr.gold
@@ -0,0 +1 @@
+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
new file mode 100644
index 0000000..955a424
--- /dev/null
+++ b/tests/gold_tests/pluginTest/slice/gold_error/etag.stdout.gold
@@ -0,0 +1,9 @@
+``
+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
new file mode 100644
index 0000000..fad0575
--- /dev/null
+++ b/tests/gold_tests/pluginTest/slice/gold_error/lm.stderr.gold
@@ -0,0 +1 @@
+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
new file mode 100644
index 0000000..2d83f7e
--- /dev/null
+++ b/tests/gold_tests/pluginTest/slice/gold_error/lm.stdout.gold
@@ -0,0 +1,9 @@
+``
+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
new file mode 100644
index 0000000..fad0575
--- /dev/null
+++ b/tests/gold_tests/pluginTest/slice/gold_error/non206.stderr.gold
@@ -0,0 +1 @@
+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
new file mode 100644
index 0000000..86ee5dd
--- /dev/null
+++ b/tests/gold_tests/pluginTest/slice/gold_error/non206.stdout.gold
@@ -0,0 +1,10 @@
+``
+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_error.test.py
b/tests/gold_tests/pluginTest/slice/slice_error.test.py
new file mode 100644
index 0000000..f6fd4d5
--- /dev/null
+++ b/tests/gold_tests/pluginTest/slice/slice_error.test.py
@@ -0,0 +1,326 @@
+'''
+'''
+# Licensed to the Apache Software Foundation (ASF) under one
+# or more contributor license agreements. See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership. The ASF licenses this file
+# to you under the Apache License, Version 2.0 (the
+# "License"); you may not use this file except in compliance
+# with the License. You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+import os
+import time
+Test.Summary = '''
+Slice plugin error.log 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.HasProgram("curl", "Curl needs to be installed on system for
this test to work"),
+ Condition.PluginExists('slice.so'),
+)
+Test.ContinueOnFail = False
+
+# configure origin server
+server = Test.MakeOriginServer("server", lookup_key="{%Range}{PATH}")
+
+# Define ATS and configure
+ts = Test.MakeATSProcess("ts", command="traffic_manager")
+
+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": "",
+}
+
+response_header_chk = {"headers":
+ "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)
+
+blockbytes = 9
+
+range0 = "{}-{}".format(0, blockbytes - 1)
+range1 = "{}-{}".format(blockbytes, (2 * blockbytes) - 1)
+
+body0 = body[0:blockbytes]
+body1 = body[blockbytes:2 * blockbytes]
+
+# 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": "",
+}
+
+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,
+}
+
+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": "",
+}
+
+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,
+}
+
+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": "",
+}
+
+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,
+}
+
+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": "",
+}
+
+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,
+}
+
+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": "",
+}
+
+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,
+}
+
+server.addResponse("sessionlog.json", request_header_n206_0,
response_header_n206_0)
+
+# 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": "",
+}
+
+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,
+}
+
+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": "",
+}
+
+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,
+}
+
+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"'
+
+# set up whole asset fetch into cache
+ts.Disk.remap_config.AddLine(
+ 'map / http://127.0.0.1:{}'.format(server.Variables.Port) +
+ ' @plugin=slice.so @pparam=bytesover:{}'.format(blockbytes)
+)
+
+# minimal configuration
+ts.Disk.records_config.update({
+ 'proxy.config.diags.debug.enabled': 1,
+ 'proxy.config.diags.debug.tags': 'slice',
+ 'proxy.config.http.cache.http': 0,
+ 'proxy.config.http.wait_for_cache': 0,
+ 'proxy.config.http.insert_age_in_response': 0,
+ 'proxy.config.http.insert_request_via_str': 0,
+ 'proxy.config.http.insert_response_via_str': 3,
+ 'proxy.config.http.server_ports': '{}'.format(ts.Variables.port),
+})
+
+# 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")
+
+# 0 Test - Etag mismatch test
+tr = Test.AddTestRun("Etag test")
+tr.Processes.Default.StartBefore(server)
+tr.Processes.Default.StartBefore(Test.Processes.ts, ready=1)
+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"
+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
+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"
+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
+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"
+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
+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"
+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
+tr.StillRunningAfter = ts