{"action":"closed","issue":{"url":"https://api.github.com/repos/envoyproxy/envoy/issues/2715","repository_url":"https://api.github.com/repos/envoyproxy/envoy","labels_url":"https://api.github.com/repos/envoyproxy/envoy/issues/2715/labels{/name}","comments_url":"https://api.github.com/repos/envoyproxy/envoy/issues/2715/comments","events_url":"https://api.github.com/repos/envoyproxy/envoy/issues/2715/events","html_url":"https://github.com/envoyproxy/envoy/issues/2715","id":302231243,"number":2715,"title":"HTTP1 conneciton pool attach pending request to half-closed connection","user":{"login":"lizan","id":1016047,"avatar_url":"https://avatars1.githubusercontent.com/u/1016047?v=4","gravatar_id":"","url":"https://api.github.com/users/lizan","html_url":"https://github.com/lizan","followers_url":"https://api.github.com/users/lizan/followers","following_url":"https://api.github.com/users/lizan/following{/other_user}","gists_url":"https://api.github.com/users/lizan/gists{/gist_id}","starred_url":"https://api.github.com/users/lizan/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/lizan/subscriptions","organizations_url":"https://api.github.com/users/lizan/orgs","repos_url":"https://api.github.com/users/lizan/repos","events_url":"https://api.github.com/users/lizan/events{/privacy}","received_events_url":"https://api.github.com/users/lizan/received_events","type":"User","site_admin":false},"labels":[{"id":421403907,"url":"https://api.github.com/repos/envoyproxy/envoy/labels/bug","name":"bug","color":"ee0701","default":true}],"state":"closed","locked":false,"assignee":{"login":"lizan","id":1016047,"avatar_url":"https://avatars1.githubusercontent.com/u/1016047?v=4","gravatar_id":"","url":"https://api.github.com/users/lizan","html_url":"https://github.com/lizan","followers_url":"https://api.github.com/users/lizan/followers","following_url":"https://api.github.com/users/lizan/following{/other_user}","gists_url":"https://api.github.com/users/lizan/gists{/gist_id}","starred_url":"https://api.github.com/users/lizan/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/lizan/subscriptions","organizations_url":"https://api.github.com/users/lizan/orgs","repos_url":"https://api.github.com/users/lizan/repos","events_url":"https://api.github.com/users/lizan/events{/privacy}","received_events_url":"https://api.github.com/users/lizan/received_events","type":"User","site_admin":false},"assignees":[{"login":"lizan","id":1016047,"avatar_url":"https://avatars1.githubusercontent.com/u/1016047?v=4","gravatar_id":"","url":"https://api.github.com/users/lizan","html_url":"https://github.com/lizan","followers_url":"https://api.github.com/users/lizan/followers","following_url":"https://api.github.com/users/lizan/following{/other_user}","gists_url":"https://api.github.com/users/lizan/gists{/gist_id}","starred_url":"https://api.github.com/users/lizan/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/lizan/subscriptions","organizations_url":"https://api.github.com/users/lizan/orgs","repos_url":"https://api.github.com/users/lizan/repos","events_url":"https://api.github.com/users/lizan/events{/privacy}","received_events_url":"https://api.github.com/users/lizan/received_events","type":"User","site_admin":false}],"milestone":{"url":"https://api.github.com/repos/envoyproxy/envoy/milestones/6","html_url":"https://github.com/envoyproxy/envoy/milestone/6","labels_url":"https://api.github.com/repos/envoyproxy/envoy/milestones/6/labels","id":3163642,"number":6,"title":"1.7.0","description":"","creator":{"login":"mattklein123","id":6305260,"avatar_url":"https://avatars3.githubusercontent.com/u/6305260?v=4","gravatar_id":"","url":"https://api.github.com/users/mattklein123","html_url":"https://github.com/mattklein123","followers_url":"https://api.github.com/users/mattklein123/followers","following_url":"https://api.github.com/users/mattklein123/following{/other_user}","gists_url":"https://api.github.com/users/mattklein123/gists{/gist_id}","starred_url":"https://api.github.com/users/mattklein123/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/mattklein123/subscriptions","organizations_url":"https://api.github.com/users/mattklein123/orgs","repos_url":"https://api.github.com/users/mattklein123/repos","events_url":"https://api.github.com/users/mattklein123/events{/privacy}","received_events_url":"https://api.github.com/users/mattklein123/received_events","type":"User","site_admin":false},"open_issues":44,"closed_issues":22,"state":"open","created_at":"2018-03-05T22:43:00Z","updated_at":"2018-04-24T16:34:42Z","due_on":null,"closed_at":null},"comments":29,"created_at":"2018-03-05T09:45:40Z","updated_at":"2018-04-24T16:34:42Z","closed_at":"2018-04-24T16:34:42Z","author_association":"CONTRIBUTOR","body":"*Description*:\r\nThe HTTP1 connection pool attach pending request [when a response is complete](https://github.com/envoyproxy/envoy/blob/c932e50c34a11dd382dca9c5daf2026d4686daa9/source/common/http/http1/conn_pool.cc#L212). Though the upstream server may already closed the connection, this will result the pending request attached to it end up with 503.\r\n\r\nA sample upstream HTTP1 trace log:\r\n```\r\n[2018-03-03 00:11:36.931][20][debug][client] external/envoy/source/common/http/codec_client.cc:23] [C581] connecting\r\n[2018-03-03 00:11:36.931][20][debug][connection] external/envoy/source/common/network/connection_impl.cc:559] [C581] connecting to 127.0.0.1:8080\r\n[2018-03-03 00:11:36.932][20][debug][connection] external/envoy/source/common/network/connection_impl.cc:568] [C581] connection in progress\r\n[2018-03-03 00:11:37.178][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:377] [C581] socket event: 2\r\n[2018-03-03 00:11:37.178][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:445] [C581] write ready\r\n[2018-03-03 00:11:37.180][20][debug][connection] external/envoy/source/common/network/connection_impl.cc:455] [C581] connected\r\n[2018-03-03 00:11:37.180][20][debug][client] external/envoy/source/common/http/codec_client.cc:52] [C581] connected\r\n[2018-03-03 00:11:37.181][20][debug][pool] external/envoy/source/common/http/http1/conn_pool.cc:225] [C581] attaching to next request\r\n[2018-03-03 00:11:37.184][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:314] [C581] writing 506 bytes, end_stream false\r\n[2018-03-03 00:11:37.184][20][trace][connection] external/envoy/source/common/network/raw_buffer_socket.cc:67] [C581] write returns: 506\r\n[2018-03-03 00:11:37.459][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:377] [C581] socket event: 2\r\n[2018-03-03 00:11:37.459][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:445] [C581] write ready\r\n[2018-03-03 00:11:37.487][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:377] [C581] socket event: 3\r\n[2018-03-03 00:11:37.487][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:445] [C581] write ready\r\n[2018-03-03 00:11:37.487][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:415] [C581] read ready\r\n[2018-03-03 00:11:37.488][20][trace][connection] external/envoy/source/common/network/raw_buffer_socket.cc:25] [C581] read returns: 166\r\n[2018-03-03 00:11:37.488][20][trace][connection] external/envoy/source/common/network/raw_buffer_socket.cc:25] [C581] read returns: 0\r\n[2018-03-03 00:11:37.488][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:298] [C581] parsing 166 bytes\r\n[2018-03-03 00:11:37.489][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:285] [C581] completed header: key=content-length value=0\r\n[2018-03-03 00:11:37.489][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:285] [C581] completed header: key=date value=Sat, 03 Mar 2018 00:11:36 GMT\r\n[2018-03-03 00:11:37.489][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:285] [C581] completed header: key=content-type value=text/plain; charset=utf-8\r\n[2018-03-03 00:11:37.490][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:285] [C581] completed header: key=x-envoy-upstream-service-time value=49\r\n[2018-03-03 00:11:37.490][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:354] [C581] headers complete\r\n[2018-03-03 00:11:37.491][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:285] [C581] completed header: key=server value=envoy\r\n[2018-03-03 00:11:37.497][20][debug][client] external/envoy/source/common/http/codec_client.cc:81] [C581] response complete\r\n[2018-03-03 00:11:37.501][20][debug][pool] external/envoy/source/common/http/http1/conn_pool.cc:200] [C581] response complete\r\n[2018-03-03 00:11:37.502][20][debug][pool] external/envoy/source/common/http/http1/conn_pool.cc:225] [C581] attaching to next request\r\n[2018-03-03 00:11:37.503][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:314] [C581] writing 509 bytes, end_stream false\r\n[2018-03-03 00:11:37.504][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:315] [C581] parsed 166 bytes\r\n[2018-03-03 00:11:37.504][20][debug][connection] external/envoy/source/common/network/connection_impl.cc:439] [C581] remote close\r\n[2018-03-03 00:11:37.505][20][debug][connection] external/envoy/source/common/network/connection_impl.cc:134] [C581] closing socket: 0\r\n[2018-03-03 00:11:37.505][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:298] [C581] parsing 0 bytes\r\n[2018-03-03 00:11:37.505][20][trace][http] external/envoy/source/common/http/http1/codec_impl.cc:315] [C581] parsed 0 bytes\r\n[2018-03-03 00:11:37.506][20][debug][client] external/envoy/source/common/http/codec_client.cc:70] [C581] disconnect. resetting 1 pending requests\r\n[2018-03-03 00:11:37.506][20][debug][client] external/envoy/source/common/http/codec_client.cc:91] [C581] request reset\r\n[2018-03-03 00:11:37.520][20][debug][pool] external/envoy/source/common/http/http1/conn_pool.cc:115] [C581] client disconnected\r\n```\r\n\r\nThe first request was processed correctly while the 2nd request is attached at\r\n```\r\n[2018-03-03 00:11:37.502][20][debug][pool] external/envoy/source/common/http/http1/conn_pool.cc:225] [C581] attaching to next request\r\n[2018-03-03 00:11:37.503][20][trace][connection] external/envoy/source/common/network/connection_impl.cc:314] [C581] writing 509 bytes, end_stream false\r\n```\r\n\r\nThe write never complete and the request was reset immediately.\r\n\r\n\r\n*Repro steps*:\r\nIt is a little bit hard to reproduce, I'll update when I have a minimal reproducible environment.\r\n\r\nThe current repro is with [Istio load testing tool](https://github.com/istio/istio/tree/0.6.0/tools) at 100 qps with mTLS enabled.\r\nSee https://github.com/istio/istio/issues/3295 for more details."}}
{"actor":{"display_login":"alyssawilk"}}