{"action":"created","issue":{"url":"https://api.github.com/repos/http4s/http4s/issues/710","repository_url":"https://api.github.com/repos/http4s/http4s","labels_url":"https://api.github.com/repos/http4s/http4s/issues/710/labels{/name}","comments_url":"https://api.github.com/repos/http4s/http4s/issues/710/comments","events_url":"https://api.github.com/repos/http4s/http4s/issues/710/events","html_url":"https://github.com/http4s/http4s/issues/710","id":177091218,"number":710,"title":"Expected `Content-Length: 39` bytes, but only 0 were written.","user":{"login":"dbousamra","id":648137,"avatar_url":"https://avatars.githubusercontent.com/u/648137?v=3","gravatar_id":"","url":"https://api.github.com/users/dbousamra","html_url":"https://github.com/dbousamra","followers_url":"https://api.github.com/users/dbousamra/followers","following_url":"https://api.github.com/users/dbousamra/following{/other_user}","gists_url":"https://api.github.com/users/dbousamra/gists{/gist_id}","starred_url":"https://api.github.com/users/dbousamra/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/dbousamra/subscriptions","organizations_url":"https://api.github.com/users/dbousamra/orgs","repos_url":"https://api.github.com/users/dbousamra/repos","events_url":"https://api.github.com/users/dbousamra/events{/privacy}","received_events_url":"https://api.github.com/users/dbousamra/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/http4s/http4s/labels/bug","name":"bug","color":"fc2929"}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":18,"created_at":"2016-09-15T05:20:57Z","updated_at":"2016-09-21T16:36:47Z","closed_at":null,"body":"Copy of stacktrace:\r\n\r\n```\r\nERROR] 2016-09-15 05:12:48,341  org.http4s.blaze.pipeline.Stage fatalError - Fatal Error: Error executing request\r\njava.lang.IllegalStateException: Expected `Content-Length: 39` bytes, but only 0 were written.\r\n        at org.http4s.blaze.util.IdentityWriter.org$http4s$blaze$util$IdentityWriter$$$anonfun$3(IdentityWriter.scala:58)\r\n        at scala.concurrent.Future$$anonfun$flatMap$1.apply(Future.scala:253)\r\n        at scala.concurrent.Future$$anonfun$flatMap$1.apply(Future.scala:251)\r\n        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:32)\r\n        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)\r\n        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)\r\n        at java.lang.Thread.run(Thread.java:745)\r\n[ERROR] 2016-09-15 05:12:48,341  org.http4s.blaze.pipeline.Stage outboundCommand - ClientTimeoutStage: Idle: 60 seconds, Request: Duration.Inf received unhandled error command\r\njava.lang.IllegalStateException: Expected `Content-Length: 39` bytes, but only 0 were written.\r\n        at org.http4s.blaze.util.IdentityWriter.org$http4s$blaze$util$IdentityWriter$$$anonfun$3(IdentityWriter.scala:58)\r\n        at scala.concurrent.Future$$anonfun$flatMap$1.apply(Future.scala:253)\r\n        at scala.concurrent.Future$$anonfun$flatMap$1.apply(Future.scala:251)\r\n        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:32)\r\n        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)\r\n        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)\r\n        at java.lang.Thread.run(Thread.java:745)\r\n[ERROR] 2016-09-15 05:12:48,341  org.http4s.blaze.pipeline.Stage closeWithError - NIO2 channel closed with an unexpected error\r\njava.lang.IllegalStateException: Expected `Content-Length: 39` bytes, but only 0 were written.\r\n        at org.http4s.blaze.util.IdentityWriter.org$http4s$blaze$util$IdentityWriter$$$anonfun$3(IdentityWriter.scala:58)\r\n        at scala.concurrent.Future$$anonfun$flatMap$1.apply(Future.scala:253)\r\n        at scala.concurrent.Future$$anonfun$flatMap$1.apply(Future.scala:251)\r\n        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:32)\r\n        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)\r\n        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)\r\n        at java.lang.Thread.run(Thread.java:745)\r\n```\r\n\r\nSome background. I have a proxy server written in http4s, whose job it is to route requests to downstream services. The code looks like:\r\n\r\n```scala\r\ndef makeDownstreamRequest(client: Client, req: Request, service: DownstreamService, path: String, includeQueryParams: Boolean = true): Task[Response] = {\r\n\r\n    val serviceUriToUse = req.headers.get(`X-Forwarded-Proto`) match {\r\n      case Some(proto) => proto.value match {\r\n        case \"https\" => service.serviceUri.https\r\n        case \"http\"  => service.serviceUri.http\r\n        case _       => service.serviceUri.http\r\n      }\r\n      case None => service.serviceUri.http\r\n    }\r\n\r\n    val headers = req.headers.put(service.version)\r\n\r\n    val uri = appendPath(serviceUriToUse, path).copy(\r\n      query = req.uri.query,\r\n      fragment = req.uri.fragment\r\n    )\r\n\r\n    val newReq = req.copy(\r\n      uri = uri,\r\n      headers = headers\r\n    )\r\n    client.toHttpService.run(newReq).attempt.flatMap {\r\n      case \\/-(response) => {\r\n        response.pure[Task]\r\n      }\r\n      case -\\/(error)    => {\r\n        BadGateway()\r\n      }\r\n    }\r\n  }\r\n```\r\n\r\nThis works well normally. But when a request is made that is OAuth 1.0 signed, i receive this stacktrace, BUT only occasionally. It seems to only occur when the server has been idle for a period (say 60s or so). If I load test it, only the first request fails.\r\n\r\nI'm using 0.14.3, with a PooledClient with default settings."},"comment":{"url":"https://api.github.com/repos/http4s/http4s/issues/comments/248669198","html_url":"https://github.com/http4s/http4s/issues/710#issuecomment-248669198","issue_url":"https://api.github.com/repos/http4s/http4s/issues/710","id":248669198,"user":{"login":"bryce-anderson","id":2948506,"avatar_url":"https://avatars.githubusercontent.com/u/2948506?v=3","gravatar_id":"","url":"https://api.github.com/users/bryce-anderson","html_url":"https://github.com/bryce-anderson","followers_url":"https://api.github.com/users/bryce-anderson/followers","following_url":"https://api.github.com/users/bryce-anderson/following{/other_user}","gists_url":"https://api.github.com/users/bryce-anderson/gists{/gist_id}","starred_url":"https://api.github.com/users/bryce-anderson/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bryce-anderson/subscriptions","organizations_url":"https://api.github.com/users/bryce-anderson/orgs","repos_url":"https://api.github.com/users/bryce-anderson/repos","events_url":"https://api.github.com/users/bryce-anderson/events{/privacy}","received_events_url":"https://api.github.com/users/bryce-anderson/received_events","type":"User","site_admin":false},"created_at":"2016-09-21T16:36:47Z","updated_at":"2016-09-21T16:36:47Z","body":"That's good news about the deadlock issue! It's not clear to me what the stack trace you posted relates to. What conditions is that under?\r\n\r\nAnd I still wonder what would happen if you set all timeouts to `Inf`."}}
{"actor":{"display_login":"bryce-anderson"}}