See <https://ci.trafficserver.apache.org/job/tsqa-master/926/changes>
Changes: [Bryan Call] TS-3964: Stat for total time spent for HTTP/2 is 0 ------------------------------------------ [...truncated 505 lines...] test_spdy (test_example.TestConfigureFlags) ... ok INFO 2015-10-12 17:40:59,973 - Environment prefix is /tmp/tsqa.env.xPSotq test_basic_proxy (test_example.TestDynamicHTTPEndpointCase) ... 127.0.0.1 - - [12/Oct/2015 17:41:03] "GET /test HTTP/1.1" 404 0 ok INFO 2015-10-12 17:41:03,432 - Environment prefix is /tmp/tsqa.env.4bODJi test_logs_exist (test_example.TestLogs) ... ok SKIP: Skip the entire class INFO 2015-10-12 17:41:16,925 - Environment prefix is /tmp/tsqa.env.XSc_SB test_basic_intercept (test_example.TestServerIntercept) ... 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:20] "GET / HTTP/1.1" 200 5 ok INFO 2015-10-12 17:41:20,441 - Environment prefix is /tmp/tsqa.env.bPKI6M INFO 2015-10-12 17:41:20,443 - map / http://127.0.0.1:54616/ test_head_request_without_timout (test_headrequest.TestHeadRequestWithoutTimeout) ... INFO 2015-10-12 17:41:23,701 - HTTP/1.1 200 OK Server: ATS/6.1.0 Vary: Accept-Encoding Date: Mon, 12 Oct 2015 17:41:23 GMT Age: 0 Connection: close INFO 2015-10-12 17:41:23,701 - head request with case(TE) costs 0.031286 seconds while the timout is 5.000000 seconds. INFO 2015-10-12 17:41:23,702 - HTTP/1.1 200 OK Server: ATS/6.1.0 Content-Length: 123 Vary: Accept-Encoding Date: Mon, 12 Oct 2015 17:41:23 GMT Age: 0 Connection: close INFO 2015-10-12 17:41:23,702 - head request with case(CL) costs 0.001382 seconds while the timout is 5.000000 seconds. INFO 2015-10-12 17:41:23,717 - HTTP/1.1 200 OK Server: ATS/6.1.0 Vary: Accept-Encoding Date: Mon, 12 Oct 2015 17:41:23 GMT Age: 0 Connection: close INFO 2015-10-12 17:41:23,718 - head request with case() costs 0.015222 seconds while the timout is 5.000000 seconds. ok INFO 2015-10-12 17:41:23,904 - Environment prefix is /tmp/tsqa.env.Z5mt6l test_working (test_hostdb.TestHostDBBadResolvConf) ... ok INFO 2015-10-12 17:41:27,376 - Environment prefix is /tmp/tsqa.env.9MdFQr test_lookup_timeout (test_hostdb.TestHostDBFailedDNS) ... ok INFO 2015-10-12 17:41:32,813 - Environment prefix is /tmp/tsqa.env.Mfvq8F Test basic fnctionality of hosts files ... ok Test that changes to hosts file get loaded within host_file.interval ... ok INFO 2015-10-12 17:41:42,308 - Environment prefix is /tmp/tsqa.env.bC_Hq1 SKIP: -------------------- >> begin captured logging << -------------------- root: INFO: Environment prefix is /tmp/tsqa.env.bC_Hq1 --------------------- >> end captured logging << --------------------- Failure: SkipTest (Cannot import hyper, skipping tests for HTTP/2) ... SKIP: Cannot import hyper, skipping tests for HTTP/2 INFO 2015-10-12 17:41:42,393 - Environment prefix is /tmp/tsqa.env.6HMTki SKIP: Cannot find h2spec. skipping test. -------------------- >> begin captured logging << -------------------- root: INFO: Environment prefix is /tmp/tsqa.env.6HMTki --------------------- >> end captured logging << --------------------- INFO 2015-10-12 17:41:42,494 - Environment prefix is /tmp/tsqa.env.hUS2zB test_ecdsa (test_https.TestECDSA) ... ok test_intermediate_ca_ecdsa (test_https.TestECDSA) ... ok test_intermediate_ca_rsa (test_https.TestECDSA) ... ok We should be served the first match, since we aren't sending SNI headers ... ok Make sure we get the certificate we asked for if we pass in SNI headers ... ok test_rsa (test_https.TestECDSA) ... ok We should be served the first match, since we aren't sending SNI headers ... ok Make sure we get the certificate we asked for if we pass in SNI headers ... ok INFO 2015-10-12 17:41:46,034 - Environment prefix is /tmp/tsqa.env.ZFawEi test_ecdsa (test_https.TestMix) ... ok test_intermediate_ca_ecdsa (test_https.TestMix) ... ok test_intermediate_ca_rsa (test_https.TestMix) ... ok We should be served the first match, since we aren't sending SNI headers ... ok Make sure we get the certificate we asked for if we pass in SNI headers ... ok test_rsa (test_https.TestMix) ... ok We should be served the first match, since we aren't sending SNI headers ... ok Make sure we get the certificate we asked for if we pass in SNI headers ... ok INFO 2015-10-12 17:41:49,726 - Environment prefix is /tmp/tsqa.env.N2RYuh test_ecdsa (test_https.TestRSA) ... ok test_intermediate_ca_ecdsa (test_https.TestRSA) ... ok test_intermediate_ca_rsa (test_https.TestRSA) ... ok We should be served the first match, since we aren't sending SNI headers ... ok Make sure we get the certificate we asked for if we pass in SNI headers ... ok test_rsa (test_https.TestRSA) ... ok We should be served the first match, since we aren't sending SNI headers ... ok Make sure we get the certificate we asked for if we pass in SNI headers ... ok INFO 2015-10-12 17:41:53,357 - Environment prefix is /tmp/tsqa.env.EixnVR test_error_path (test_keepalive.TestKeepAliveInHTTP) ... ok Ensure that sending a request with a body doesn't break the keepalive session ... ok test_working_path (test_keepalive.TestKeepAliveInHTTP) ... 127.0.0.1 - - [12/Oct/2015 17:41:56] "GET /exists/ HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:56] "GET /exists/ HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:56] "GET /exists/ HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:56] "GET /exists/ HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:56] "GET /exists/ HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:56] "GET /exists/ HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:56] "GET /exists/ HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:56] "GET /exists/ HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:41:56] "GET /exists/ HTTP/1.1" 200 5 ok INFO 2015-10-12 17:41:56,782 - Environment prefix is /tmp/tsqa.env.fL_hqk Tests that origin_min_keep_alive_connections is honored via http. ... ok INFO 2015-10-12 17:42:03,211 - Environment prefix is /tmp/tsqa.env.yP3qi2 Tests that origin_min_keep_alive_connections is honored via https. ... ok INFO 2015-10-12 17:42:09,640 - Environment prefix is /tmp/tsqa.env.SdnvYV Test that the origin does in fact support keepalive via http. ... ok Tests that keepalive works through ATS to origin via http. ... ok Tests that origin does not timeout using keepalive via http. ... ok Tests that keepalive timeout is honored through ATS to origin via http. ... ok INFO 2015-10-12 17:42:31,114 - Environment prefix is /tmp/tsqa.env.541Ry8 Test that the origin does in fact support keepalive via https. ... ok Tests that keepalive works through ATS to origin via https. ... ok Tests that origin does not timeout using keepalive via https. ... ok Tests that keepalive timeout is honored through ATS to origin via https. ... ok INFO 2015-10-12 17:42:52,610 - Environment prefix is /tmp/tsqa.env.r6_iuH Tests that keepalive works through ATS to origin via https. ... ok Tests that keepalive works through ATS to origin via https. ... ok INFO 2015-10-12 17:42:56,132 - Environment prefix is /tmp/tsqa.env.ENEHPJ Tests that keepalive works through ATS to origin via https. ... ok Tests that keepalive works through ATS to origin via https. ... ok INFO 2015-10-12 17:42:59,587 - Environment prefix is /tmp/tsqa.env.8sZBrb INFO 2015-10-12 17:42:59,589 - socket_server_port = 46813 INFO 2015-10-12 17:42:59,589 - starting the socket server test_origin_min_connection (test_origin_min_keep_alive_connection.TestKeepAlive_Origin_Min_connections) ... INFO 2015-10-12 17:43:02,859 - Sending data back to the client: 4f8476c837594ffca920b5a5e0979dc2 INFO 2015-10-12 17:43:02,860 - 4f8476c837594ffca920b5a5e0979dc2 INFO 2015-10-12 17:43:07,866 - Sending data back to the client: 4f8476c837594ffca920b5a5e0979dc2 INFO 2015-10-12 17:43:07,866 - 4f8476c837594ffca920b5a5e0979dc2 ok INFO 2015-10-12 17:43:08,055 - Environment prefix is /tmp/tsqa.env.mYVbVe test_redirection (test_redirection.TestRedirection) ... 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /redirect/9 HTTP/1.1" 302 247 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/8 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/7 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/6 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/5 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/4 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/3 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/2 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/1 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /get HTTP/1.1" 200 391 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /redirect/10 HTTP/1.1" 302 247 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/9 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/8 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/7 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/6 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/5 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/4 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/3 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/2 HTTP/1.1" 302 0 127.0.0.1 - - [12/Oct/2015 17:43:11] "GET /relative-redirect/1 HTTP/1.1" 302 0 ok INFO 2015-10-12 17:43:11,571 - Environment prefix is /tmp/tsqa.env.vZ8go0 test_regressions (test_regressions.TestRegressions) ... ok INFO 2015-10-12 17:45:45,385 - Starting build (d133993325226bee52737bbab4e1cbc1): configure {'enable-ccache': None, 'enable-experimental-plugins': None, 'enable-example-plugins': None, 'enable-test-tools': None, 'enable-linux-native-aio': None, 'disable-dependency-tracking': None} SKIP: Error 1 running: ['<https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/configure',> '--prefix=/', '--enable-ccache', '--enable-experimental-plugins', '--enable-example-plugins', '--enable-test-tools', '--enable-linux-native-aio', '--disable-dependency-tracking'] configure: error: Linux native AIO requires libaio.h -------------------- >> begin captured logging << -------------------- tsqa.environment: INFO: Starting build (d133993325226bee52737bbab4e1cbc1): configure {'enable-ccache': None, 'enable-experimental-plugins': None, 'enable-example-plugins': None, 'enable-test-tools': None, 'enable-linux-native-aio': None, 'disable-dependency-tracking': None} --------------------- >> end captured logging << --------------------- INFO 2015-10-12 17:45:55,100 - Environment prefix is /tmp/tsqa.env.rKC2DV test_remap_http (test_remap.TestRemapHTTP) ... 127.0.0.1 - - [12/Oct/2015 17:45:58] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:45:58] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:45:58] "GET / HTTP/1.1" 200 5 ok INFO 2015-10-12 17:45:58,545 - Environment prefix is /tmp/tsqa.env.oiyXVq test_remap_https (test_remap.TestRemapHTTPS) ... 127.0.0.1 - - [12/Oct/2015 17:46:01] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:46:01] "GET / HTTP/1.1" 200 5 127.0.0.1 - - [12/Oct/2015 17:46:01] "GET / HTTP/1.1" 200 5 ok SKIP: Skipping spdy/2 tests INFO 2015-10-12 17:46:02,011 - Environment prefix is /tmp/tsqa.env.U9XnZZ INFO 2015-10-12 17:46:02,013 - spdycat path = /usr/local/bin/spdycat INFO 2015-10-12 17:46:02,013 - spdy server port = 48074 INFO 2015-10-12 17:46:02,013 - http server port = 47626 Test that the origin does in fact support spdy 3 ... INFO 2015-10-12 17:46:05,242 - full args = ['/usr/local/bin/spdycat', 'https://localhost:48074/', '-nv', '--spdy3'] ok Test that non spdy port won't advertise spdy ... INFO 2015-10-12 17:46:06,328 - full args = ['/usr/local/bin/spdycat', 'https://localhost:47626/', '-nv', '--spdy3'] Fatal: EOF reqnum=1, completed=0 Some requests were not processed. total=1, processed=0 ok INFO 2015-10-12 17:46:06,543 - Environment prefix is /tmp/tsqa.env.Nk33Wx INFO 2015-10-12 17:46:06,545 - spdycat path = /usr/local/bin/spdycat INFO 2015-10-12 17:46:06,545 - spdy server port = 37395 INFO 2015-10-12 17:46:06,545 - http server port = 43085 Test that the origin does in fact support spdy 3.1 ... INFO 2015-10-12 17:46:09,778 - full args = ['/usr/local/bin/spdycat', 'https://localhost:37395/', '-nv', '--spdy3-1'] ok Test that non spdy port won't advertise spdy ... INFO 2015-10-12 17:46:10,729 - full args = ['/usr/local/bin/spdycat', 'https://localhost:43085/', '-nv', '--spdy3-1'] Fatal: EOF reqnum=1, completed=0 Some requests were not processed. total=1, processed=0 ok INFO 2015-10-12 17:46:10,934 - Environment prefix is /tmp/tsqa.env.C149kY Make sure the new ticket key is loaded ... ok Make sure the new ticket key is loaded ... ok ====================================================================== ERROR: test_chunked_bad_close (test_chunked.TestChunked) ---------------------------------------------------------------------- Traceback (most recent call last): File "<https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/ci/tsqa/tests/test_chunked.py";,> line 198, in test_chunked_bad_close requests.get(url, proxies=self.proxies, timeout=2) File "<https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/ci/tsqa/virtualenv/lib/python2.7/site-packages/requests/api.py";,> line 69, in get return request('get', url, params=params, **kwargs) File "<https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/ci/tsqa/virtualenv/lib/python2.7/site-packages/requests/api.py";,> line 50, in request response = session.request(method=method, url=url, **kwargs) File "<https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/ci/tsqa/virtualenv/lib/python2.7/site-packages/requests/sessions.py";,> line 471, in request resp = self.send(prep, **send_kwargs) File "<https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/ci/tsqa/virtualenv/lib/python2.7/site-packages/requests/sessions.py";,> line 611, in send r.content File "<https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/ci/tsqa/virtualenv/lib/python2.7/site-packages/requests/models.py";,> line 734, in content self._content = bytes().join(self.iter_content(CONTENT_CHUNK_SIZE)) or bytes() File "<https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/ci/tsqa/virtualenv/lib/python2.7/site-packages/requests/models.py";,> line 664, in generate raise ConnectionError(e) ConnectionError: HTTPConnectionPool(host='127.0.0.1', port=59176): Read timed out. -------------------- >> begin captured logging << -------------------- root: INFO: Environment prefix is /tmp/tsqa.env.fMBYNO test_chunked: INFO: sending data back to the client --------------------- >> end captured logging << --------------------- ====================================================================== FAIL: test_log_field (test_custom_log.TestCustomLogField) ---------------------------------------------------------------------- Traceback (most recent call last): File "<https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/ci/tsqa/tests/test_custom_log.py";,> line 70, in test_log_field self.assertEqual(line, expected_line) AssertionError: '127.0.0.1 7F000001\n' != '127.6.242.6 7F06F206\n' -------------------- >> begin captured logging << -------------------- root: INFO: Environment prefix is /tmp/tsqa.env.LpFBl6 --------------------- >> end captured logging << --------------------- ---------------------------------------------------------------------- XML: <https://ci.trafficserver.apache.org/job/tsqa-master/ws/src/ci/tsqa/nosetests.xml> ---------------------------------------------------------------------- Ran 83 tests in 873.182s FAILED (SKIP=8, errors=1, failures=1) 2 make: *** [test] Error 1 Build step 'Execute shell' marked build as failure Recording test results
