Hello.
We have been implementing the snowplow pipeline on GCP using the BQ stream-loader to insert our events into BiqQuery. While performing load testing to see how the pipeline would handle running in production, we noticed that we were building up a significant number of unacked events in our enriched events subscription and saw that the ack rate was very low (1-2 messages per second). Restarting the BQ loader container fixed it temporarily, but after an hour or so, we saw the ack rate decline again. We attempted using a larger VM (n2-standard-4: 4 vCPUs 16 gigs RAM) which significantly increased our ack rate to around 750 messages/second but again after about an hour we saw that drastically decline while still sitting at 100% vCPU usage. I looked into the VM running htop and saw that there were 4 processes that had been running for over an hour each that were each taking up 100% of their respective vCPUs. When checking the container logs I then saw this same warning repeating over and over again:
[WARNING] Your app's responsiveness to a new asynchronous event (such as a new connection, an upstream response, or a timer) was in excess of 100 milliseconds. Your CPU is probably starving. Consider increasing the granularity of your delays or adding more cedes. This may also be a sign that you are unintentionally running blocking I/O operations (such as File or InetAddress) without the blocking combinator.
It then eventually culminated in this error:
com.google.cloud.bigquery.BigQueryException: Error writing request body to server
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.translate(HttpBigQueryRpc.java:115)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:507)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at flatMap @ com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.go$1(Bigquery.scala:54)
at flatMap @ fs2.Stream.$anonfun$parEvalMapAction$6(Stream.scala:2140)
Caused by: java.io.IOException: Error writing request body to server
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(Unknown Source)
at java.base/java.io.BufferedOutputStream.flushBuffer(Unknown Source)
at java.base/java.io.BufferedOutputStream.flush(Unknown Source)
at java.base/java.util.zip.DeflaterOutputStream.flush(Unknown Source)
at com.fasterxml.jackson.core.json.UTF8JsonGenerator.flush(UTF8JsonGenerator.java:1200)
at com.google.api.client.json.jackson2.JacksonGenerator.flush(JacksonGenerator.java:46)
at com.google.api.client.http.json.JsonHttpContent.writeTo(JsonHttpContent.java:77)
at com.google.api.client.http.GZipEncoding.encode(GZipEncoding.java:53)
at com.google.api.client.http.HttpEncodingStreamingContent.writeTo(HttpEncodingStreamingContent.java:48)
at com.google.api.client.http.javanet.NetHttpRequest$DefaultOutputWriter.write(NetHttpRequest.java:76)
at com.google.api.client.http.javanet.NetHttpRequest.writeContentToOutputStream(NetHttpRequest.java:174)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:117)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:84)
at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1012)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:514)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:455)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.execute(AbstractGoogleClientRequest.java:565)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:505)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at cats.effect.unsafe.WorkerThread.blockOn(WorkerThread.scala:668)
at scala.concurrent.package$.blocking(package.scala:124)
at cats.effect.IOFiber.runLoop(IOFiber.scala:953)
at cats.effect.IOFiber.execR(IOFiber.scala:1319)
at cats.effect.IOFiber.run(IOFiber.scala:118)
at cats.effect.unsafe.WorkerThread.run(WorkerThread.scala:585)
com.google.cloud.bigquery.BigQueryException: Error writing request body to server
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.translate(HttpBigQueryRpc.java:115)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:507)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at flatMap @ com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.go$1(Bigquery.scala:54)
at flatMap @ fs2.Stream.$anonfun$parEvalMapAction$6(Stream.scala:2140)
Caused by: java.io.IOException: Error writing request body to server
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(Unknown Source)
at java.base/java.io.BufferedOutputStream.flushBuffer(Unknown Source)
at java.base/java.io.BufferedOutputStream.flush(Unknown Source)
at java.base/java.util.zip.DeflaterOutputStream.flush(Unknown Source)
at com.fasterxml.jackson.core.json.UTF8JsonGenerator.flush(UTF8JsonGenerator.java:1200)
at com.google.api.client.json.jackson2.JacksonGenerator.flush(JacksonGenerator.java:46)
at com.google.api.client.http.json.JsonHttpContent.writeTo(JsonHttpContent.java:77)
at com.google.api.client.http.GZipEncoding.encode(GZipEncoding.java:53)
at com.google.api.client.http.HttpEncodingStreamingContent.writeTo(HttpEncodingStreamingContent.java:48)
at com.google.api.client.http.javanet.NetHttpRequest$DefaultOutputWriter.write(NetHttpRequest.java:76)
at com.google.api.client.http.javanet.NetHttpRequest.writeContentToOutputStream(NetHttpRequest.java:174)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:117)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:84)
at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1012)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:514)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:455)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.execute(AbstractGoogleClientRequest.java:565)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:505)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at cats.effect.unsafe.WorkerThread.blockOn(WorkerThread.scala:668)
at scala.concurrent.package$.blocking(package.scala:124)
at cats.effect.IOFiber.runLoop(IOFiber.scala:953)
at cats.effect.IOFiber.execR(IOFiber.scala:1319)
at cats.effect.IOFiber.run(IOFiber.scala:118)
at cats.effect.unsafe.WorkerThread.run(WorkerThread.scala:585)
com.google.cloud.bigquery.BigQueryException: Error writing request body to server
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.translate(HttpBigQueryRpc.java:115)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:507)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at flatMap @ com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.go$1(Bigquery.scala:54)
at flatMap @ fs2.Stream.$anonfun$parEvalMapAction$6(Stream.scala:2140)
Caused by: java.io.IOException: Error writing request body to server
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(Unknown Source)
at java.base/java.io.BufferedOutputStream.flushBuffer(Unknown Source)
at java.base/java.io.BufferedOutputStream.flush(Unknown Source)
at java.base/java.util.zip.DeflaterOutputStream.flush(Unknown Source)
at com.fasterxml.jackson.core.json.UTF8JsonGenerator.flush(UTF8JsonGenerator.java:1200)
at com.google.api.client.json.jackson2.JacksonGenerator.flush(JacksonGenerator.java:46)
at com.google.api.client.http.json.JsonHttpContent.writeTo(JsonHttpContent.java:77)
at com.google.api.client.http.GZipEncoding.encode(GZipEncoding.java:53)
at com.google.api.client.http.HttpEncodingStreamingContent.writeTo(HttpEncodingStreamingContent.java:48)
at com.google.api.client.http.javanet.NetHttpRequest$DefaultOutputWriter.write(NetHttpRequest.java:76)
at com.google.api.client.http.javanet.NetHttpRequest.writeContentToOutputStream(NetHttpRequest.java:174)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:117)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:84)
at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1012)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:514)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:455)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.execute(AbstractGoogleClientRequest.java:565)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:505)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at cats.effect.unsafe.WorkerThread.blockOn(WorkerThread.scala:668)
at scala.concurrent.package$.blocking(package.scala:124)
at cats.effect.IOFiber.runLoop(IOFiber.scala:953)
at cats.effect.IOFiber.execR(IOFiber.scala:1319)
at cats.effect.IOFiber.run(IOFiber.scala:118)
at cats.effect.unsafe.WorkerThread.run(WorkerThread.scala:585)
com.google.cloud.bigquery.BigQueryException: Error writing request body to server
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.translate(HttpBigQueryRpc.java:115)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:507)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at flatMap @ com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.go$1(Bigquery.scala:54)
at flatMap @ fs2.Stream.$anonfun$parEvalMapAction$6(Stream.scala:2140)
Caused by: java.io.IOException: Error writing request body to server
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(Unknown Source)
at java.base/java.io.BufferedOutputStream.flushBuffer(Unknown Source)
at java.base/java.io.BufferedOutputStream.flush(Unknown Source)
at java.base/java.util.zip.DeflaterOutputStream.flush(Unknown Source)
at com.fasterxml.jackson.core.json.UTF8JsonGenerator.flush(UTF8JsonGenerator.java:1200)
at com.google.api.client.json.jackson2.JacksonGenerator.flush(JacksonGenerator.java:46)
at com.google.api.client.http.json.JsonHttpContent.writeTo(JsonHttpContent.java:77)
at com.google.api.client.http.GZipEncoding.encode(GZipEncoding.java:53)
at com.google.api.client.http.HttpEncodingStreamingContent.writeTo(HttpEncodingStreamingContent.java:48)
at com.google.api.client.http.javanet.NetHttpRequest$DefaultOutputWriter.write(NetHttpRequest.java:76)
at com.google.api.client.http.javanet.NetHttpRequest.writeContentToOutputStream(NetHttpRequest.java:174)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:117)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:84)
at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1012)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:514)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:455)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.execute(AbstractGoogleClientRequest.java:565)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:505)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at cats.effect.unsafe.WorkerThread.blockOn(WorkerThread.scala:668)
at scala.concurrent.package$.blocking(package.scala:124)
at cats.effect.IOFiber.runLoop(IOFiber.scala:953)
at cats.effect.IOFiber.execR(IOFiber.scala:1319)
at cats.effect.IOFiber.run(IOFiber.scala:118)
at cats.effect.unsafe.WorkerThread.run(WorkerThread.scala:585)
[io-compute-0] ERROR com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Shutdown - Error on sinking and checkpointing events
com.google.cloud.bigquery.BigQueryException: Error writing request body to server
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.translate(HttpBigQueryRpc.java:115)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:507)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at flatMap @ com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.go$1(Bigquery.scala:54)
at flatMap @ fs2.Stream.$anonfun$parEvalMapAction$6(Stream.scala:2140)
Caused by: java.io.IOException: Error writing request body to server
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(Unknown Source)
at java.base/java.io.BufferedOutputStream.flushBuffer(Unknown Source)
at java.base/java.io.BufferedOutputStream.flush(Unknown Source)
at java.base/java.util.zip.DeflaterOutputStream.flush(Unknown Source)
at com.fasterxml.jackson.core.json.UTF8JsonGenerator.flush(UTF8JsonGenerator.java:1200)
at com.google.api.client.json.jackson2.JacksonGenerator.flush(JacksonGenerator.java:46)
at com.google.api.client.http.json.JsonHttpContent.writeTo(JsonHttpContent.java:77)
at com.google.api.client.http.GZipEncoding.encode(GZipEncoding.java:53)
at com.google.api.client.http.HttpEncodingStreamingContent.writeTo(HttpEncodingStreamingContent.java:48)
at com.google.api.client.http.javanet.NetHttpRequest$DefaultOutputWriter.write(NetHttpRequest.java:76)
at com.google.api.client.http.javanet.NetHttpRequest.writeContentToOutputStream(NetHttpRequest.java:174)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:117)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:84)
at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1012)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:514)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:455)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.execute(AbstractGoogleClientRequest.java:565)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:505)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at cats.effect.unsafe.WorkerThread.blockOn(WorkerThread.scala:668)
at scala.concurrent.package$.blocking(package.scala:124)
at cats.effect.IOFiber.runLoop(IOFiber.scala:953)
at cats.effect.IOFiber.execR(IOFiber.scala:1319)
at cats.effect.IOFiber.run(IOFiber.scala:118)
at cats.effect.unsafe.WorkerThread.run(WorkerThread.scala:585)
com.google.cloud.bigquery.BigQueryException: Error writing request body to server
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.translate(HttpBigQueryRpc.java:115)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:507)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at flatMap @ com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.go$1(Bigquery.scala:54)
at flatMap @ fs2.Stream.$anonfun$parEvalMapAction$6(Stream.scala:2140)
Caused by: java.io.IOException: Error writing request body to server
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(Unknown Source)
at java.base/java.io.BufferedOutputStream.flushBuffer(Unknown Source)
at java.base/java.io.BufferedOutputStream.flush(Unknown Source)
at java.base/java.util.zip.DeflaterOutputStream.flush(Unknown Source)
at com.fasterxml.jackson.core.json.UTF8JsonGenerator.flush(UTF8JsonGenerator.java:1200)
at com.google.api.client.json.jackson2.JacksonGenerator.flush(JacksonGenerator.java:46)
at com.google.api.client.http.json.JsonHttpContent.writeTo(JsonHttpContent.java:77)
at com.google.api.client.http.GZipEncoding.encode(GZipEncoding.java:53)
at com.google.api.client.http.HttpEncodingStreamingContent.writeTo(HttpEncodingStreamingContent.java:48)
at com.google.api.client.http.javanet.NetHttpRequest$DefaultOutputWriter.write(NetHttpRequest.java:76)
at com.google.api.client.http.javanet.NetHttpRequest.writeContentToOutputStream(NetHttpRequest.java:174)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:117)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:84)
at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1012)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:514)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:455)
at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.execute(AbstractGoogleClientRequest.java:565)
at com.google.cloud.bigquery.spi.v2.HttpBigQueryRpc.insertAll(HttpBigQueryRpc.java:505)
at com.google.cloud.bigquery.BigQueryImpl.insertAll(BigQueryImpl.java:1097)
at com.snowplowanalytics.snowplow.storage.bigquery.streamloader.Bigquery$.$anonfun$mkInsert$2(Bigquery.scala:91)
at cats.effect.unsafe.WorkerThread.blockOn(WorkerThread.scala:668)
at scala.concurrent.package$.blocking(package.scala:124)
at cats.effect.IOFiber.runLoop(IOFiber.scala:953)
at cats.effect.IOFiber.execR(IOFiber.scala:1319)
at cats.effect.IOFiber.run(IOFiber.scala:118)
at cats.effect.unsafe.WorkerThread.run(WorkerThread.scala:585)
Here is also a chart from when we were running the load test that shows the message rate decline:
We started the test around 2:30pm and you can see the ack rate jump to about 700 messages/second while our number of unacked messages slowly climbs then at around 4:00 the ack rate dropped drastically to about 30 messages/second then slowly declines over the course of the next 8 hours while the unacked count climbs until our load test finished running at around 5:00pm. Around midnight is when I restarted the container and you can see the ack rate jump to almost 800 messages/second and pretty quickly clear out the backlog of unacked messages.
Are there any configurations we can look at or recommendations you all have on how to ensure that we don’t run into this issue in production?
Thank you in advance for your help!