{"action":"created","issue":{"url":"https://api.github.com/repos/getlantern/lantern/issues/5514","repository_url":"https://api.github.com/repos/getlantern/lantern","labels_url":"https://api.github.com/repos/getlantern/lantern/issues/5514/labels{/name}","comments_url":"https://api.github.com/repos/getlantern/lantern/issues/5514/comments","events_url":"https://api.github.com/repos/getlantern/lantern/issues/5514/events","html_url":"https://github.com/getlantern/lantern/issues/5514","id":196988411,"number":5514,"title":"Chrome sometimes not able to establish a CONNECT tunnel","user":{"login":"myleshorton","id":1143966,"avatar_url":"https://avatars.githubusercontent.com/u/1143966?v=3","gravatar_id":"","url":"https://api.github.com/users/myleshorton","html_url":"https://github.com/myleshorton","followers_url":"https://api.github.com/users/myleshorton/followers","following_url":"https://api.github.com/users/myleshorton/following{/other_user}","gists_url":"https://api.github.com/users/myleshorton/gists{/gist_id}","starred_url":"https://api.github.com/users/myleshorton/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/myleshorton/subscriptions","organizations_url":"https://api.github.com/users/myleshorton/orgs","repos_url":"https://api.github.com/users/myleshorton/repos","events_url":"https://api.github.com/users/myleshorton/events{/privacy}","received_events_url":"https://api.github.com/users/myleshorton/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":7,"created_at":"2016-12-21T17:24:50Z","updated_at":"2016-12-22T00:08:09Z","closed_at":null,"body":"It looks like this can happen sometimes when the remote server closes the connection. This could happen, for example, if there's an idle connection the server decides to close. This will then kick out to this chunk of code in `client/handler.go`:\r\n\r\n```\r\n\tif req.Method == http.MethodConnect {\r\n\t\t// CONNECT requests are often used for HTTPS requests.\r\n\t\tlog.Tracef(\"Intercepting CONNECT %s\", req.URL)\r\n\t\terr := client.interceptCONNECT(ctx, resp, req)\r\n\t\tif err != nil {\r\n\t\t\tlog.Error(op.FailIf(err))\r\n\t\t}\r\n\t} else {\r\n```\r\n\r\nIt will basically hit that error condition, which presumably just closes the connection to the browser, which causes Chrome to mark Lantern as a bad proxy.\r\n\r\nFrom Chrome:\r\n```\r\n193973: HTTP_STREAM_JOB\r\nhttps://ssl.gstatic.com/\r\nStart Time: 2016-12-21 09:07:32.060\r\n\r\nt=694279 [st=    0] +HTTP_STREAM_JOB  [dt=12903]\r\n                     --> alternative_service = \"Uninitialized :0\"\r\n                     --> original_url = \"https://ssl.gstatic.com/\"\r\n                     --> priority = \"LOWEST\"\r\n                     --> source_dependency = 193970 (URL_REQUEST)\r\n                     --> url = \"https://ssl.gstatic.com/\"\r\nt=694279 [st=    0]   +PROXY_SERVICE  [dt=0]\r\nt=694279 [st=    0]      PROXY_SERVICE_RESOLVED_PROXY_LIST\r\n                         --> pac_string = \"PROXY 127.0.0.1:18345;DIRECT\"\r\nt=694279 [st=    0]   -PROXY_SERVICE\r\nt=694279 [st=    0]   +HOST_RESOLVER_IMPL_REQUEST  [dt=0]\r\n                       --> address_family = 0\r\n                       --> allow_cached_response = true\r\n                       --> host = \"ssl.gstatic.com:443\"\r\n                       --> is_speculative = false\r\nt=694279 [st=    0]      HOST_RESOLVER_IMPL_IPV6_REACHABILITY_CHECK\r\n                         --> cached = true\r\n                         --> ipv6_available = true\r\nt=694279 [st=    0]   -HOST_RESOLVER_IMPL_REQUEST\r\n                       --> net_error = -804 (ERR_DNS_CACHE_MISS)\r\nt=694279 [st=    0]   +SOCKET_POOL  [dt=12829]\r\nt=707108 [st=12829]      SOCKET_POOL_BOUND_TO_CONNECT_JOB\r\n                         --> source_dependency = 193790 (CONNECT_JOB)\r\nt=707108 [st=12829]   -SOCKET_POOL\r\n                       --> net_error = -111 (ERR_TUNNEL_CONNECTION_FAILED)\r\nt=707108 [st=12829]    PROXY_LIST_FALLBACK\r\n                       --> bad_proxy = \"127.0.0.1:18345\"\r\nt=707108 [st=12829]   +HOST_RESOLVER_IMPL_REQUEST  [dt=0]\r\n                       --> address_family = 0\r\n                       --> allow_cached_response = true\r\n                       --> host = \"ssl.gstatic.com:443\"\r\n                       --> is_speculative = false\r\nt=707108 [st=12829]      HOST_RESOLVER_IMPL_IPV6_REACHABILITY_CHECK\r\n                         --> cached = false\r\n                         --> ipv6_available = true\r\nt=707108 [st=12829]   -HOST_RESOLVER_IMPL_REQUEST\r\n                       --> net_error = -804 (ERR_DNS_CACHE_MISS)\r\nt=707110 [st=12831]   +SOCKET_POOL  [dt=71]\r\nt=707181 [st=12902]      SOCKET_POOL_BOUND_TO_CONNECT_JOB\r\n                         --> source_dependency = 194418 (CONNECT_JOB)\r\nt=707181 [st=12902]      SOCKET_POOL_BOUND_TO_SOCKET\r\n                         --> source_dependency = 194423 (SOCKET)\r\nt=707181 [st=12902]   -SOCKET_POOL\r\nt=707181 [st=12902]    HTTP_STREAM_REQUEST_PROTO\r\n                       --> proto = \"h2\"\r\nt=707181 [st=12902]   +HOST_RESOLVER_IMPL_REQUEST  [dt=0]\r\n                       --> address_family = 0\r\n                       --> allow_cached_response = true\r\n                       --> host = \"ssl.gstatic.com:443\"\r\n                       --> is_speculative = false\r\nt=707181 [st=12902]      HOST_RESOLVER_IMPL_IPV6_REACHABILITY_CHECK\r\n                         --> cached = true\r\n                         --> ipv6_available = true\r\nt=707181 [st=12902]      HOST_RESOLVER_IMPL_CACHE_HIT\r\nt=707181 [st=12902]   -HOST_RESOLVER_IMPL_REQUEST\r\nt=707181 [st=12902]    HTTP2_SESSION_POOL_IMPORTED_SESSION_FROM_SOCKET\r\n                       --> source_dependency = 194424 (HTTP2_SESSION)\r\nt=707182 [st=12903]    HTTP_STREAM_JOB_BOUND_TO_REQUEST\r\n                       --> source_dependency = 193970 (URL_REQUEST)\r\nt=707182 [st=12903] -HTTP_STREAM_JOB\r\n```\r\n\r\nFrom Lantern logs:\r\n\r\n```\r\nDec 21 17:07:33.853 - 56m7s ERROR flashlight.client: handler.go:39 Error piping data to upstream: read tcp 127.0.0.1:18345->127.0.0.1:55463: read: connection reset by peer [error=Error piping data to upstream: %v error_location=github.com/getlantern/flashlight/vendor/github.com/getlantern/proxy.(*connectInterceptor).connect (proxy_connect.go:119) error_op=read error_text=Error piping data to upstream: read tcp 127.0.0.1:18345->127.0.0.1:55463: read: connection reset by peer error_type=errors.Error local_addr=127.0.0.1:55463 network=tcp op=proxy origin=encrypted-tbn1.gstatic.com:443 origin_host=encrypted-tbn1.gstatic.com origin_port=443 remote_addr=127.0.0.1:18345 root_op=proxy user_agent=Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/55.0.2883.95 Safari/537.36]\r\nERROR flashlight.client: handler.go:39   at github.com/getlantern/flashlight/vendor/github.com/getlantern/proxy.(*connectInterceptor).connect (proxy_connect.go:119)\r\nERROR flashlight.client: handler.go:39   at github.com/getlantern/flashlight/vendor/github.com/getlantern/proxy.(*connectInterceptor).(github.com/getlantern/flashlight/vendor/github.com/getlantern/proxy.connect)-fm (proxy_connect.go:47)\r\nERROR flashlight.client: handler.go:39   at github.com/getlantern/flashlight/client.(*Client).serveHTTPWithContext (handler.go:37)\r\nERROR flashlight.client: handler.go:39   at github.com/getlantern/flashlight/client.(*Client).ServeHTTP (handler.go:22)\r\nERROR flashlight.client: handler.go:39   at net/http.serverHandler.ServeHTTP (server.go:2202)\r\nERROR flashlight.client: handler.go:39   at net/http.(*conn).serve (server.go:1579)\r\nERROR flashlight.client: handler.go:39   at runtime.goexit (asm_amd64.s:2086)\r\nERROR flashlight.client: handler.go:39 Caused by: read: connection reset by peer\r\n```"},"comment":{"url":"https://api.github.com/repos/getlantern/lantern/issues/comments/268680350","html_url":"https://github.com/getlantern/lantern/issues/5514#issuecomment-268680350","issue_url":"https://api.github.com/repos/getlantern/lantern/issues/5514","id":268680350,"user":{"login":"myleshorton","id":1143966,"avatar_url":"https://avatars.githubusercontent.com/u/1143966?v=3","gravatar_id":"","url":"https://api.github.com/users/myleshorton","html_url":"https://github.com/myleshorton","followers_url":"https://api.github.com/users/myleshorton/followers","following_url":"https://api.github.com/users/myleshorton/following{/other_user}","gists_url":"https://api.github.com/users/myleshorton/gists{/gist_id}","starred_url":"https://api.github.com/users/myleshorton/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/myleshorton/subscriptions","organizations_url":"https://api.github.com/users/myleshorton/orgs","repos_url":"https://api.github.com/users/myleshorton/repos","events_url":"https://api.github.com/users/myleshorton/events{/privacy}","received_events_url":"https://api.github.com/users/myleshorton/received_events","type":"User","site_admin":false},"created_at":"2016-12-22T00:08:09Z","updated_at":"2016-12-22T00:08:09Z","body":"Actually it looks quite likely this is what we're hitting @joesis:\r\n\r\nhttps://cs.chromium.org/chromium/src/net/http/http_proxy_client_socket.cc?rcl=0&l=507\r\n\r\nSince it looks like that's where a Bad Gateway response would reach...\r\n\r\nNo not really sure if there's a solid way around this TBH..."}}
{"actor":{"display_login":"myleshorton"}}