Test Case: cache must treat cached entity as stale when the age exceeds max-age Cache-Control directive

0.019| starting test case test_case/rfc2616/ccRespDirMsg-max-age-obey from test_clause/rfc2616/ccRespDirMsg-max-age-obey clause, Co-Advisor version: head-mid57
0.019| step 1: attempting to cache entity with max-age Cache-Control directive

Subcase: cache something

0.019| starting sub-case test_case/rfc2616/cacheSmth
0.019| selecting coad-dev.measurement-factory.com:8080 as the server address
0.020| server listens for TCP connections at coad-dev.measurement-factory.com:8080
0.020| server accepting HTTP queries at coad-dev.measurement-factory.com:8080
0.020| client connecting to 172.16.0.7:80; 3 attempt(s)
0.020| client at 172.16.0.1:1164 connected to 172.16.0.7:80
0.020| client will send 94 bytes (94 + 0)
GET http://172.16.0.1:8080/erwdstyemydp HTTP/1.1\r\n
Host: 172.16.0.1:8080\r\n
Connection: close\r\n
\r\n

0.021| client at 172.16.0.1:1164 expects to write to 172.16.0.7:80
0.021| client at 172.16.0.1:1164 wrote 94 bytes to 172.16.0.7:80
0.021| client at 172.16.0.1:1164 stops writing to 172.16.0.7:80
0.021| client at 172.16.0.1:1164 expects to read from 172.16.0.7:80
0.038| server at 172.16.0.1:8080 accepted connection from 172.16.0.7:1110
0.039| server at 172.16.0.1:8080 expects to read from 172.16.0.7:1110
0.039| server at 172.16.0.1:8080 read 116 bytes from 172.16.0.7:1110
0.039| server got request headers (116 bytes)
GET /erwdstyemydp HTTP/1.1\r\n
Host: 172.16.0.1:8080\r\n
Max-Forwards: 10\r\n
Connection: close\r\n
Via: 1.1 172.16.0.1:8080\r\n
\r\n

0.039| expecting no message body
0.039| no message body data to parse
0.039| server expects no more request data (after 116 + 0 = 116 bytes)
0.039| server at 172.16.0.1:8080 stops reading from 172.16.0.7:1110
0.040| server will send 205 bytes
HTTP/1.1 200 OK\r\n
Cache-Control: public\r\n
Last-Modified: Sun, 07 Jul 2002 22:02:34 GMT\r\n
Cache-Control: max-age=8\r\n
Date: Mon, 07 Jul 2003 22:02:34 GMT\r\n
Connection: close\r\n
Content-Length: 15\r\n
\r\n

body-hwljpuaajn

0.040| server at 172.16.0.1:8080 expects to write to 172.16.0.7:1110
0.040| server at 172.16.0.1:8080 wrote 205 bytes to 172.16.0.7:1110
0.041| server at 172.16.0.1:8080 stops writing to 172.16.0.7:1110
0.041| server stops servicing connection with 172.16.0.7:1110
0.041| server at 172.16.0.1:8080 closing connection to 172.16.0.7:1110
0.050| client at 172.16.0.1:1164 read 277 bytes from 172.16.0.7:80
0.051| client parsed response headers (262 bytes)
HTTP/1.1 200 OK\r\n
Date: Mon, 07 Jul 2003 22:02:33 GMT\r\n
Cache-Control: public\r\n
Last-Modified: Sun, 07 Jul 2002 22:02:34 GMT\r\n
Cache-Control: max-age=8\r\n
Content-Length: 15\r\n
Via: 1.1 172.16.0.1:8080\r\n
Connection: close\r\n
Content-Type: text/plain; charset=ISO-8859-1\r\n
\r\n

0.051| expecting 15 bytes of message body based on Content-Length header
0.051| parsed 15 bytes of message body: 
body-hwljpuaajn

0.052| client expects no more data (after 262 + 15 = 277 bytes)
0.052| content size: 15
0.052| client at 172.16.0.1:1164 stops reading from 172.16.0.7:80
0.052| client stops servicing connection with 172.16.0.7:80
0.052| client at 172.16.0.1:1164 closing connection to 172.16.0.7:80
0.052| server stops accepting HTTP queries at coad-dev.measurement-factory.com:8080
0.052| finished case: test_case/rfc2616/cacheSmth
0.052| result code: success
0.052| result reason: DUT proxied the transaction and possibly cached the response

0.052| step 2: verifying whether the entity was cached and is fresh

Subcase: check that a given entity instance is cached and fresh

0.053| starting sub-case test_case/rfc2616/checkCached-fresh
0.053| server accepting HTTP queries at coad-dev.measurement-factory.com:8080
0.053| client connecting to 172.16.0.7:80; 3 attempt(s)
0.053| client at 172.16.0.1:1165 connected to 172.16.0.7:80
0.053| client will send 94 bytes (94 + 0)
GET http://172.16.0.1:8080/erwdstyemydp HTTP/1.1\r\n
Host: 172.16.0.1:8080\r\n
Connection: close\r\n
\r\n

0.054| client at 172.16.0.1:1165 expects to write to 172.16.0.7:80
0.054| client at 172.16.0.1:1165 wrote 94 bytes to 172.16.0.7:80
0.054| client at 172.16.0.1:1165 stops writing to 172.16.0.7:80
0.054| client at 172.16.0.1:1165 expects to read from 172.16.0.7:80
0.056| client at 172.16.0.1:1165 read 270 bytes from 172.16.0.7:80
0.056| client parsed response headers (255 bytes)
HTTP/1.1 200 OK\r\n
Date: Mon, 07 Jul 2003 22:02:33 GMT\r\n
Via: 1.1 172.16.0.1:8080\r\n
Cache-Control: public, max-age=8\r\n
Last-Modified: Sun, 07 Jul 2002 22:02:34 GMT\r\n
Content-Length: 15\r\n
Content-Type: text/plain; charset=ISO-8859-1\r\n
Age: 0\r\n
Connection: close\r\n
\r\n

0.056| expecting 15 bytes of message body based on Content-Length header
0.057| parsed 15 bytes of message body: 
body-hwljpuaajn

0.057| client expects no more data (after 255 + 15 = 270 bytes)
0.057| content size: 15
0.057| client at 172.16.0.1:1165 stops reading from 172.16.0.7:80
0.057| client stops servicing connection with 172.16.0.7:80
0.057| client at 172.16.0.1:1165 closing connection to 172.16.0.7:80
0.057| server stops accepting HTTP queries at coad-dev.measurement-factory.com:8080
0.057| finished case: test_case/rfc2616/checkCached-fresh
0.057| result code: success
0.057| result reason: at the time of the request, entity instance appeared to be cached and fresh

0.057| sleeping for 10 seconds to increase age of a cached entity
10.059| step 3: verifying whether the cached entity is still cached

Subcase: check that a given entity instance is not cached or cached but stale

10.059| starting sub-case test_case/rfc2616/checkCached-notORstale
10.059| server accepting HTTP queries at coad-dev.measurement-factory.com:8080
10.059| client connecting to 172.16.0.7:80; 3 attempt(s)
10.060| client at 172.16.0.1:1166 connected to 172.16.0.7:80
10.060| client will send 94 bytes (94 + 0)
GET http://172.16.0.1:8080/erwdstyemydp HTTP/1.1\r\n
Host: 172.16.0.1:8080\r\n
Connection: close\r\n
\r\n

10.060| client at 172.16.0.1:1166 expects to write to 172.16.0.7:80
10.060| client at 172.16.0.1:1166 wrote 94 bytes to 172.16.0.7:80
10.060| client at 172.16.0.1:1166 stops writing to 172.16.0.7:80
10.060| client at 172.16.0.1:1166 expects to read from 172.16.0.7:80
10.062| client at 172.16.0.1:1166 read 271 bytes from 172.16.0.7:80
10.062| client parsed response headers (256 bytes)
HTTP/1.1 200 OK\r\n
Date: Mon, 07 Jul 2003 22:02:43 GMT\r\n
Via: 1.1 172.16.0.1:8080\r\n
Cache-Control: public, max-age=8\r\n
Last-Modified: Sun, 07 Jul 2002 22:02:34 GMT\r\n
Content-Length: 15\r\n
Content-Type: text/plain; charset=ISO-8859-1\r\n
Age: 10\r\n
Connection: close\r\n
\r\n

10.063| expecting 15 bytes of message body based on Content-Length header
10.063| parsed 15 bytes of message body: 
body-hwljpuaajn

10.063| client expects no more data (after 256 + 15 = 271 bytes)
10.063| content size: 15
10.063| client at 172.16.0.1:1166 stops reading from 172.16.0.7:80
10.063| client stops servicing connection with 172.16.0.7:80
10.063| client at 172.16.0.1:1166 closing connection to 172.16.0.7:80
10.063| server stops accepting HTTP queries at coad-dev.measurement-factory.com:8080
10.063| finished case: test_case/rfc2616/checkCached-notORstale
10.063| result code: failure
10.063| result reason: at the time of the request, entity instance appeared to be cached and fresh rather than being not cached or cached but stale

10.063| finished case: test_case/rfc2616/ccRespDirMsg-max-age-obey
10.063| result code: violation
10.063| result reason: cache did not treat cached entity as stale when the age exceeds max-age Cache-Control directive