Test Case: cache MUST ignore max-age=8 in the value of foobar=value extension response cache-directive
Subcase gistStateComment
cache must treat cached entity as stale when the age exceeds max-age Cache-Control directivesuccesscache did treat cached entity as stale when the age exceeds max-age Cache-Control directive
... directivesuccesscache did treat cached entity as stale when the age exceeds max-age Cache-Control directive

119.472| starting test case test_case/rfc2616/ccExtension-max-age-value-toClt
119.472| Co-Advisor version: 2.1.4b
119.472| step 1: executing unaltered test case to make sure DUT supports the original cache-directive(s)

Subcase: cache must treat cached entity as stale when the age exceeds max-age Cache-Control directive
Subcase gistStateComment
cache somethingsuccessDUT proxied the transaction and possibly cached the response
check that a given entity instance is cached and freshsuccessat the time of the request, entity instance appeared to be cached and fresh
check that a given entity instance is not cached or cached but stalesuccessat the time of the request, entity instance did not appear to be cached

119.472| starting sub-case test_case/rfc2616/ccRespDirMsg-max-age-obey
119.473| step 1.1: attempting to cache entity with max-age Cache-Control directive

Subcase: cache something
119.473| starting sub-case test_case/rfc2616/cacheSmth
119.473| server accepting HTTP queries at 10.0.0.42:8081
119.473| client connecting to 10.0.0.42:8080; 3 attempt(s)
119.473| client at 10.0.0.42:58096 connected to 10.0.0.42:8080
119.473| client will send 92 bytes (92 + 0)
GET http://10.0.0.42:8081/ulvbmpkpuabi HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Connection: close\r\n
\r\n

119.474| client at 10.0.0.42:58096 expects to write to 10.0.0.42:8080
119.474| client at 10.0.0.42:58096 wrote 92 bytes to 10.0.0.42:8080 ( 92 bytes so far)
119.474| client at 10.0.0.42:58096 stops writing to 10.0.0.42:8080( after 92 bytes)
119.474| client at 10.0.0.42:58096 expects to read from 10.0.0.42:8080
119.474| server at 10.0.0.42:8081 accepted connection from 10.0.0.42:56917
119.474| server at 10.0.0.42:8081 expects to read from 10.0.0.42:56917
119.474| server at 10.0.0.42:8081 read 130 bytes from 10.0.0.42:56917 ( 130 bytes so far)
119.475| server got request headers (130 bytes)
GET /ulvbmpkpuabi HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Max-Forwards: 10\r\n
Connection: close\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
\r\n

119.475| expecting no message body
119.475| expected message body format: opaque message body
119.475| no more message body data to parse
119.475| server expects no more request data (after 130 + 0 = 130 bytes)
119.475| server at 10.0.0.42:8081 stops reading from 10.0.0.42:56917( after 130 bytes)
119.476| server will send 205 bytes
HTTP/1.1 200 OK\r\n
Cache-Control: public\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Cache-Control: max-age=8\r\n
Date: Fri, 03 Jun 2005 22:34:11 GMT\r\n
Content-Length: 15\r\n
Connection: close\r\n
\r\n
body-ocolfjnphw

119.476| server at 10.0.0.42:8081 expects to write to 10.0.0.42:56917
119.476| server at 10.0.0.42:8081 wrote 205 bytes to 10.0.0.42:56917 ( 205 bytes so far)
119.477| server at 10.0.0.42:8081 stops writing to 10.0.0.42:56917( after 205 bytes)
119.477| server stops servicing connection with 10.0.0.42:56917
119.477| server at 10.0.0.42:8081 closing connection to 10.0.0.42:56917 (read 130 bytes and wrote 205 bytes)
119.477| client at 10.0.0.42:58096 read 257 bytes from 10.0.0.42:8080 ( 257 bytes so far)
119.478| client parsed response headers (242 bytes)
HTTP/1.1 200 OK\r\n
Date: Fri, 03 Jun 2005 22:34:10 GMT\r\n
Cache-Control: public, max-age=8\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Content-Length: 15\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
Connection: close\r\n
Content-Type: text/plain\r\n
\r\n

119.478| expecting 15 bytes of message body based on Content-Length header
119.478| expected message body format: opaque message body
119.478| parsed 15 bytes of message body:
body-ocolfjnphw

119.478| client expects no more data (after 242 + 15 = 257 bytes)
119.479| content size: 15
119.479| client at 10.0.0.42:58096 stops reading from 10.0.0.42:8080( after 257 bytes)
119.479| client stops servicing connection with 10.0.0.42:8080
119.479| client at 10.0.0.42:58096 closing connection to 10.0.0.42:8080 (read 257 bytes and wrote 92 bytes)
119.479| server stops accepting HTTP queries at 10.0.0.42:8081
119.479| finished case: test_case/rfc2616/cacheSmth
119.479| result code: success
119.479| result reason: DUT proxied the transaction and possibly cached the response

119.479| step 1.2: verifying whether the entity was cached and is fresh

Subcase: check that a given entity instance is cached and fresh
119.480| starting sub-case test_case/rfc2616/checkCached-fresh
119.480| server accepting HTTP queries at 10.0.0.42:8081
119.480| client connecting to 10.0.0.42:8080; 3 attempt(s)
119.480| client at 10.0.0.42:60536 connected to 10.0.0.42:8080
119.480| client will send 92 bytes (92 + 0)
GET http://10.0.0.42:8081/ulvbmpkpuabi HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Connection: close\r\n
\r\n

119.480| client at 10.0.0.42:60536 expects to write to 10.0.0.42:8080
119.481| client at 10.0.0.42:60536 wrote 92 bytes to 10.0.0.42:8080 ( 92 bytes so far)
119.481| client at 10.0.0.42:60536 stops writing to 10.0.0.42:8080( after 92 bytes)
119.481| client at 10.0.0.42:60536 expects to read from 10.0.0.42:8080
119.481| client at 10.0.0.42:60536 read 265 bytes from 10.0.0.42:8080 ( 265 bytes so far)
119.482| client parsed response headers (250 bytes)
HTTP/1.1 200 OK\r\n
Date: Fri, 03 Jun 2005 22:34:10 GMT\r\n
Content-Type: text/plain\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Cache-Control: public, max-age=8\r\n
Content-Length: 15\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
Age: 0\r\n
Connection: close\r\n
\r\n

119.482| expecting 15 bytes of message body based on Content-Length header
119.482| expected message body format: opaque message body
119.482| parsed 15 bytes of message body:
body-ocolfjnphw

119.482| client expects no more data (after 250 + 15 = 265 bytes)
119.482| content size: 15
119.482| client at 10.0.0.42:60536 stops reading from 10.0.0.42:8080( after 265 bytes)
119.482| client stops servicing connection with 10.0.0.42:8080
119.482| client at 10.0.0.42:60536 closing connection to 10.0.0.42:8080 (read 265 bytes and wrote 92 bytes)
119.483| server stops accepting HTTP queries at 10.0.0.42:8081
119.483| finished case: test_case/rfc2616/checkCached-fresh
119.483| result code: success
119.483| result reason: at the time of the request, entity instance appeared to be cached and fresh

119.483| sleeping for 10 seconds to increase age of a cached entity
129.488| step 1.3: verifying whether the cached entity is still cached

Subcase: check that a given entity instance is not cached or cached but stale
129.488| starting sub-case test_case/rfc2616/checkCached-notORstale
129.488| server accepting HTTP queries at 10.0.0.42:8081
129.488| client connecting to 10.0.0.42:8080; 3 attempt(s)
129.488| client at 10.0.0.42:53071 connected to 10.0.0.42:8080
129.488| client will send 92 bytes (92 + 0)
GET http://10.0.0.42:8081/ulvbmpkpuabi HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Connection: close\r\n
\r\n

129.489| client at 10.0.0.42:53071 expects to write to 10.0.0.42:8080
129.489| client at 10.0.0.42:53071 wrote 92 bytes to 10.0.0.42:8080 ( 92 bytes so far)
129.489| client at 10.0.0.42:53071 stops writing to 10.0.0.42:8080( after 92 bytes)
129.489| client at 10.0.0.42:53071 expects to read from 10.0.0.42:8080
129.489| server at 10.0.0.42:8081 accepted connection from 10.0.0.42:55516
129.489| server at 10.0.0.42:8081 expects to read from 10.0.0.42:55516
129.490| server at 10.0.0.42:8081 read 130 bytes from 10.0.0.42:55516 ( 130 bytes so far)
129.490| server got request headers (130 bytes)
GET /ulvbmpkpuabi HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Max-Forwards: 10\r\n
Connection: close\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
\r\n

129.490| expecting no message body
129.490| expected message body format: opaque message body
129.490| no more message body data to parse
129.490| server expects no more request data (after 130 + 0 = 130 bytes)
129.490| server at 10.0.0.42:8081 stops reading from 10.0.0.42:55516( after 130 bytes)
129.491| server will send 205 bytes
HTTP/1.1 200 OK\r\n
Cache-Control: public\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Cache-Control: max-age=8\r\n
Content-Length: 15\r\n
Date: Fri, 03 Jun 2005 22:34:21 GMT\r\n
Connection: close\r\n
\r\n
body-ocolfjnphw

129.491| server at 10.0.0.42:8081 expects to write to 10.0.0.42:55516
129.491| server at 10.0.0.42:8081 wrote 205 bytes to 10.0.0.42:55516 ( 205 bytes so far)
129.492| server at 10.0.0.42:8081 stops writing to 10.0.0.42:55516( after 205 bytes)
129.492| server stops servicing connection with 10.0.0.42:55516
129.492| server at 10.0.0.42:8081 closing connection to 10.0.0.42:55516 (read 130 bytes and wrote 205 bytes)
129.492| client at 10.0.0.42:53071 read 257 bytes from 10.0.0.42:8080 ( 257 bytes so far)
129.493| client parsed response headers (242 bytes)
HTTP/1.1 200 OK\r\n
Date: Fri, 03 Jun 2005 22:34:20 GMT\r\n
Cache-Control: public, max-age=8\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Content-Length: 15\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
Connection: close\r\n
Content-Type: text/plain\r\n
\r\n

129.493| expecting 15 bytes of message body based on Content-Length header
129.493| expected message body format: opaque message body
129.493| parsed 15 bytes of message body:
body-ocolfjnphw

129.493| client expects no more data (after 242 + 15 = 257 bytes)
129.494| content size: 15
129.494| client at 10.0.0.42:53071 stops reading from 10.0.0.42:8080( after 257 bytes)
129.494| client stops servicing connection with 10.0.0.42:8080
129.494| client at 10.0.0.42:53071 closing connection to 10.0.0.42:8080 (read 257 bytes and wrote 92 bytes)
129.494| server stops accepting HTTP queries at 10.0.0.42:8081
129.495| finished case: test_case/rfc2616/checkCached-notORstale
129.495| result code: success
129.495| result reason: at the time of the request, entity instance did not appear to be cached

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

129.495| step 2: repeating the same test case with the original cache-directive(s) replaced with max-age=8 in the value of foobar=value extension response cache-directive; expecting a violation if the DUT correctly ignores those extensions

Subcase: cache must treat cached entity as stale when the age exceeds max-age Cache-Control directive
Subcase gistStateComment
cache somethingsuccessDUT proxied the transaction and possibly cached the response
check that a given entity instance is cached and freshsuccessat the time of the request, entity instance appeared to be cached and fresh
check that a given entity instance is not cached or cached but stalesuccessat the time of the request, entity instance did not appear to be cached

129.495| starting sub-case test_case/rfc2616/ccRespDirMsg-max-age-obey
129.495| step 2.1: attempting to cache entity with max-age Cache-Control directive

Subcase: cache something
129.495| starting sub-case test_case/rfc2616/cacheSmth
129.495| server accepting HTTP queries at 10.0.0.42:8081
129.496| client connecting to 10.0.0.42:8080; 3 attempt(s)
129.496| client at 10.0.0.42:58949 connected to 10.0.0.42:8080
129.496| client will send 92 bytes (92 + 0)
GET http://10.0.0.42:8081/mfkawtyofanq HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Connection: close\r\n
\r\n

129.496| client at 10.0.0.42:58949 expects to write to 10.0.0.42:8080
129.496| client at 10.0.0.42:58949 wrote 92 bytes to 10.0.0.42:8080 ( 92 bytes so far)
129.496| client at 10.0.0.42:58949 stops writing to 10.0.0.42:8080( after 92 bytes)
129.497| client at 10.0.0.42:58949 expects to read from 10.0.0.42:8080
129.497| server at 10.0.0.42:8081 accepted connection from 10.0.0.42:52519
129.497| server at 10.0.0.42:8081 expects to read from 10.0.0.42:52519
129.497| server at 10.0.0.42:8081 read 130 bytes from 10.0.0.42:52519 ( 130 bytes so far)
129.497| server got request headers (130 bytes)
GET /mfkawtyofanq HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Max-Forwards: 10\r\n
Connection: close\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
\r\n

129.497| expecting no message body
129.498| expected message body format: opaque message body
129.498| no more message body data to parse
129.498| server expects no more request data (after 130 + 0 = 130 bytes)
129.498| server at 10.0.0.42:8081 stops reading from 10.0.0.42:52519( after 130 bytes)
129.499| server will send 226 bytes
HTTP/1.1 200 OK\r\n
Cache-Control: public\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Cache-Control: foobar=" max-age=8,max-age=8 "\r\n
Date: Fri, 03 Jun 2005 22:34:21 GMT\r\n
Content-Length: 15\r\n
Connection: close\r\n
\r\n
body-tmxskrllxs

129.499| server at 10.0.0.42:8081 expects to write to 10.0.0.42:52519
129.500| server at 10.0.0.42:8081 wrote 226 bytes to 10.0.0.42:52519 ( 226 bytes so far)
129.500| server at 10.0.0.42:8081 stops writing to 10.0.0.42:52519( after 226 bytes)
129.500| server stops servicing connection with 10.0.0.42:52519
129.500| server at 10.0.0.42:8081 closing connection to 10.0.0.42:52519 (read 130 bytes and wrote 226 bytes)
129.501| client at 10.0.0.42:58949 read 278 bytes from 10.0.0.42:8080 ( 278 bytes so far)
129.501| client parsed response headers (263 bytes)
HTTP/1.1 200 OK\r\n
Date: Fri, 03 Jun 2005 22:34:20 GMT\r\n
Cache-Control: public, foobar=" max-age=8,max-age=8 "\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Content-Length: 15\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
Connection: close\r\n
Content-Type: text/plain\r\n
\r\n

129.502| expecting 15 bytes of message body based on Content-Length header
129.502| expected message body format: opaque message body
129.502| parsed 15 bytes of message body:
body-tmxskrllxs

129.502| client expects no more data (after 263 + 15 = 278 bytes)
129.502| content size: 15
129.502| client at 10.0.0.42:58949 stops reading from 10.0.0.42:8080( after 278 bytes)
129.502| client stops servicing connection with 10.0.0.42:8080
129.502| client at 10.0.0.42:58949 closing connection to 10.0.0.42:8080 (read 278 bytes and wrote 92 bytes)
129.502| server stops accepting HTTP queries at 10.0.0.42:8081
129.503| finished case: test_case/rfc2616/cacheSmth
129.503| result code: success
129.503| result reason: DUT proxied the transaction and possibly cached the response

129.503| step 2.2: verifying whether the entity was cached and is fresh

Subcase: check that a given entity instance is cached and fresh
129.503| starting sub-case test_case/rfc2616/checkCached-fresh
129.503| server accepting HTTP queries at 10.0.0.42:8081
129.503| client connecting to 10.0.0.42:8080; 3 attempt(s)
129.504| client at 10.0.0.42:60204 connected to 10.0.0.42:8080
129.504| client will send 92 bytes (92 + 0)
GET http://10.0.0.42:8081/mfkawtyofanq HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Connection: close\r\n
\r\n

129.504| client at 10.0.0.42:60204 expects to write to 10.0.0.42:8080
129.504| client at 10.0.0.42:60204 wrote 92 bytes to 10.0.0.42:8080 ( 92 bytes so far)
129.504| client at 10.0.0.42:60204 stops writing to 10.0.0.42:8080( after 92 bytes)
129.504| client at 10.0.0.42:60204 expects to read from 10.0.0.42:8080
129.504| client at 10.0.0.42:60204 read 286 bytes from 10.0.0.42:8080 ( 286 bytes so far)
129.505| client parsed response headers (271 bytes)
HTTP/1.1 200 OK\r\n
Date: Fri, 03 Jun 2005 22:34:20 GMT\r\n
Content-Type: text/plain\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Cache-Control: public, foobar=" max-age=8,max-age=8 "\r\n
Content-Length: 15\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
Age: 0\r\n
Connection: close\r\n
\r\n

129.505| expecting 15 bytes of message body based on Content-Length header
129.505| expected message body format: opaque message body
129.506| parsed 15 bytes of message body:
body-tmxskrllxs

129.506| client expects no more data (after 271 + 15 = 286 bytes)
129.506| content size: 15
129.506| client at 10.0.0.42:60204 stops reading from 10.0.0.42:8080( after 286 bytes)
129.506| client stops servicing connection with 10.0.0.42:8080
129.506| client at 10.0.0.42:60204 closing connection to 10.0.0.42:8080 (read 286 bytes and wrote 92 bytes)
129.506| server stops accepting HTTP queries at 10.0.0.42:8081
129.506| finished case: test_case/rfc2616/checkCached-fresh
129.506| result code: success
129.506| result reason: at the time of the request, entity instance appeared to be cached and fresh

129.506| sleeping for 10 seconds to increase age of a cached entity
139.508| step 2.3: verifying whether the cached entity is still cached

Subcase: check that a given entity instance is not cached or cached but stale
139.508| starting sub-case test_case/rfc2616/checkCached-notORstale
139.508| server accepting HTTP queries at 10.0.0.42:8081
139.508| client connecting to 10.0.0.42:8080; 3 attempt(s)
139.508| client at 10.0.0.42:53508 connected to 10.0.0.42:8080
139.509| client will send 92 bytes (92 + 0)
GET http://10.0.0.42:8081/mfkawtyofanq HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Connection: close\r\n
\r\n

139.509| client at 10.0.0.42:53508 expects to write to 10.0.0.42:8080
139.510| client at 10.0.0.42:53508 wrote 92 bytes to 10.0.0.42:8080 ( 92 bytes so far)
139.510| client at 10.0.0.42:53508 stops writing to 10.0.0.42:8080( after 92 bytes)
139.510| client at 10.0.0.42:53508 expects to read from 10.0.0.42:8080
139.511| server at 10.0.0.42:8081 accepted connection from 10.0.0.42:59602
139.511| server at 10.0.0.42:8081 expects to read from 10.0.0.42:59602
139.511| server at 10.0.0.42:8081 read 130 bytes from 10.0.0.42:59602 ( 130 bytes so far)
139.511| server got request headers (130 bytes)
GET /mfkawtyofanq HTTP/1.1\r\n
Host: 10.0.0.42:8081\r\n
Max-Forwards: 10\r\n
Connection: close\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
\r\n

139.511| expecting no message body
139.511| expected message body format: opaque message body
139.512| no more message body data to parse
139.512| server expects no more request data (after 130 + 0 = 130 bytes)
139.512| server at 10.0.0.42:8081 stops reading from 10.0.0.42:59602( after 130 bytes)
139.512| server will send 226 bytes
HTTP/1.1 200 OK\r\n
Cache-Control: public\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Cache-Control: foobar=" max-age=8,max-age=8 "\r\n
Content-Length: 15\r\n
Date: Fri, 03 Jun 2005 22:34:31 GMT\r\n
Connection: close\r\n
\r\n
body-tmxskrllxs

139.513| server at 10.0.0.42:8081 expects to write to 10.0.0.42:59602
139.513| server at 10.0.0.42:8081 wrote 226 bytes to 10.0.0.42:59602 ( 226 bytes so far)
139.513| server at 10.0.0.42:8081 stops writing to 10.0.0.42:59602( after 226 bytes)
139.513| server stops servicing connection with 10.0.0.42:59602
139.513| server at 10.0.0.42:8081 closing connection to 10.0.0.42:59602 (read 130 bytes and wrote 226 bytes)
139.514| client at 10.0.0.42:53508 read 278 bytes from 10.0.0.42:8080 ( 278 bytes so far)
139.514| client parsed response headers (263 bytes)
HTTP/1.1 200 OK\r\n
Date: Fri, 03 Jun 2005 22:34:30 GMT\r\n
Cache-Control: public, foobar=" max-age=8,max-age=8 "\r\n
Last-Modified: Thu, 03 Jun 2004 22:32:10 GMT\r\n
Content-Length: 15\r\n
Via: 1.1 10.0.0.42:8081 (Apache/2.0.54)\r\n
Connection: close\r\n
Content-Type: text/plain\r\n
\r\n

139.514| expecting 15 bytes of message body based on Content-Length header
139.515| expected message body format: opaque message body
139.515| parsed 15 bytes of message body:
body-tmxskrllxs

139.515| client expects no more data (after 263 + 15 = 278 bytes)
139.515| content size: 15
139.515| client at 10.0.0.42:53508 stops reading from 10.0.0.42:8080( after 278 bytes)
139.515| client stops servicing connection with 10.0.0.42:8080
139.515| client at 10.0.0.42:53508 closing connection to 10.0.0.42:8080 (read 278 bytes and wrote 92 bytes)
139.515| server stops accepting HTTP queries at 10.0.0.42:8081
139.516| finished case: test_case/rfc2616/checkCached-notORstale
139.516| result code: success
139.516| result reason: at the time of the request, entity instance did not appear to be cached

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

139.516| finished case: test_case/rfc2616/ccExtension-max-age-value-toClt
139.516| result code: violation
139.516| result reason: cache did not ignore max-age=8 in the value of foobar=value extension response cache-directive