Created
June 12, 2021 06:12
-
-
Save dominic-p/95fd4029204c9d21cb1342d86965eb99 to your computer and use it in GitHub Desktop.
Trow authorization issue logs
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Command | |
| $ sudo crictl --debug pull --creds test:test trow-svc.trow.svc.cluster.local:8000/test/nginx:alpine | |
| DEBU[0000] get image connection | |
| DEBU[0000] connect using endpoint 'unix:///var/run/crio/crio.sock' with '2s' timeout | |
| DEBU[0000] connected successfully using endpoint: unix:///var/run/crio/crio.sock | |
| DEBU[0000] PullImageRequest: &PullImageRequest{Image:&ImageSpec{Image:trow-svc.trow.svc.cluster.local:8000/test/nginx:alpine,Annotations:map[string]string{},},Auth:&AuthConfig{Username:test,Password:test,Auth:,ServerAddress:,IdentityToken:,RegistryToken:,},SandboxConfig:nil,} | |
| DEBU[0000] PullImageResponse: nil | |
| FATA[0000] pulling image: rpc error: code = Unknown desc = unable to retrieve auth token: invalid username/password: unauthorized: authentication required | |
| Logs | |
| [2021-06-12T06:07:56Z DEBUG hyper::server] Incoming stream | |
| [2021-06-12T06:07:56Z TRACE hyper::buffer] get_buf [] | |
| [2021-06-12T06:07:56Z TRACE hyper::buffer] read_into_buf buf[0..4096] | |
| [2021-06-12T06:07:56Z TRACE hyper::buffer] get_buf [u8; 4096][0..227] | |
| [2021-06-12T06:07:56Z TRACE hyper::http::h1] try_parse([22, 3, 1, 0, 222, 1, 0, 0, 218, 3, 3, 36, 179, 116, 208, 148, 137, 2, 72, 77, 129, 162, 216, 93, 250, 140, 103, 122, 67, 233, 192, 21, 119, 140, 125, 255, 30, 107, 174, 18, 33, 153, 153, 32, 188, 226, 255, 196, 21, 61, 92, 236, 58, 220, 139, 198, 31, 176, 250, 31, 137, 251, 41, 151, 255, 65, 137, 165, 124, 219, 14, 207, 30, 32, 175, 132, 0, 22, 192, 44, 192, 48, 192, 43, 192, 47, 192, 10, 192, 9, 192, 20, 192, 19, 19, 3, 19, 1, 19, 2, 1, 0, 0, 123, 0, 5, 0, 5, 1, 0, 0, 0, 0, 0, 10, 0, 10, 0, 8, 0, 29, 0, 23, 0, 24, 0, 25, 0, 11, 0, 2, 1, 0, 0, 13, 0, 26, 0, 24, 8, 4, 4, 3, 8, 7, 8, 5, 8, 6, 4, 1, 5, 1, 6, 1, 5, 3, 6, 3, 2, 1, 2, 3, 255, 1, 0, 1, 0, 0, 18, 0, 0, 0, 43, 0, 9, 8, 3, 4, 3, 3, 3, 2, 3, 1, 0, 51, 0, 38, 0, 36, 0, 29, 0, 32, 246, 161, 143, 61, 32, 46, 13, 106, 49, 175, 209, 44, 142, 45, 241, 73, 227, 41, 200, 170, 190, 143, 175, 176, 76, 121, 35, 41, 81, 190, 68, 13]) | |
| [2021-06-12T06:07:56Z TRACE hyper::http::h1] Request.try_parse([Header; 100], [u8; 227]) | |
| [2021-06-12T06:07:56Z INFO hyper::server] request error = Header | |
| [2021-06-12T06:07:56Z DEBUG hyper::server] keep_alive loop ending for 10.244.0.0:49314 | |
| [2021-06-12T06:07:56Z DEBUG hyper::server] Incoming stream | |
| [2021-06-12T06:07:56Z TRACE hyper::buffer] get_buf [] | |
| [2021-06-12T06:07:56Z TRACE hyper::buffer] read_into_buf buf[0..4096] | |
| [2021-06-12T06:07:56Z TRACE hyper::buffer] get_buf [u8; 4096][0..194] | |
| [2021-06-12T06:07:56Z TRACE hyper::http::h1] try_parse([71, 69, 84, 32, 47, 118, 50, 47, 32, 72, 84, 84, 80, 47, 49, 46, 49, 13, 10, 72, 111, 115, 116, 58, 32, 49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48, 13, 10, 85, 115, 101, 114, 45, 65, 103, 101, 110, 116, 58, 32, 99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52, 13, 10, 68, 111, 99, 107, 101, 114, 45, 68, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 45, 65, 112, 105, 45, 86, 101, 114, 115, 105, 111, 110, 58, 32, 114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48, 13, 10, 65, 99, 99, 101, 112, 116, 45, 69, 110, 99, 111, 100, 105, 110, 103, 58, 32, 103, 122, 105, 112, 13, 10, 67, 111, 110, 110, 101, 99, 116, 105, 111, 110, 58, 32, 99, 108, 111, 115, 101, 13, 10, 13, 10]) | |
| [2021-06-12T06:07:56Z TRACE hyper::http::h1] Request.try_parse([Header; 100], [u8; 194]) | |
| [2021-06-12T06:07:56Z TRACE hyper::http::h1] Request.try_parse Complete(194) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] raw header: "Host"=[49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48] | |
| [2021-06-12T06:07:56Z TRACE hyper::header] raw header: "User-Agent"=[99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52] | |
| [2021-06-12T06:07:56Z TRACE hyper::header] raw header: "Docker-Distribution-Api-Version"=[114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48] | |
| [2021-06-12T06:07:56Z TRACE hyper::header] raw header: "Accept-Encoding"=[103, 122, 105, 112] | |
| [2021-06-12T06:07:56Z TRACE hyper::header] raw header: "Connection"=[99, 108, 111, 115, 101] | |
| [2021-06-12T06:07:56Z DEBUG hyper::server::request] Request Line: Get AbsolutePath("/v2/") Http11 | |
| [2021-06-12T06:07:56Z DEBUG hyper::server::request] Headers { Host: 10.99.246.200:8000 | |
| , User-Agent: cri-o/1.19.1 go/go1.15.2 os/linux arch/arm64 | |
| , Docker-Distribution-Api-Version: registry/2.0 | |
| , Accept-Encoding: gzip | |
| , Connection: close | |
| , } | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.set( "Connection", Connection([Close]) ) | |
| [2021-06-12T06:07:56Z TRACE rocket::data::data] Data::new(EmptyReader) | |
| [2021-06-12T06:07:56Z TRACE rocket::data::data] Filled peek buf with 0 bytes. | |
| [2021-06-12T06:07:56Z TRACE rocket::data::data] Peek bytes: 0/512 bytes. | |
| [2021-06-12T06:07:56Z INFO rocket::rocket] GET /v2/: | |
| [2021-06-12T06:07:56Z TRACE rocket::router] Routing the request: GET /v2/ | |
| [2021-06-12T06:07:56Z TRACE rocket::router] All matches: [Route { name: Some("get_v2root"), method: Get, base: Origin { source: None, path: "/", query: None, segment_count: [uninitialized storage] }, uri: Origin { source: None, path: "/v2", query: None, segment_count: [uninitialized storage] }, rank: -4, format: None, metadata: Metadata { path_segments: [RouteSegment { string: "v2", kind: Static, name: "v2", index: Some(0), _part: PhantomData }], query_segments: None, fully_dynamic_query: true } }] | |
| [2021-06-12T06:07:56Z INFO rocket::rocket] Matched: GET /v2 (get_v2root) | |
| [2021-06-12T06:07:56Z INFO rocket::rocket] Outcome: Failure | |
| [2021-06-12T06:07:56Z WARN rocket::rocket] Responding with 401 Unauthorized catcher. | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.append_raw( "www-authenticate", [66, 101, 97, 114, 101, 114, 32, 114, 101, 97, 108, 109, 61, 34, 104, 116, 116, 112, 58, 47, 47, 49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48, 47, 108, 111, 103, 105, 110, 34, 44, 115, 101, 114, 118, 105, 99, 101, 61, 34, 116, 114, 111, 119, 95, 114, 101, 103, 105, 115, 116, 114, 121, 34, 44, 115, 99, 111, 112, 101, 61, 34, 112, 117, 115, 104, 47, 112, 117, 108, 108, 34] ) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.append_raw( "Content-Type", [97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 106, 115, 111, 110] ) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.append_raw( "Server", [82, 111, 99, 107, 101, 116] ) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.append_raw( "Docker-Distribution-API-Version", [114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48] ) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.set( "Content-Length", ContentLength(0) ) | |
| [2021-06-12T06:07:56Z DEBUG hyper::server::response] writing head: Http11 Unauthorized | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.set( "Date", Date(HttpDate(Tm { tm_sec: 56, tm_min: 7, tm_hour: 6, tm_mday: 12, tm_mon: 5, tm_year: 121, tm_wday: 6, tm_yday: 162, tm_isdst: 0, tm_utcoff: 0, tm_nsec: 153930123 })) ) | |
| [2021-06-12T06:07:56Z DEBUG hyper::server::response] headers [ | |
| Headers { Connection: close | |
| , www-authenticate: Bearer realm="http://10.99.246.200:8000/login",service="trow_registry",scope="push/pull" | |
| , Content-Type: application/json | |
| , Server: Rocket | |
| , Docker-Distribution-API-Version: registry/2.0 | |
| , Content-Length: 0 | |
| , Date: Sat, 12 Jun 2021 06:07:56 GMT | |
| , }] | |
| [2021-06-12T06:07:56Z TRACE hyper::server::response] ending | |
| [2021-06-12T06:07:56Z INFO rocket::rocket] Response succeeded. | |
| [2021-06-12T06:07:56Z DEBUG hyper::server] keep_alive = false for 10.244.0.0:17242 | |
| [2021-06-12T06:07:56Z DEBUG hyper::server] keep_alive loop ending for 10.244.0.0:17242 | |
| [2021-06-12T06:07:56Z DEBUG hyper::server] Incoming stream | |
| [2021-06-12T06:07:56Z TRACE hyper::buffer] get_buf [] | |
| [2021-06-12T06:07:56Z TRACE hyper::buffer] read_into_buf buf[0..4096] | |
| [2021-06-12T06:07:56Z TRACE hyper::buffer] get_buf [u8; 4096][0..210] | |
| [2021-06-12T06:07:56Z TRACE hyper::http::h1] try_parse([71, 69, 84, 32, 47, 108, 111, 103, 105, 110, 63, 115, 99, 111, 112, 101, 61, 114, 101, 112, 111, 115, 105, 116, 111, 114, 121, 37, 51, 65, 116, 101, 115, 116, 37, 50, 70, 110, 103, 105, 110, 120, 37, 51, 65, 112, 117, 108, 108, 38, 115, 101, 114, 118, 105, 99, 101, 61, 116, 114, 111, 119, 95, 114, 101, 103, 105, 115, 116, 114, 121, 32, 72, 84, 84, 80, 47, 49, 46, 49, 13, 10, 72, 111, 115, 116, 58, 32, 49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48, 13, 10, 85, 115, 101, 114, 45, 65, 103, 101, 110, 116, 58, 32, 99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52, 13, 10, 65, 99, 99, 101, 112, 116, 45, 69, 110, 99, 111, 100, 105, 110, 103, 58, 32, 103, 122, 105, 112, 13, 10, 67, 111, 110, 110, 101, 99, 116, 105, 111, 110, 58, 32, 99, 108, 111, 115, 101, 13, 10, 13, 10]) | |
| [2021-06-12T06:07:56Z TRACE hyper::http::h1] Request.try_parse([Header; 100], [u8; 210]) | |
| [2021-06-12T06:07:56Z TRACE hyper::http::h1] Request.try_parse Complete(210) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] raw header: "Host"=[49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48] | |
| [2021-06-12T06:07:56Z TRACE hyper::header] raw header: "User-Agent"=[99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52] | |
| [2021-06-12T06:07:56Z TRACE hyper::header] raw header: "Accept-Encoding"=[103, 122, 105, 112] | |
| [2021-06-12T06:07:56Z TRACE hyper::header] raw header: "Connection"=[99, 108, 111, 115, 101] | |
| [2021-06-12T06:07:56Z DEBUG hyper::server::request] Request Line: Get AbsolutePath("/login?scope=repository%3Atest%2Fnginx%3Apull&service=trow_registry") Http11 | |
| [2021-06-12T06:07:56Z DEBUG hyper::server::request] Headers { Host: 10.99.246.200:8000 | |
| , User-Agent: cri-o/1.19.1 go/go1.15.2 os/linux arch/arm64 | |
| , Accept-Encoding: gzip | |
| , Connection: close | |
| , } | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.set( "Connection", Connection([Close]) ) | |
| [2021-06-12T06:07:56Z TRACE rocket::data::data] Data::new(EmptyReader) | |
| [2021-06-12T06:07:56Z TRACE rocket::data::data] Filled peek buf with 0 bytes. | |
| [2021-06-12T06:07:56Z TRACE rocket::data::data] Peek bytes: 0/512 bytes. | |
| [2021-06-12T06:07:56Z INFO rocket::rocket] GET /login?scope=repository%3Atest%2Fnginx%3Apull&service=trow_registry: | |
| [2021-06-12T06:07:56Z TRACE rocket::router] Routing the request: GET /login?scope=repository%3Atest%2Fnginx%3Apull&service=trow_registry | |
| [2021-06-12T06:07:56Z TRACE rocket::router] All matches: [Route { name: Some("login"), method: Get, base: Origin { source: None, path: "/", query: None, segment_count: [uninitialized storage] }, uri: Origin { source: None, path: "/login", query: None, segment_count: [uninitialized storage] }, rank: -4, format: None, metadata: Metadata { path_segments: [RouteSegment { string: "login", kind: Static, name: "login", index: Some(0), _part: PhantomData }], query_segments: None, fully_dynamic_query: true } }] | |
| [2021-06-12T06:07:56Z INFO rocket::rocket] Matched: GET /login (login) | |
| [2021-06-12T06:07:56Z INFO rocket::rocket] Outcome: Failure | |
| [2021-06-12T06:07:56Z WARN rocket::rocket] Responding with 401 Unauthorized catcher. | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.append_raw( "www-authenticate", [66, 101, 97, 114, 101, 114, 32, 114, 101, 97, 108, 109, 61, 34, 104, 116, 116, 112, 58, 47, 47, 49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48, 47, 108, 111, 103, 105, 110, 34, 44, 115, 101, 114, 118, 105, 99, 101, 61, 34, 116, 114, 111, 119, 95, 114, 101, 103, 105, 115, 116, 114, 121, 34, 44, 115, 99, 111, 112, 101, 61, 34, 112, 117, 115, 104, 47, 112, 117, 108, 108, 34] ) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.append_raw( "Content-Type", [97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 106, 115, 111, 110] ) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.append_raw( "Server", [82, 111, 99, 107, 101, 116] ) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.append_raw( "Docker-Distribution-API-Version", [114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48] ) | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.set( "Content-Length", ContentLength(0) ) | |
| [2021-06-12T06:07:56Z DEBUG hyper::server::response] writing head: Http11 Unauthorized | |
| [2021-06-12T06:07:56Z TRACE hyper::header] Headers.set( "Date", Date(HttpDate(Tm { tm_sec: 56, tm_min: 7, tm_hour: 6, tm_mday: 12, tm_mon: 5, tm_year: 121, tm_wday: 6, tm_yday: 162, tm_isdst: 0, tm_utcoff: 0, tm_nsec: 156894140 })) ) | |
| [2021-06-12T06:07:56Z DEBUG hyper::server::response] headers [ | |
| Headers { Connection: close | |
| , www-authenticate: Bearer realm="http://10.99.246.200:8000/login",service="trow_registry",scope="push/pull" | |
| , Content-Type: application/json | |
| , Server: Rocket | |
| , Docker-Distribution-API-Version: registry/2.0 | |
| , Content-Length: 0 | |
| , Date: Sat, 12 Jun 2021 06:07:56 GMT | |
| , }] | |
| [2021-06-12T06:07:56Z TRACE hyper::server::response] ending | |
| [2021-06-12T06:07:56Z INFO rocket::rocket] Response succeeded. | |
| [2021-06-12T06:07:56Z DEBUG hyper::server] keep_alive = false for 10.244.0.0:7851 | |
| [2021-06-12T06:07:56Z DEBUG hyper::server] keep_alive loop ending for 10.244.0.0:7851 |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Command | |
| $ sudo crictl --debug pull --creds test:test 10.99.246.200:8000/test/nginx:alpine | |
| DEBU[0000] get image connection | |
| DEBU[0000] connect using endpoint 'unix:///var/run/crio/crio.sock' with '2s' timeout | |
| DEBU[0000] connected successfully using endpoint: unix:///var/run/crio/crio.sock | |
| DEBU[0000] PullImageRequest: &PullImageRequest{Image:&ImageSpec{Image:10.99.246.200:8000/test/nginx:alpine,Annotations:map[string]string{},},Auth:&AuthConfig{Username:test,Password:test,Auth:,ServerAddress:,IdentityToken:,RegistryToken:,},SandboxConfig:nil,} | |
| DEBU[0000] PullImageResponse: &PullImageResponse{ImageRef:10.99.246.200:8000/test/nginx@sha256:6243b2a72ee9fd917c350149a365ee0bb7fdabf6175ecaf0d404ad7a316fa7ee,} | |
| Image is up to date for 10.99.246.200:8000/test/nginx@sha256:6243b2a72ee9fd917c350149a365ee0bb7fdabf6175ecaf0d404ad7a316fa7ee | |
| Logs | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] Incoming stream | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] get_buf [] | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] read_into_buf buf[0..4096] | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] get_buf [u8; 4096][0..227] | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] try_parse([22, 3, 1, 0, 222, 1, 0, 0, 218, 3, 3, 18, 176, 230, 34, 18, 125, 160, 155, 116, 221, 109, 169, 50, 49, 254, 196, 119, 216, 116, 101, 214, 201, 57, 156, 21, 46, 254, 120, 156, 116, 175, 131, 32, 23, 238, 14, 184, 135, 253, 156, 7, 93, 101, 44, 30, 163, 223, 181, 38, 242, 215, 123, 63, 39, 10, 118, 69, 209, 204, 166, 164, 105, 0, 72, 46, 0, 22, 192, 44, 192, 48, 192, 43, 192, 47, 192, 10, 192, 9, 192, 20, 192, 19, 19, 3, 19, 1, 19, 2, 1, 0, 0, 123, 0, 5, 0, 5, 1, 0, 0, 0, 0, 0, 10, 0, 10, 0, 8, 0, 29, 0, 23, 0, 24, 0, 25, 0, 11, 0, 2, 1, 0, 0, 13, 0, 26, 0, 24, 8, 4, 4, 3, 8, 7, 8, 5, 8, 6, 4, 1, 5, 1, 6, 1, 5, 3, 6, 3, 2, 1, 2, 3, 255, 1, 0, 1, 0, 0, 18, 0, 0, 0, 43, 0, 9, 8, 3, 4, 3, 3, 3, 2, 3, 1, 0, 51, 0, 38, 0, 36, 0, 29, 0, 32, 187, 97, 206, 189, 32, 171, 26, 206, 126, 244, 59, 7, 114, 251, 93, 90, 41, 106, 208, 164, 194, 133, 245, 49, 189, 251, 108, 150, 82, 69, 209, 77]) | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] Request.try_parse([Header; 100], [u8; 227]) | |
| [2021-06-12T06:03:08Z INFO hyper::server] request error = Header | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] keep_alive loop ending for 10.244.0.0:19838 | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] Incoming stream | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] get_buf [] | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] read_into_buf buf[0..4096] | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] get_buf [u8; 4096][0..194] | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] try_parse([71, 69, 84, 32, 47, 118, 50, 47, 32, 72, 84, 84, 80, 47, 49, 46, 49, 13, 10, 72, 111, 115, 116, 58, 32, 49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48, 13, 10, 85, 115, 101, 114, 45, 65, 103, 101, 110, 116, 58, 32, 99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52, 13, 10, 68, 111, 99, 107, 101, 114, 45, 68, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 45, 65, 112, 105, 45, 86, 101, 114, 115, 105, 111, 110, 58, 32, 114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48, 13, 10, 65, 99, 99, 101, 112, 116, 45, 69, 110, 99, 111, 100, 105, 110, 103, 58, 32, 103, 122, 105, 112, 13, 10, 67, 111, 110, 110, 101, 99, 116, 105, 111, 110, 58, 32, 99, 108, 111, 115, 101, 13, 10, 13, 10]) | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] Request.try_parse([Header; 100], [u8; 194]) | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] Request.try_parse Complete(194) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Host"=[49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "User-Agent"=[99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Docker-Distribution-Api-Version"=[114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Accept-Encoding"=[103, 122, 105, 112] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Connection"=[99, 108, 111, 115, 101] | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::request] Request Line: Get AbsolutePath("/v2/") Http11 | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::request] Headers { Host: 10.99.246.200:8000 | |
| , User-Agent: cri-o/1.19.1 go/go1.15.2 os/linux arch/arm64 | |
| , Docker-Distribution-Api-Version: registry/2.0 | |
| , Accept-Encoding: gzip | |
| , Connection: close | |
| , } | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.set( "Connection", Connection([Close]) ) | |
| [2021-06-12T06:03:08Z TRACE rocket::data::data] Data::new(EmptyReader) | |
| [2021-06-12T06:03:08Z TRACE rocket::data::data] Filled peek buf with 0 bytes. | |
| [2021-06-12T06:03:08Z TRACE rocket::data::data] Peek bytes: 0/512 bytes. | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] GET /v2/: | |
| [2021-06-12T06:03:08Z TRACE rocket::router] Routing the request: GET /v2/ | |
| [2021-06-12T06:03:08Z TRACE rocket::router] All matches: [Route { name: Some("get_v2root"), method: Get, base: Origin { source: None, path: "/", query: None, segment_count: [uninitialized storage] }, uri: Origin { source: None, path: "/v2", query: None, segment_count: [uninitialized storage] }, rank: -4, format: None, metadata: Metadata { path_segments: [RouteSegment { string: "v2", kind: Static, name: "v2", index: Some(0), _part: PhantomData }], query_segments: None, fully_dynamic_query: true } }] | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] Matched: GET /v2 (get_v2root) | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] Outcome: Failure | |
| [2021-06-12T06:03:08Z WARN rocket::rocket] Responding with 401 Unauthorized catcher. | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "www-authenticate", [66, 101, 97, 114, 101, 114, 32, 114, 101, 97, 108, 109, 61, 34, 104, 116, 116, 112, 58, 47, 47, 49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48, 47, 108, 111, 103, 105, 110, 34, 44, 115, 101, 114, 118, 105, 99, 101, 61, 34, 116, 114, 111, 119, 95, 114, 101, 103, 105, 115, 116, 114, 121, 34, 44, 115, 99, 111, 112, 101, 61, 34, 112, 117, 115, 104, 47, 112, 117, 108, 108, 34] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Content-Type", [97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 106, 115, 111, 110] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Server", [82, 111, 99, 107, 101, 116] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Docker-Distribution-API-Version", [114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.set( "Content-Length", ContentLength(0) ) | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::response] writing head: Http11 Unauthorized | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.set( "Date", Date(HttpDate(Tm { tm_sec: 8, tm_min: 3, tm_hour: 6, tm_mday: 12, tm_mon: 5, tm_year: 121, tm_wday: 6, tm_yday: 162, tm_isdst: 0, tm_utcoff: 0, tm_nsec: 179857285 })) ) | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::response] headers [ | |
| Headers { Connection: close | |
| , www-authenticate: Bearer realm="http://10.99.246.200:8000/login",service="trow_registry",scope="push/pull" | |
| , Content-Type: application/json | |
| , Server: Rocket | |
| , Docker-Distribution-API-Version: registry/2.0 | |
| , Content-Length: 0 | |
| , Date: Sat, 12 Jun 2021 06:03:08 GMT | |
| , }] | |
| [2021-06-12T06:03:08Z TRACE hyper::server::response] ending | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] Response succeeded. | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] keep_alive = false for 10.244.0.0:33077 | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] keep_alive loop ending for 10.244.0.0:33077 | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] Incoming stream | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] get_buf [] | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] read_into_buf buf[0..4096] | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] get_buf [u8; 4096][0..258] | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] try_parse([71, 69, 84, 32, 47, 108, 111, 103, 105, 110, 63, 97, 99, 99, 111, 117, 110, 116, 61, 116, 101, 115, 116, 38, 115, 99, 111, 112, 101, 61, 114, 101, 112, 111, 115, 105, 116, 111, 114, 121, 37, 51, 65, 116, 101, 115, 116, 37, 50, 70, 110, 103, 105, 110, 120, 37, 51, 65, 112, 117, 108, 108, 38, 115, 101, 114, 118, 105, 99, 101, 61, 116, 114, 111, 119, 95, 114, 101, 103, 105, 115, 116, 114, 121, 32, 72, 84, 84, 80, 47, 49, 46, 49, 13, 10, 72, 111, 115, 116, 58, 32, 49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48, 13, 10, 85, 115, 101, 114, 45, 65, 103, 101, 110, 116, 58, 32, 99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52, 13, 10, 65, 117, 116, 104, 111, 114, 105, 122, 97, 116, 105, 111, 110, 58, 32, 66, 97, 115, 105, 99, 32, 100, 71, 86, 122, 100, 68, 112, 48, 90, 88, 78, 48, 13, 10, 65, 99, 99, 101, 112, 116, 45, 69, 110, 99, 111, 100, 105, 110, 103, 58, 32, 103, 122, 105, 112, 13, 10, 67, 111, 110, 110, 101, 99, 116, 105, 111, 110, 58, 32, 99, 108, 111, 115, 101, 13, 10, 13, 10]) | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] Request.try_parse([Header; 100], [u8; 258]) | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] Request.try_parse Complete(258) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Host"=[49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "User-Agent"=[99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Authorization"=[66, 97, 115, 105, 99, 32, 100, 71, 86, 122, 100, 68, 112, 48, 90, 88, 78, 48] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Accept-Encoding"=[103, 122, 105, 112] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Connection"=[99, 108, 111, 115, 101] | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::request] Request Line: Get AbsolutePath("/login?account=test&scope=repository%3Atest%2Fnginx%3Apull&service=trow_registry") Http11 | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::request] Headers { Host: 10.99.246.200:8000 | |
| , User-Agent: cri-o/1.19.1 go/go1.15.2 os/linux arch/arm64 | |
| , Authorization: Basic dGVzdDp0ZXN0 | |
| , Accept-Encoding: gzip | |
| , Connection: close | |
| , } | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.set( "Connection", Connection([Close]) ) | |
| [2021-06-12T06:03:08Z TRACE rocket::data::data] Data::new(EmptyReader) | |
| [2021-06-12T06:03:08Z TRACE rocket::data::data] Filled peek buf with 0 bytes. | |
| [2021-06-12T06:03:08Z TRACE rocket::data::data] Peek bytes: 0/512 bytes. | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] GET /login?account=test&scope=repository%3Atest%2Fnginx%3Apull&service=trow_registry: | |
| [2021-06-12T06:03:08Z TRACE rocket::router] Routing the request: GET /login?account=test&scope=repository%3Atest%2Fnginx%3Apull&service=trow_registry | |
| [2021-06-12T06:03:08Z TRACE rocket::router] All matches: [Route { name: Some("login"), method: Get, base: Origin { source: None, path: "/", query: None, segment_count: [uninitialized storage] }, uri: Origin { source: None, path: "/login", query: None, segment_count: [uninitialized storage] }, rank: -4, format: None, metadata: Metadata { path_segments: [RouteSegment { string: "login", kind: Static, name: "login", index: Some(0), _part: PhantomData }], query_segments: None, fully_dynamic_query: true } }] | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] Matched: GET /login (login) | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] Outcome: Success | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Content-Type", [97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 106, 115, 111, 110] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Server", [82, 111, 99, 107, 101, 116] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Docker-Distribution-API-Version", [114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.set( "Content-Length", ContentLength(330) ) | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::response] writing head: Http11 Ok | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.set( "Date", Date(HttpDate(Tm { tm_sec: 8, tm_min: 3, tm_hour: 6, tm_mday: 12, tm_mon: 5, tm_year: 121, tm_wday: 6, tm_yday: 162, tm_isdst: 0, tm_utcoff: 0, tm_nsec: 225788145 })) ) | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::response] headers [ | |
| Headers { Connection: close | |
| , Content-Type: application/json | |
| , Server: Rocket | |
| , Docker-Distribution-API-Version: registry/2.0 | |
| , Content-Length: 330 | |
| , Date: Sat, 12 Jun 2021 06:03:08 GMT | |
| , }] | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::response] write 330 bytes | |
| [2021-06-12T06:03:08Z TRACE hyper::server::response] ending | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] Response succeeded. | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] keep_alive = false for 10.244.0.0:59820 | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] keep_alive loop ending for 10.244.0.0:59820 | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] Incoming stream | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] get_buf [] | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] read_into_buf buf[0..4096] | |
| [2021-06-12T06:03:08Z TRACE hyper::buffer] get_buf [u8; 4096][0..921] | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] try_parse([71, 69, 84, 32, 47, 118, 50, 47, 116, 101, 115, 116, 47, 110, 103, 105, 110, 120, 47, 109, 97, 110, 105, 102, 101, 115, 116, 115, 47, 97, 108, 112, 105, 110, 101, 32, 72, 84, 84, 80, 47, 49, 46, 49, 13, 10, 72, 111, 115, 116, 58, 32, 49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48, 13, 10, 85, 115, 101, 114, 45, 65, 103, 101, 110, 116, 58, 32, 99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52, 13, 10, 65, 99, 99, 101, 112, 116, 58, 32, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 111, 99, 105, 46, 105, 109, 97, 103, 101, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 118, 49, 43, 106, 115, 111, 110, 13, 10, 65, 99, 99, 101, 112, 116, 58, 32, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 100, 111, 99, 107, 101, 114, 46, 100, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 118, 50, 43, 106, 115, 111, 110, 13, 10, 65, 99, 99, 101, 112, 116, 58, 32, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 100, 111, 99, 107, 101, 114, 46, 100, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 118, 49, 43, 112, 114, 101, 116, 116, 121, 106, 119, 115, 13, 10, 65, 99, 99, 101, 112, 116, 58, 32, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 100, 111, 99, 107, 101, 114, 46, 100, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 118, 49, 43, 106, 115, 111, 110, 13, 10, 65, 99, 99, 101, 112, 116, 58, 32, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 100, 111, 99, 107, 101, 114, 46, 100, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 108, 105, 115, 116, 46, 118, 50, 43, 106, 115, 111, 110, 13, 10, 65, 99, 99, 101, 112, 116, 58, 32, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 111, 99, 105, 46, 105, 109, 97, 103, 101, 46, 105, 110, 100, 101, 120, 46, 118, 49, 43, 106, 115, 111, 110, 13, 10, 65, 117, 116, 104, 111, 114, 105, 122, 97, 116, 105, 111, 110, 58, 32, 66, 101, 97, 114, 101, 114, 32, 101, 121, 74, 104, 98, 71, 99, 105, 79, 105, 74, 73, 85, 122, 73, 49, 78, 105, 73, 115, 73, 110, 82, 53, 99, 67, 73, 54, 73, 107, 112, 88, 86, 67, 74, 57, 46, 101, 121, 74, 104, 100, 87, 81, 105, 79, 105, 74, 85, 99, 109, 57, 51, 73, 70, 74, 108, 90, 50, 108, 122, 100, 72, 74, 53, 73, 105, 119, 105, 90, 88, 104, 119, 73, 106, 111, 120, 78, 106, 73, 122, 78, 68, 103, 120, 77, 122, 103, 52, 76, 67, 74, 112, 89, 88, 81, 105, 79, 106, 69, 50, 77, 106, 77, 48, 78, 122, 99, 51, 79, 68, 103, 115, 73, 109, 108, 122, 99, 121, 73, 54, 73, 110, 82, 121, 98, 51, 99, 116, 99, 51, 90, 106, 76, 110, 82, 121, 98, 51, 99, 117, 99, 51, 90, 106, 76, 109, 78, 115, 100, 88, 78, 48, 90, 88, 73, 117, 98, 71, 57, 106, 89, 87, 119, 54, 79, 68, 65, 119, 77, 67, 73, 115, 73, 109, 112, 48, 97, 83, 73, 54, 73, 106, 89, 119, 77, 68, 100, 108, 78, 122, 69, 122, 76, 84, 89, 121, 89, 106, 77, 116, 78, 71, 89, 122, 79, 67, 49, 105, 89, 122, 66, 104, 76, 84, 69, 52, 77, 109, 69, 49, 77, 84, 70, 105, 77, 122, 77, 122, 89, 83, 73, 115, 73, 109, 53, 105, 90, 105, 73, 54, 77, 84, 89, 121, 77, 122, 81, 51, 78, 122, 99, 52, 79, 67, 119, 105, 99, 51, 86, 105, 73, 106, 111, 105, 100, 71, 86, 122, 100, 67, 74, 57, 46, 122, 53, 56, 98, 114, 84, 83, 67, 119, 90, 70, 109, 115, 107, 100, 109, 68, 78, 100, 45, 68, 122, 84, 68, 76, 112, 98, 109, 100, 109, 68, 83, 73, 99, 73, 51, 67, 79, 74, 78, 118, 107, 115, 13, 10, 68, 111, 99, 107, 101, 114, 45, 68, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 45, 65, 112, 105, 45, 86, 101, 114, 115, 105, 111, 110, 58, 32, 114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48, 13, 10, 65, 99, 99, 101, 112, 116, 45, 69, 110, 99, 111, 100, 105, 110, 103, 58, 32, 103, 122, 105, 112, 13, 10, 67, 111, 110, 110, 101, 99, 116, 105, 111, 110, 58, 32, 99, 108, 111, 115, 101, 13, 10, 13, 10]) | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] Request.try_parse([Header; 100], [u8; 921]) | |
| [2021-06-12T06:03:08Z TRACE hyper::http::h1] Request.try_parse Complete(921) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Host"=[49, 48, 46, 57, 57, 46, 50, 52, 54, 46, 50, 48, 48, 58, 56, 48, 48, 48] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "User-Agent"=[99, 114, 105, 45, 111, 47, 49, 46, 49, 57, 46, 49, 32, 103, 111, 47, 103, 111, 49, 46, 49, 53, 46, 50, 32, 111, 115, 47, 108, 105, 110, 117, 120, 32, 97, 114, 99, 104, 47, 97, 114, 109, 54, 52] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Accept"=[97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 111, 99, 105, 46, 105, 109, 97, 103, 101, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 118, 49, 43, 106, 115, 111, 110] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Accept"=[97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 100, 111, 99, 107, 101, 114, 46, 100, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 118, 50, 43, 106, 115, 111, 110] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Accept"=[97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 100, 111, 99, 107, 101, 114, 46, 100, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 118, 49, 43, 112, 114, 101, 116, 116, 121, 106, 119, 115] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Accept"=[97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 100, 111, 99, 107, 101, 114, 46, 100, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 118, 49, 43, 106, 115, 111, 110] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Accept"=[97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 100, 111, 99, 107, 101, 114, 46, 100, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 108, 105, 115, 116, 46, 118, 50, 43, 106, 115, 111, 110] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Accept"=[97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 111, 99, 105, 46, 105, 109, 97, 103, 101, 46, 105, 110, 100, 101, 120, 46, 118, 49, 43, 106, 115, 111, 110] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Authorization"=[66, 101, 97, 114, 101, 114, 32, 101, 121, 74, 104, 98, 71, 99, 105, 79, 105, 74, 73, 85, 122, 73, 49, 78, 105, 73, 115, 73, 110, 82, 53, 99, 67, 73, 54, 73, 107, 112, 88, 86, 67, 74, 57, 46, 101, 121, 74, 104, 100, 87, 81, 105, 79, 105, 74, 85, 99, 109, 57, 51, 73, 70, 74, 108, 90, 50, 108, 122, 100, 72, 74, 53, 73, 105, 119, 105, 90, 88, 104, 119, 73, 106, 111, 120, 78, 106, 73, 122, 78, 68, 103, 120, 77, 122, 103, 52, 76, 67, 74, 112, 89, 88, 81, 105, 79, 106, 69, 50, 77, 106, 77, 48, 78, 122, 99, 51, 79, 68, 103, 115, 73, 109, 108, 122, 99, 121, 73, 54, 73, 110, 82, 121, 98, 51, 99, 116, 99, 51, 90, 106, 76, 110, 82, 121, 98, 51, 99, 117, 99, 51, 90, 106, 76, 109, 78, 115, 100, 88, 78, 48, 90, 88, 73, 117, 98, 71, 57, 106, 89, 87, 119, 54, 79, 68, 65, 119, 77, 67, 73, 115, 73, 109, 112, 48, 97, 83, 73, 54, 73, 106, 89, 119, 77, 68, 100, 108, 78, 122, 69, 122, 76, 84, 89, 121, 89, 106, 77, 116, 78, 71, 89, 122, 79, 67, 49, 105, 89, 122, 66, 104, 76, 84, 69, 52, 77, 109, 69, 49, 77, 84, 70, 105, 77, 122, 77, 122, 89, 83, 73, 115, 73, 109, 53, 105, 90, 105, 73, 54, 77, 84, 89, 121, 77, 122, 81, 51, 78, 122, 99, 52, 79, 67, 119, 105, 99, 51, 86, 105, 73, 106, 111, 105, 100, 71, 86, 122, 100, 67, 74, 57, 46, 122, 53, 56, 98, 114, 84, 83, 67, 119, 90, 70, 109, 115, 107, 100, 109, 68, 78, 100, 45, 68, 122, 84, 68, 76, 112, 98, 109, 100, 109, 68, 83, 73, 99, 73, 51, 67, 79, 74, 78, 118, 107, 115] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Docker-Distribution-Api-Version"=[114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Accept-Encoding"=[103, 122, 105, 112] | |
| [2021-06-12T06:03:08Z TRACE hyper::header] raw header: "Connection"=[99, 108, 111, 115, 101] | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::request] Request Line: Get AbsolutePath("/v2/test/nginx/manifests/alpine") Http11 | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::request] Headers { Host: 10.99.246.200:8000 | |
| , User-Agent: cri-o/1.19.1 go/go1.15.2 os/linux arch/arm64 | |
| , Accept: application/vnd.oci.image.manifest.v1+json | |
| Accept: application/vnd.docker.distribution.manifest.v2+json | |
| Accept: application/vnd.docker.distribution.manifest.v1+prettyjws | |
| Accept: application/vnd.docker.distribution.manifest.v1+json | |
| Accept: application/vnd.docker.distribution.manifest.list.v2+json | |
| Accept: application/vnd.oci.image.index.v1+json | |
| , Authorization: Bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJUcm93IFJlZ2lzdHJ5IiwiZXhwIjoxNjIzNDgxMzg4LCJpYXQiOjE2MjM0Nzc3ODgsImlzcyI6InRyb3ctc3ZjLnRyb3cuc3ZjLmNsdXN0ZXIubG9jYWw6ODAwMCIsImp0aSI6IjYwMDdlNzEzLTYyYjMtNGYzOC1iYzBhLTE4MmE1MTFiMzMzYSIsIm5iZiI6MTYyMzQ3Nzc4OCwic3ViIjoidGVzdCJ9.z58brTSCwZFmskdmDNd-DzTDLpbmdmDSIcI3COJNvks | |
| , Docker-Distribution-Api-Version: registry/2.0 | |
| , Accept-Encoding: gzip | |
| , Connection: close | |
| , } | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.set( "Connection", Connection([Close]) ) | |
| [2021-06-12T06:03:08Z TRACE rocket::data::data] Data::new(EmptyReader) | |
| [2021-06-12T06:03:08Z TRACE rocket::data::data] Filled peek buf with 0 bytes. | |
| [2021-06-12T06:03:08Z TRACE rocket::data::data] Peek bytes: 0/512 bytes. | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] GET /v2/test/nginx/manifests/alpine application/vnd.oci.image.manifest.v1+json: | |
| [2021-06-12T06:03:08Z TRACE rocket::router] Routing the request: GET /v2/test/nginx/manifests/alpine application/vnd.oci.image.manifest.v1+json | |
| [2021-06-12T06:03:08Z TRACE rocket::router] All matches: [Route { name: Some("get_manifest_2level"), method: Get, base: Origin { source: None, path: "/", query: None, segment_count: 0 }, uri: Origin { source: None, path: "/v2/<user>/<repo>/manifests/<reference>", query: None, segment_count: [uninitialized storage] }, rank: -1, format: None, metadata: Metadata { path_segments: [RouteSegment { string: "v2", kind: Static, name: "v2", index: Some(0), _part: PhantomData }, RouteSegment { string: "<user>", kind: Single, name: "user", index: Some(1), _part: PhantomData }, RouteSegment { string: "<repo>", kind: Single, name: "repo", index: Some(2), _part: PhantomData }, RouteSegment { string: "manifests", kind: Static, name: "manifests", index: Some(3), _part: PhantomData }, RouteSegment { string: "<reference>", kind: Single, name: "reference", index: Some(4), _part: PhantomData }], query_segments: None, fully_dynamic_query: true } }] | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] Matched: GET /v2/<user>/<repo>/manifests/<reference> (get_manifest_2level) | |
| [2021-06-12T06:03:08Z TRACE mio::poll] registering with poller | |
| [2021-06-12T06:03:08Z INFO trow::client_interface] Getting read location for test/nginx with ref alpine | |
| [2021-06-12T06:03:08Z DEBUG trow::client_interface] Connecting to https://127.0.0.1:51000 | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; idle | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; connecting | |
| [2021-06-12T06:03:08Z TRACE hyper::client::connect::http] Http::connect; scheme=Some("https"), host=Some("127.0.0.1"), port=Some(Port(51000)) | |
| [2021-06-12T06:03:08Z DEBUG hyper::client::connect::http] connecting to 127.0.0.1:51000 | |
| [2021-06-12T06:03:08Z TRACE mio::poll] registering with poller | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; not ready | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; connecting | |
| [2021-06-12T06:03:08Z DEBUG hyper::client::connect::http] connected to 127.0.0.1:51000 | |
| [2021-06-12T06:03:08Z TRACE hyper::client::conn] client handshake HTTP/2 | |
| [2021-06-12T06:03:08Z DEBUG h2::client] binding client connection | |
| [2021-06-12T06:03:08Z TRACE mio::poll] registering with poller | |
| [2021-06-12T06:03:08Z DEBUG h2::client] client connection bound | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::frame::settings] encoding SETTINGS; len=18 | |
| [2021-06-12T06:03:08Z TRACE h2::frame::settings] encoding setting; val=EnablePush(0) | |
| [2021-06-12T06:03:08Z TRACE h2::frame::settings] encoding setting; val=InitialWindowSize(2097152) | |
| [2021-06-12T06:03:08Z TRACE h2::frame::settings] encoding setting; val=MaxFrameSize(16384) | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] encoded settings rem=27 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=65535; old=0; new=65535 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=65535; old=0; new=65535 | |
| [2021-06-12T06:03:08Z TRACE h2::server] server_handshake; io=hyper::common::io::rewind::Rewind<tonic::transport::service::io::ServerIo> | |
| [2021-06-12T06:03:08Z TRACE h2::server] -> server_handshake | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] Prioritize::new; flow=FlowControl { window_size: Window(65535), available: Window(65535) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::proto::connection] Connection; peer=Client | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] set_target_connection_window; target=5242880; available=65535, reserved=0 | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::frame::settings] encoding SETTINGS; len=12 | |
| [2021-06-12T06:03:08Z TRACE h2::frame::settings] encoding setting; val=InitialWindowSize(1048576) | |
| [2021-06-12T06:03:08Z TRACE h2::frame::settings] encoding setting; val=MaxFrameSize(16384) | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] encoded settings rem=21 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; connected | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; not ready | |
| [2021-06-12T06:03:08Z TRACE h2::server] flush | |
| [2021-06-12T06:03:08Z TRACE h2::server] <- server_handshake | |
| [2021-06-12T06:03:08Z TRACE h2::server] -> server_handshake | |
| [2021-06-12T06:03:08Z TRACE h2::server] state=Handshaking::Flushing(_) | |
| [2021-06-12T06:03:08Z TRACE h2::server] -> flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] queued_data_frame=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::server] <- flush | |
| [2021-06-12T06:03:08Z TRACE h2::server] flush.poll=Ready | |
| [2021-06-12T06:03:08Z TRACE h2::server] read_preface | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE h2::server] -- flush | |
| [2021-06-12T06:03:08Z TRACE h2::server] -> read_preface | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::server] <- read_preface | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=65535; old=0; new=65535 | |
| [2021-06-12T06:03:08Z TRACE want] signal: Want | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=65535; old=0; new=65535 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] Prioritize::new; flow=FlowControl { window_size: Window(65535), available: Window(65535) } | |
| [2021-06-12T06:03:08Z TRACE want] signal found waiting giver, notifying | |
| [2021-06-12T06:03:08Z DEBUG h2::proto::connection] Connection; peer=Server | |
| [2021-06-12T06:03:08Z TRACE h2::server] connection established! | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; connected | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] set_target_connection_window; target=1048576; available=65535, reserved=0 | |
| [2021-06-12T06:03:08Z TRACE h2::server] <- server_handshake | |
| [2021-06-12T06:03:08Z TRACE h2::server] -- server_handshake | |
| [2021-06-12T06:03:08Z TRACE want] poll_want: taker wants! | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; ready | |
| [2021-06-12T06:03:08Z TRACE h2::server] -- read_preface | |
| [2021-06-12T06:03:08Z TRACE h2::server] -- server_handshake | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z DEBUG trow::client_interface] Connected to https://127.0.0.1:51000 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 } | |
| [2021-06-12T06:03:08Z TRACE h2::frame::window_update] encoding WINDOW_UPDATE; id=StreamId(0) | |
| [2021-06-12T06:03:08Z TRACE tower_buffer::service] sending request to buffer worker | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] encoded window_update rem=40 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=5177345; old=65535; new=5242880 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] poll_complete | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 } | |
| [2021-06-12T06:03:08Z TRACE h2::frame::window_update] encoding WINDOW_UPDATE; id=StreamId(0) | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] encoded window_update rem=13 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE tower_buffer::worker] worker polling for next message | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=983041; old=65535; new=1048576 | |
| [2021-06-12T06:03:08Z TRACE tower_buffer::worker] processing new request | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE tower_buffer::worker] resumed=false worker received request; waiting for service readiness | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] queued_data_frame=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] poll_complete | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] queued_data_frame=false | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; connected | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE want] poll_want: taker wants! | |
| [2021-06-12T06:03:08Z TRACE tonic::transport::service::reconnect] poll_ready; ready | |
| [2021-06-12T06:03:08Z DEBUG tower_buffer::worker] service.ready=true processing request | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE tower_buffer::worker] returning response future | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE tower_buffer::worker] worker polling for next message | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=2097152; old=0; new=2097152 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=65535; old=0; new=65535 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::send] send_headers; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }; init_window=65535 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] Prioritize::queue_frame; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=27 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_send stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=27 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 27B | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> first entry | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Settings | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=1 effective=1 curr=0 | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv SETTINGS frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] requested=1 additional=1 buffered=0 window=65535 conn=65535 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assigning capacity=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] assigned capacity to stream; available=1; buffered=0; id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Settings { flags: (0x1: ACK) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] notifying task | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] available=1 requested=1 buffered=0 has_unavailable=true | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Settings { flags: (0x1: ACK) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::frame::settings] encoding SETTINGS; len=0 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] encoded settings rem=9 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE hyper::proto::h2] send body chunk: 25 bytes, eos=false | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] send_data; sz=25 requested=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::settings] ACK sent; applying settings | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> send_data | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=13 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] buffered=25 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=13 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 13B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=WindowUpdate | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_assign_capacity | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] requested=25 additional=24 buffered=25 window=65535 conn=65534 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assigning capacity=24 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv WINDOW_UPDATE frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] assigned capacity to stream; available=25; buffered=25; id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=5177345; old=65535; new=5242880 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] available=25 requested=25 buffered=25 has_unavailable=true | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> already queued | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assign_connection_capacity; inc=5177345 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] available=25 buffered=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] Prioritize::queue_frame; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_send stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> already queued | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- send_data | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- send_data | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Open { local: Streaming, remote: AwaitingHeaders } }; is_closed=false; pending_send_empty=false; buffered_send_data=25; num_recv=0; num_send=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=1 effective=26 curr=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] poll_complete | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] queued_data_frame=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] requested=26 additional=1 buffered=25 window=65535 conn=65510 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assigning capacity=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] assigned capacity to stream; available=26; buffered=25; id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] notifying task | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] available=26 requested=26 buffered=25 has_unavailable=true | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> already queued | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=0 effective=25 curr=26 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assign_connection_capacity; inc=1 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE hyper::proto::h2] send body eos | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] send_data; sz=0 requested=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> send_data | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] buffered=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::state] send_close: Open => HalfClosedLocal(AwaitingHeaders) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=0 effective=25 curr=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] available=25 buffered=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] Prioritize::queue_frame; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_send stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> already queued | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- send_data | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- send_data | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedLocal(AwaitingHeaders) }; is_closed=false; pending_send_empty=false; buffered_send_data=25; num_recv=0; num_send=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: HalfClosedLocal(AwaitingHeaders) }, is_counted: true, ref_count: 2, next_pending_send: None, is_pending_send: true, send_flow: FlowControl { window_size: Window(65535), available: Window(25) }, requested_send_capacity: 25, buffered_send_data: 25, send_task: Some(Waker { data: 0xffff58024b80, vtable: 0xaaaac1b838e8 }), pending_send: Deque { indices: Some(Indices { head: 0, tail: 2 }) }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: true, next_open: None, is_pending_open: false, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(2097152), available: Window(2097152) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData }, content_length: Omitted } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedLocal(AwaitingHeaders) }; is_closed=false; pending_send_empty=false; buffered_send_data=25; num_recv=0; num_send=1 | |
| [2021-06-12T06:03:08Z TRACE want] signal: Want | |
| [2021-06-12T06:03:08Z TRACE want] signal: Want | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=21 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=21 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 21B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Settings | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv SETTINGS frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Settings { flags: (0x1: ACK) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Settings { flags: (0x1: ACK) } | |
| [2021-06-12T06:03:08Z TRACE h2::frame::settings] encoding SETTINGS; len=0 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] encoded settings rem=9 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::settings] ACK sent; applying settings | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] recv_stream_window_update; stream.id=StreamId(1) stream.state=State { inner: HalfClosedLocal(AwaitingHeaders) } inc=983041 flow=FlowControl { window_size: Window(65535), available: Window(25) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> recv_stream_window_update | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=983041; old=65535; new=1048576 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] requested=25 additional=0 buffered=25 window=1048576 conn=65510 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- recv_stream_window_update | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- recv_stream_window_update | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=13 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=13 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 13B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=WindowUpdate | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv WINDOW_UPDATE frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=983041; old=65535; new=1048576 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assign_connection_capacity; inc=983041 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=9 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=9 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 9B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Settings | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Settings { flags: (0x1: ACK) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv SETTINGS frame=Settings { flags: (0x1: ACK) } | |
| [2021-06-12T06:03:08Z DEBUG h2::proto::settings] received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] update_initial_window_size; new=2097152; old=2097152 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] poll_complete | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] popped; stream.id=StreamId(1) stream.state=State { inner: HalfClosedLocal(AwaitingHeaders) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] is_pending_reset=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> first entry | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedLocal(AwaitingHeaders) }; is_closed=false; pending_send_empty=false; buffered_send_data=25; num_recv=0; num_send=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] writing frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] -> hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] encoding at pos=18 | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] <- hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] -- hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] popped; stream.id=StreamId(1) stream.state=State { inner: HalfClosedLocal(AwaitingHeaders) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] is_pending_reset=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] data frame sz=25 eos=false window=25 available=25 requested=25 buffered=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] sending data frame len=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=25; window=1048576; available=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=25; window=1048576; available=1048576 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame; frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> first entry | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedLocal(AwaitingHeaders) }; is_closed=false; pending_send_empty=false; buffered_send_data=0; num_recv=0; num_send=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] writing frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reclaimed frame=Data { stream_id: StreamId(1) } sz=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] popped; stream.id=StreamId(1) stream.state=State { inner: HalfClosedLocal(AwaitingHeaders) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] is_pending_reset=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] data frame sz=0 eos=true window=0 available=0 requested=0 buffered=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] sending data frame len=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=0; window=1048551; available=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=0; window=1048551; available=1048551 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame; frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedLocal(AwaitingHeaders) }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] writing frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reclaimed frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) } sz=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] queued_data_frame=false | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=9 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=9 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 9B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Settings | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Settings { flags: (0x1: ACK) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv SETTINGS frame=Settings { flags: (0x1: ACK) } | |
| [2021-06-12T06:03:08Z DEBUG h2::proto::settings] received settings ACK; applying Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384 } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] update_initial_window_size; new=1048576; old=1048576 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=79 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=79 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 79B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Headers | |
| [2021-06-12T06:03:08Z TRACE h2::frame::headers] loading headers; flags=(0x4: END_HEADERS) | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] -> hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=70 kind=Indexed | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=69 kind=Indexed | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=68 kind=LiteralWithIndexing | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=55 kind=LiteralWithoutIndexing | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=24 kind=LiteralWithIndexing | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=13 kind=LiteralWithIndexing | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] <- hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] -- hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv HEADERS frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=1048576; old=0; new=1048576 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] inc_window; sz=2097152; old=0; new=2097152 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] recv_headers; stream=StreamId(1); state=State { inner: Idle } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] opening stream; init_window=1048576 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> first entry | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Open { local: AwaitingHeaders, remote: Streaming } }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=34 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=34 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 34B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Data | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv DATA frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] recv_data; size=25; connection=1048576; stream=1048576 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=25; window=1048576; available=1048576 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=25; window=1048576; available=1048576 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Open { local: AwaitingHeaders, remote: Streaming } }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=9 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=9 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 9B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Data | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv DATA frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] recv_data; size=0; connection=1048551; stream=1048551 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=0; window=1048551; available=1048551 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::state] recv_close: Open => HalfClosedRemote(AwaitingHeaders) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=0; window=1048551; available=1048551 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedRemote(AwaitingHeaders) }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] poll_complete | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] next_incoming; id=StreamId(1), state=State { inner: HalfClosedRemote(AwaitingHeaders) } | |
| [2021-06-12T06:03:08Z TRACE h2::server] received incoming | |
| [2021-06-12T06:03:08Z TRACE hyper::proto::h2::server] incoming request | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] poll_complete | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] release_capacity; size=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] release_connection_capacity; size=25, connection in_flight_data=25 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] release_capacity; size=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] release_connection_capacity; size=0, connection in_flight_data=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: HalfClosedRemote(AwaitingHeaders) }, is_counted: true, ref_count: 2, next_pending_send: None, is_pending_send: false, send_flow: FlowControl { window_size: Window(2097152), available: Window(0) }, requested_send_capacity: 0, buffered_send_data: 0, send_task: None, pending_send: Deque { indices: None }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: false, next_open: None, is_pending_open: false, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(1048551), available: Window(1048576) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData }, content_length: Omitted } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedRemote(AwaitingHeaders) }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::send] send_headers; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }; init_window=2097152 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] Prioritize::queue_frame; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_send stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> first entry | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedRemote(Streaming) }; is_closed=false; pending_send_empty=false; buffered_send_data=0; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=1 effective=1 curr=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] requested=1 additional=1 buffered=0 window=2097152 conn=5242880 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assigning capacity=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] assigned capacity to stream; available=1; buffered=0; id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] notifying task | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] available=1 requested=1 buffered=0 has_unavailable=true | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE hyper::proto::h2] send body chunk: 218 bytes, eos=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] send_data; sz=218 requested=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> send_data | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] buffered=218 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] requested=218 additional=217 buffered=218 window=2097152 conn=5242879 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assigning capacity=217 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] assigned capacity to stream; available=218; buffered=218; id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] available=218 requested=218 buffered=218 has_unavailable=true | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> already queued | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] available=218 buffered=218 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] Prioritize::queue_frame; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_send stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> already queued | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- send_data | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- send_data | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedRemote(Streaming) }; is_closed=false; pending_send_empty=false; buffered_send_data=218; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=1 effective=219 curr=218 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_assign_capacity; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] requested=219 additional=1 buffered=218 window=2097152 conn=5242662 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assigning capacity=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] assigned capacity to stream; available=219; buffered=218; id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::stream] notifying task | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] available=219 requested=219 buffered=218 has_unavailable=true | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> already queued | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_assign_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=0 effective=218 curr=219 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] assign_connection_capacity; inc=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- assign_connection_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::state] send_close: HalfClosedRemote => Closed | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::send] send_trailers -- queuing; frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] Prioritize::queue_frame; stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_send stream.id=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> already queued | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- Prioritize::queue_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reserve_capacity; stream.id=StreamId(1) requested=0 effective=218 curr=218 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- reserve_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=218; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: Closed(EndStream) }, is_counted: true, ref_count: 2, next_pending_send: None, is_pending_send: true, send_flow: FlowControl { window_size: Window(2097152), available: Window(218) }, requested_send_capacity: 218, buffered_send_data: 218, send_task: Some(Waker { data: 0xffffa800af40, vtable: 0xaaaac1b8a890 }), pending_send: Deque { indices: Some(Indices { head: 0, tail: 2 }) }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: true, next_open: None, is_pending_open: false, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(1048551), available: Window(1048576) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData }, content_length: Omitted } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=218; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: Closed(EndStream) }, is_counted: true, ref_count: 1, next_pending_send: None, is_pending_send: true, send_flow: FlowControl { window_size: Window(2097152), available: Window(218) }, requested_send_capacity: 218, buffered_send_data: 218, send_task: Some(Waker { data: 0xffffa800af40, vtable: 0xaaaac1b8a890 }), pending_send: Deque { indices: Some(Indices { head: 0, tail: 2 }) }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: true, next_open: None, is_pending_open: false, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(1048551), available: Window(1048576) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData }, content_length: Omitted } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=218; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] poll_complete | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] popped; stream.id=StreamId(1) stream.state=State { inner: Closed(EndStream) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] is_pending_reset=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> first entry | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=218; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] writing frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] -> hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] encoding at pos=9 | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] <- hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] -- hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] popped; stream.id=StreamId(1) stream.state=State { inner: Closed(EndStream) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] is_pending_reset=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] data frame sz=218 eos=false window=218 available=218 requested=218 buffered=218 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] sending data frame len=218 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=218; window=2097152; available=218 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- updating stream flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=218; window=5242880; available=5242880 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- updating connection flow | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame; frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] Queue::push | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::store] -> first entry | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=false; pending_send_empty=false; buffered_send_data=0; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] writing frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] reclaimed frame=Data { stream_id: StreamId(1) } sz=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] popped; stream.id=StreamId(1) stream.state=State { inner: Closed(EndStream) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] is_pending_reset=false | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame; frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=true; pending_send_empty=true; buffered_send_data=0; num_recv=1; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] dec_num_streams; stream=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- popped | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] writing frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] -> hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] encoding at pos=283 | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] <- hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::encoder] -- hpack::encode | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] queued_data_frame=false | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=47 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=47 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 47B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Headers | |
| [2021-06-12T06:03:08Z TRACE h2::frame::headers] loading headers; flags=(0x4: END_HEADERS) | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] -> hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=38 kind=Indexed | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=37 kind=LiteralWithIndexing | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=24 kind=LiteralWithIndexing | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] <- hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] -- hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv HEADERS frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] recv_headers; stream=StreamId(1); state=State { inner: HalfClosedLocal(AwaitingHeaders) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] opening stream; init_window=2097152 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedLocal(Streaming) }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=227 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=227 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 227B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Data | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv DATA frame=Data { stream_id: StreamId(1) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] recv_data; size=218; connection=5242880; stream=2097152 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=218; window=5242880; available=5242880 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::flow_control] send_data; sz=218; window=2097152; available=2097152 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: HalfClosedLocal(Streaming) }; is_closed=false; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=21 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=21 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 21B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=Headers | |
| [2021-06-12T06:03:08Z TRACE h2::frame::headers] loading headers; flags=(0x5: END_HEADERS | END_STREAM) | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] -> hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] rem=12 kind=LiteralWithIndexing | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] <- hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::hpack::decoder] -- hpack::decode | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv HEADERS frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] recv_headers; stream=StreamId(1); state=State { inner: HalfClosedLocal(Streaming) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::state] recv_close: HalfClosedLocal => Closed | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=true; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=1 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] dec_num_streams; stream=StreamId(1) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] poll_complete | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: Closed(EndStream) }, is_counted: false, ref_count: 2, next_pending_send: None, is_pending_send: false, send_flow: FlowControl { window_size: Window(1048551), available: Window(0) }, requested_send_capacity: 0, buffered_send_data: 0, send_task: Some(Waker { data: 0xffff58024b80, vtable: 0xaaaac1b838e8 }), pending_send: Deque { indices: None }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: true, next_open: None, is_pending_open: false, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(2096934), available: Window(2096934) }, in_flight_recv_data: 218, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: Some(Indices { head: 1, tail: 2 }) }, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData }, content_length: Omitted } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=true; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] release_capacity; size=218 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::recv] release_connection_capacity; size=218, connection in_flight_data=218 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] drop_stream_ref; stream=Stream { id: StreamId(1), state: State { inner: Closed(EndStream) }, is_counted: false, ref_count: 1, next_pending_send: None, is_pending_send: false, send_flow: FlowControl { window_size: Window(1048551), available: Window(0) }, requested_send_capacity: 0, buffered_send_data: 0, send_task: Some(Waker { data: 0xffff58024b80, vtable: 0xaaaac1b838e8 }), pending_send: Deque { indices: None }, next_pending_send_capacity: None, is_pending_send_capacity: false, send_capacity_inc: true, next_open: None, is_pending_open: false, is_pending_push: false, next_pending_accept: None, is_pending_accept: false, recv_flow: FlowControl { window_size: Window(2096934), available: Window(2097152) }, in_flight_recv_data: 0, next_window_update: None, is_pending_window_update: false, reset_at: None, next_reset_expire: None, pending_recv: Deque { indices: None }, recv_task: None, pending_push_promises: Queue { indices: None, _p: PhantomData }, content_length: Omitted } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::counts] transition_after; stream=StreamId(1); state=State { inner: Closed(EndStream) }; is_closed=true; pending_send_empty=true; buffered_send_data=0; num_recv=0; num_send=0 | |
| [2021-06-12T06:03:08Z TRACE tower_buffer::worker] worker polling for next message | |
| [2021-06-12T06:03:08Z TRACE hyper::proto::h2::client] client::dispatch::Sender dropped | |
| [2021-06-12T06:03:08Z TRACE want] signal: Closed | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] poll_complete | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] schedule_pending_open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- pop_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- try_reclaim_frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE hyper::proto::h2::client] send_request dropped, starting conn shutdown | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::buffer; frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) } | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_write] send frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) } | |
| [2021-06-12T06:03:08Z TRACE h2::frame::go_away] encoding GO_AWAY; code=NO_ERROR | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] encoded go_away rem=17 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::buffer | |
| [2021-06-12T06:03:08Z DEBUG h2::proto::connection] Connection::poll; connection error error=NO_ERROR | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> already going away | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Closing(NO_ERROR) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection closing after flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] queued_data_frame=false | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Open | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Closed(NO_ERROR) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] Streams::recv_eof | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] frame decoded from buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] read.bytes=17 | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::decode_frame; offset=17 | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] decoding frame from 17B | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] frame.kind=GoAway | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::decode_frame | |
| [2021-06-12T06:03:08Z DEBUG h2::codec::framed_read] received frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) } | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] recv GOAWAY frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) } | |
| [2021-06-12T06:03:08Z TRACE mio::poll] deregistering handle with poller | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -> poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll_ready | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -> FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] poll | |
| [2021-06-12T06:03:08Z TRACE tokio_util::codec::framed_read] attempting to decode a frame | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] <- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_read] -- FramedRead::poll_next | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] codec closed | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] Streams::recv_eof | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Closing(NO_ERROR) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection closing after flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -> FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] flushing buffer | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] <- FramedWrite::flush | |
| [2021-06-12T06:03:08Z TRACE h2::codec::framed_write] -- FramedWrite::flush | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] Outcome: Success | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Content-Type", [97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 118, 110, 100, 46, 100, 111, 99, 107, 101, 114, 46, 100, 105, 115, 116, 114, 105, 98, 117, 116, 105, 111, 110, 46, 109, 97, 110, 105, 102, 101, 115, 116, 46, 118, 50, 43, 106, 115, 111, 110] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Docker-Content-Digest", [115, 104, 97, 50, 53, 54, 58, 54, 50, 52, 51, 98, 50, 97, 55, 50, 101, 101, 57, 102, 100, 57, 49, 55, 99, 51, 53, 48, 49, 52, 57, 97, 51, 54, 53, 101, 101, 48, 98, 98, 55, 102, 100, 97, 98, 102, 54, 49, 55, 53, 101, 99, 97, 102, 48, 100, 52, 48, 52, 97, 100, 55, 97, 51, 49, 54, 102, 97, 55, 101, 101] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Server", [82, 111, 99, 107, 101, 116] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.append_raw( "Docker-Distribution-API-Version", [114, 101, 103, 105, 115, 116, 114, 121, 47, 50, 46, 48] ) | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.set( "Content-Length", ContentLength(1233) ) | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::response] writing head: Http11 Ok | |
| [2021-06-12T06:03:08Z TRACE hyper::header] Headers.set( "Date", Date(HttpDate(Tm { tm_sec: 8, tm_min: 3, tm_hour: 6, tm_mday: 12, tm_mon: 5, tm_year: 121, tm_wday: 6, tm_yday: 162, tm_isdst: 0, tm_utcoff: 0, tm_nsec: 245874033 })) ) | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] connection.state=Closed(NO_ERROR) | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::response] headers [ | |
| Headers { Connection: close | |
| , Content-Type: application/vnd.docker.distribution.manifest.v2+json | |
| , Docker-Content-Digest: sha256:6243b2a72ee9fd917c350149a365ee0bb7fdabf6175ecaf0d404ad7a316fa7ee | |
| , Server: Rocket | |
| , Docker-Distribution-API-Version: registry/2.0 | |
| , Content-Length: 1233 | |
| , Date: Sat, 12 Jun 2021 06:03:08 GMT | |
| , }] | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- poll | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] <- Connection | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z TRACE hyper::proto::h2::server] incoming connection complete | |
| [2021-06-12T06:03:08Z DEBUG hyper::server::response] write 1233 bytes | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::streams] Streams::recv_eof | |
| [2021-06-12T06:03:08Z TRACE hyper::server::response] ending | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -> clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] <- clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE h2::proto::streams::prioritize] -- clear_pending_capacity | |
| [2021-06-12T06:03:08Z TRACE mio::poll] deregistering handle with poller | |
| [2021-06-12T06:03:08Z TRACE h2::proto::connection] -- Connection | |
| [2021-06-12T06:03:08Z INFO rocket::rocket] Response succeeded. | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] keep_alive = false for 10.244.0.0:19089 | |
| [2021-06-12T06:03:08Z DEBUG hyper::server] keep_alive loop ending for 10.244.0.0:19089 |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment