Hello,
I am running an Elixir app with two shared instances (FRA, CDG). In the last few days there were times were the response times were really high (up to 30s). I couldn’t see an unusual amount of traffic during that time.
The last two days (CET):
Are you aware of something in those regions? As I am using shared instances, could it be that the instance was utilized by another customer too much that I was impacted like this?
Thank you.
I could observe it today again. And again there wasn’t much more traffic nor much load on the system…
Do you see anything noteworthy in the app’s VM logs?
Hi,
no, just the longer response times, but nothing else… And there is always just one instance impacted.
2022-01-20T10:00:41.514 app[a50785ba] cdg [info]10:00:38.222 request_id=FsvyO7-CuzglTE4AAxUh [info] Sent 200 in 10685ms
2022-01-20T10:00:41.514 app[a50785ba] cdg [info]10:00:38.719 request_id=FsvyPL1ohAacazgAAxXx [info] Sent 200 in 6922ms
2022-01-20T10:00:41.514 app[a50785ba] cdg [info]10:00:38.764 request_id=FsvyO9BbHKuaSwAAAxVR [info] Sent 200 in 10945ms
2022-01-20T10:00:41.514 app[a50785ba] cdg [info]10:00:39.072 request_id=FsvyPNhJQhZbHeMAAxYB [info] Sent 200 in 6824ms
2022-01-20T10:00:41.514 app[a50785ba] cdg [info]10:00:39.550 request_id=FsvyPQunux-l6sAAAxYR [info] Sent 200 in 6440ms
2022-01-20T10:00:41.514 app[a50785ba] cdg [info]10:00:39.604 request_id=FsvyPChdHjhPZOIAAxWh [info] Sent 200 in 10308ms
2022-01-20T10:00:41.514 app[a50785ba] cdg [info]10:00:39.819 request_id=FsvyPRy1zPpi05AAAxYh [info] Sent 200 in 6424ms
2022-01-20T10:00:41.514 app[a50785ba] cdg [info]10:00:39.909 request_id=FsvyPT-L1o5kKgAAAxYx [info] Sent 200 in 5929ms
2022-01-20T10:00:41.514 app[a50785ba] cdg [info]10:00:39.998 request_id=FsvyPUW0j0X5XgIAAxZB [info] Sent 200 in 5915ms
2022-01-20T10:00:41.965 app[a50785ba] cdg [info]10:00:40.450 request_id=FsvyPY9rPiBH2r8AAxZR [info] Sent 200 in 5130ms
2022-01-20T10:00:41.965 app[a50785ba] cdg [info]10:00:40.819 request_id=FsvyPb42odXQzk4AAxZh [info] Sent 200 in 4714ms
2022-01-20T10:00:41.965 app[a50785ba] cdg [info]10:00:40.912 request_id=FsvyPmmzQH4zi84AAxaB [info] Sent 200 in 1930ms
2022-01-20T10:00:41.965 app[a50785ba] cdg [info]10:00:41.081 request_id=FsvyPdXsabAjdDQAAxZx [info] Sent 200 in 4578ms
Usually it looks like this:
2022-01-20T10:17:07.009 app[a50785ba] cdg [info]10:17:06.789 request_id=FsvzJGR1JpRc6UgAA0Fh [info] Sent 200 in 52ms
2022-01-20T10:17:07.283 app[a50785ba] cdg [info]10:17:07.043 request_id=FsvzJHPQhnEWqfgAA0Fx [info] Sent 200 in 49ms
2022-01-20T10:17:07.955 app[86a2d9db] fra [info]10:17:07.495 request_id=FsvzJJGsg9eFDa8AAIqB [info] Sent 302 in 236µs
2022-01-20T10:17:08.126 app[86a2d9db] fra [info]10:17:07.710 request_id=FsvzJJ54j-Hq_TIAAIqR [info] Sent 200 in 510µs
2022-01-20T10:17:08.527 app[a50785ba] cdg [info]10:17:08.286 request_id=FsvzJL4KbEEeHegAA0GB [info] Sent 200 in 47ms
2022-01-20T10:17:10.257 app[a50785ba] cdg [info]10:17:09.998 request_id=FsvzJSQU5WcMz9AAA0GR [info] Sent 200 in 47ms
2022-01-20T10:17:10.779 app[a50785ba] cdg [info]10:17:10.521 request_id=FsvzJUMyELG6elIAA0Gh [info] Sent 200 in 48ms
PS: I removed the lines with the beginning of the request like POST /my/path as that’s basically the same path all the time (API).
This looks like the app itself is slow to send a response.
Are you connecting to a Postgres database with this app by chance? That looks like something that might happen if the fra Elixir app isn’t reading from the right replica.
Yes it’s connecting to a Postgres in FRA. But every instance reads/writes to the master PG.
The whole Postgres cluster is in FRA (without read replicas at other locations). IMHO CDG should be close enough for using the remote PG. Not all API requests need PG, so I wanted to have at least some location redundancy.
Until my last post there weren’t any further issues. But I could keep everything in FRA for some time to see whether I have the issue again.
As there were extreme long response times in the CDG region today starting at 4pm UTC, I disabled that region and only keep one instance in FRA where the DB cluster is.
Also here I saw some very long response time in between:
2022-01-26T16:35:50.288 app[395593cc] fra [info]16:35:46.581 request_id=Fs3fSaw2TT6kIkcAACbh [info] Sent 200 in 6ms
2022-01-26T16:35:50.288 app[395593cc] fra [info]16:35:46.592 request_id=Fs3fSazieyudeoQAACbx [info] Sent 200 in 6ms
2022-01-26T16:35:50.288 app[395593cc] fra [info]16:35:46.784 request_id=Fs3fSPP-zzYPcYMAACZh [info] Sent 200 in 3299ms
2022-01-26T16:35:50.288 app[395593cc] fra [info]16:35:47.138 request_id=Fs3fSQp0x2GtC1YAACZx [info] Sent 200 in 3276ms
2022-01-26T16:35:51.972 app[395593cc] fra [info]16:35:48.448 request_id=Fs3fSV8REbX5JsoAACbB [info] Sent 200 in 3167ms
2022-01-26T16:35:51.972 app[395593cc] fra [info]16:35:48.705 request_id=Fs3fSWrhy_q0U20AACbR [info] Sent 200 in 3226ms
2022-01-26T16:35:51.972 app[395593cc] fra [info]16:35:49.825 request_id=Fs3fSccEBYLJxLoAACcB [info] Sent 200 in 2800ms
2022-01-26T16:35:51.972 app[395593cc] fra [info]16:35:50.159 request_id=Fs3fSRuHorzBQksAACaB [info] Sent 200 in 6011ms
2022-01-26T16:35:53.004 app[395593cc] fra [info]16:35:50.293 request_id=Fs3fSRv6Cf_3ugMAACaR [info] Sent 200 in 6138ms
2022-01-26T16:35:53.004 app[395593cc] fra [info]16:35:50.409 request_id=Fs3fSSEMbMB3AgsAACah [info] Sent 200 in 6169ms
2022-01-26T16:35:53.004 app[395593cc] fra [info]16:35:50.619 request_id=Fs3fShCTlB_fF9gAACcR [info] Sent 200 in 2360ms
2022-01-26T16:35:53.004 app[395593cc] fra [info]16:35:50.999 request_id=Fs3fSiejHxD9JEAAACch [info] Sent 200 in 2352ms
2022-01-26T16:35:53.004 app[395593cc] fra [info]16:35:51.594 request_id=Fs3fSkgtvjYqUIIAACcx [info] Sent 200 in 2402ms
2022-01-26T16:35:53.004 app[395593cc] fra [info]16:35:51.841 request_id=Fs3fSuWutHiILRAAACdB [info] Sent 200 in 7ms
2022-01-26T16:35:55.700 app[395593cc] fra [info]16:35:55.291 request_id=Fs3fS7NMeaPFHzIAACdR [info] Sent 200 in 7ms
2022-01-26T16:36:00.757 app[395593cc] fra [info]16:36:00.040 request_id=Fs3fTM6gqyYHOM8AACdh [info] Sent 200 in 2ms
2022-01-26T16:36:06.498 app[395593cc] fra [info]16:36:05.094 request_id=Fs3fTftzMKFnvFoAACdx [info] Sent 200 in 10ms
2022-01-26T16:36:06.498 app[395593cc] fra [info]16:36:05.669 request_id=Fs3fTh3V4wpGGyUAACeB [info] Sent 200 in 7ms
2022-01-26T16:36:07.707 app[395593cc] fra [info]16:36:07.303 request_id=Fs3fTn9Ig40D9UoAACeR [info] Sent 200 in 7ms
2022-01-26T16:36:09.286 app[395593cc] fra [info]16:36:08.844 request_id=Fs3fTttUZHGnvcEAACeh [info] Sent 200 in 4ms
2022-01-26T16:36:10.961 app[395593cc] fra [info]16:36:10.322 request_id=Fs3fTzMvLZHrXLgAACex [info] Sent 200 in 7ms
2022-01-26T16:36:12.545 app[395593cc] fra [info]16:36:12.172 request_id=Fs3fT6F8HSosrdwAACfB [info] Sent 200 in 6ms
That’s the same API endpoint and function. Nothing special. What can I do on this case? Seems like a Fly issue from my POV.
And it happened again suddenly - out of nowhere. Not higher traffic than usual, only on one instance (CDG region again).
2022-02-01T13:32:31.532 app[e6f779b7] cdg [info]13:32:24.987 request_id=Fs-supBPL43dlKYACxfx [info] Sent 200 in 38689ms
2022-02-01T13:32:31.532 app[e6f779b7] cdg [info]13:32:25.104 request_id=Fs-svS1JCkC0OJwACxqB [info] Sent 200 in 27582ms
2022-02-01T13:32:37.912 app[e6f779b7] cdg [info]13:32:25.313 request_id=Fs-susEsaxbZJo0ACxgh [info] Sent 200 in 38195ms
2022-02-01T13:32:37.912 app[e6f779b7] cdg [info]13:32:25.920 request_id=Fs-svVaUvpSHkoYACxrB [info] Sent 200 in 27706ms
2022-02-01T13:32:37.913 app[e6f779b7] cdg [info]13:32:26.962 request_id=Fs-su0d5asAmcEMACxiR [info] Sent 200 in 37591ms
2022-02-01T13:32:37.913 app[e6f779b7] cdg [info]13:32:27.044 request_id=Fs-su1BjqSYG58YACxih [info] Sent 200 in 37523ms
2022-02-01T13:32:37.913 app[e6f779b7] cdg [info]13:32:27.820 request_id=Fs-su3lJNR1mYc8ACxjR [info] Sent 200 in 37613ms
2022-02-01T13:32:37.913 app[e6f779b7] cdg [info]13:32:28.066 request_id=Fs-su4nyXeWndTEACxkB [info] Sent 200 in 37580ms
2022-02-01T13:32:37.913 app[e6f779b7] cdg [info]13:32:28.312 request_id=Fs-su6EuXl0iLiIACxkR [info] Sent 200 in 37435ms
2022-02-01T13:32:37.913 app[e6f779b7] cdg [info]13:32:29.045 request_id=Fs-svAZBo-kH6HsACxlh [info] Sent 200 in 36473ms
2022-02-01T13:32:37.913 app[e6f779b7] cdg [info]13:32:29.372 request_id=Fs-svDd-o4qXkdQACxmh [info] Sent 200 in 35973ms
2022-02-01T13:32:37.913 app[e6f779b7] cdg [info]13:32:29.539 request_id=Fs-svEIdnIFj4qAACxnB [info] Sent 200 in 35962ms
2022-02-01T13:32:37.913 app[e6f779b7] cdg [info]13:32:29.704 request_id=Fs-svFlD0ZpphrUACxnh [info] Sent 200 in 35739ms
@kurt
To be honest, it seems that Fly is not ready yet to serve production traffic. I can’t explain to my customers all the issues we saw in the last weeks. I mean, alone Network issues in FRA and AMS - #12 by kurt was a big disaster: one region was off for hours without a real explanation. I understand that it was night for you at this time. But at the same time you’re operating a global hosting provider, that shouldn’t be an issue.
I understand that there are incidents from time to time. But I lose more and more trust when I see how issues and incidents are handled. It’s sad as I had big hopes in your platform. But I need to have a more stable platform.
I do not think these slow requests in the logs are related to our infrastructure. Those are app logs, and I’d like to understand more about what you’re actually doing + logging there.
The Frankfurt issue last week manifested as slow TLS handshakes, it happened before it hit your app process. An app that logs ~30s to send responses is experiencing something else. Thats 30 seconds spent in the app process.
Can you add more info to these app logs? Specifically, the fly-request-id header and the fly-region header. It would be helpful to know what part of the world these requests are coming from, and our request ID will let us look at some proxy level diagnostics that may or may not be helpful.
For what it’s worth, I would not run app processes in CDG that have to write to Postgres in FRA.
Unfortunately I can’t add this log right now, but I will do it as soon as possible. Whenever we see that problem again, it will be there then. But all the traffic comes basically from around Washington as we’re a Slack app. So whenever someone does something in Slack we get an event. Or when specific data is changed, we get an event too.
However, I just checked the metrics Fly provides OOTB:
Here you can see the spiking HTTP response times. The interesting one is the last spike around 2:37pm. When I saw the long response times I scaled the deployment down to 1 instance. As the backup one is in CDG, the CDG has been shut down (I verified with fly status). I did that at 2:33pm. That means that the FRA instance had that spike later.
Interestingly we see a high vm service concurrency here, but only for one instance. And no spike for the other instance at 2:37pm 
How is vm service concurrency defined? My assumption was that the shared vm was utilized too much?! Would a dedicated instance help in this case?
PS: Unfortunately I can’t run multiple instances in the same region currently (no shared state yet for login sessions). But yes, I will fix that soon so that all instances are as close to the DB as possible.
It’s happening again. After I noticed that I started another instance in CDG to keep some requests working until it’s stable again.
Good that I added your requested header already.
2022-02-02T09:03:14Z app[dd723ea0] fra [info]09:03:04.691 request_id=Fs_so2PO0Vp6-gIAAMdB [info] Fly Header: fly-region iad fly-request-id 01FTWTRAWD9AHAT6QQS4BAYP5T
2022-02-02T09:03:14Z app[dd723ea0] fra [info]09:03:04.779 request_id=Fs_snEn6_m1Ar9gAAMRB [info] Sent 200 in 39765ms
2022-02-02T09:03:14Z app[dd723ea0] fra [info]09:03:04.866 request_id=Fs_snFUei6YsGhIAAMRR [info] Sent 200 in 39665ms
2022-02-02T09:03:14Z app[dd723ea0] fra [info]09:03:05.065 request_id=Fs_snITeOOr8LzMAAMRh [info] Sent 200 in 39064ms
2022-02-02T09:03:14Z app[dd723ea0] fra [info]09:03:05.379 request_id=Fs_snJcJyOv9M-IAAMRx [info] Sent 200 in 39072ms
2022-02-02T09:03:14Z app[dd723ea0] fra [info]09:03:05.688 request_id=Fs_snK8TyZkCmFgAAMSB [info] Sent 200 in 38978ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:06.086 request_id=Fs_spdoUaINIWmwAAMfR [info] POST /myhandler
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:06.382 request_id=Fs_so5Ed65LOXksAAMdR [info] Fly Header: fly-region iad fly-request-id 01FTWTRBM1BQPNCH05MVP5HTYH
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:06.424 request_id=Fs_spe46mKkAQvoAAMfh [info] POST /myhandler
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:06.470 request_id=Fs_snNGk_4hmArEAAMSR [info] Sent 200 in 39181ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:06.637 request_id=Fs_smRDa_YxE4_sAAMLB [info] Sent 200 in 55467ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:06.723 request_id=Fs_smRMDjvTnTWwAAMLR [info] Sent 200 in 55516ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:06.997 request_id=Fs_so6j7QL3yT34AAMdh [info] Fly Header: fly-region iad fly-request-id 01FTWTRC0PYP44XM5DV3SFY1KM
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:07.094 request_id=Fs_snPj1ReTNZqwAAMSh [info] Sent 200 in 39144ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:07.183 request_id=Fs_so7KHnP2JuvkAAMdx [info] Fly Header: fly-region iad fly-request-id 01FTWTRC5PXRWFNQGFE4CRJF4H
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:07.270 request_id=Fs_snQzrxQLyGLcAAMSx [info] Sent 200 in 38986ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:07.359 request_id=Fs_snURVJvNnRnEAAMTB [info] Sent 200 in 38145ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:07.792 request_id=Fs_snU1QzCVc7hYAAMTR [info] Sent 200 in 38428ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:07.880 request_id=Fs_snWQPCB1V9j0AAMTh [info] Sent 200 in 38134ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.052 request_id=Fs_snYi9M5zQWHcAAMTx [info] Sent 200 in 37690ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.055 request_id=Fs_spk9-HjuMYaUAAMfx [info] POST /myhandler
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.077 request_id=Fs_splDLWlas_2MAAMgB [info] POST /myhandler
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.137 request_id=Fs_so-39WNGiq-cAAMeB [info] Fly Header: fly-region iad fly-request-id 01FTWTRD4T269BZZ4ACA71JWB9
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.311 request_id=Fs_snZJ37i8X5zIAAMUB [info] Sent 200 in 37786ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.336 request_id=Fs_spmA84imGy5oAAMgR [info] POST /myhandler
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.393 request_id=Fs_smcoUtJU5lQsAAMLx [info] Sent 200 in 54115ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.649 request_id=Fs_smcpLSIIn_xoAAMMB [info] Sent 200 in 54367ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.737 request_id=Fs_snbt3ar2UFq0AAMUR [info] Sent 200 in 37525ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:08.908 request_id=Fs_sncKhGObiyl4AAMUh [info] Sent 200 in 37575ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:09.081 request_id=Fs_sncPu0pd0rp0AAMUx [info] Sent 200 in 37726ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:09.377 request_id=Fs_spEJORvUcLJIAAMeR [info] Fly Header: fly-region iad fly-request-id 01FTWTREH0WYB2Z0EB5NS669D0
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:09.518 request_id=Fs_snko1_2yiz0EAAMVB [info] Sent 200 in 35911ms
2022-02-02T09:03:18Z app[dd723ea0] fra [info]09:03:09.653 request_id=Fs_spq68wh7lUHgAAMgh [info] POST /myhandler
2022-02-02T09:03:21Z app[b1bf1696] cdg [info]09:03:21.492 request_id=Fs_sqXBhD4rxpoIAAB2B [info] POST /myhandler
2022-02-02T09:03:21Z app[b1bf1696] cdg [info]09:03:21.517 request_id=Fs_sqXBhD4rxpoIAAB2B [info] Fly Header: fly-region iad fly-request-id 01FTWTS46BQTPKWB41QYMWFSKK
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:09.861 request_id=Fs_spGoHlU6ZwWoAAMeh [info] Fly Header: fly-region iad fly-request-id 01FTWTRF5X8PZYS20PVN0W642K
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:09.887 request_id=Fs_sprymLzNNgmMAAMgx [info] POST /myhandler
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:10.119 request_id=Fs_snyct-OHnwRYAAMVh [info] Sent 200 in 32804ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:10.278 request_id=Fs_sny-9sui_Ec0AAMVx [info] Sent 200 in 32820ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:10.377 request_id=Fs_sn2e1iV_9wLsAAMWB [info] Sent 200 in 31980ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:10.566 request_id=Fs_sn4AFZF_hq-cAAMWR [info] Sent 200 in 31761ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:10.823 request_id=Fs_sn4Or4KoeSw4AAMWh [info] Sent 200 in 31957ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:10.911 request_id=Fs_sn6UUXPvFrNsAAMWx [info] Sent 200 in 31484ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:11.029 request_id=Fs_spwC7RL_Y6noAAMhB [info] POST /myhandler
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:11.135 request_id=Fs_spwcRYLgeb9QAAMhR [info] POST /myhandler
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:11.149 request_id=Fs_spwfgfhbjX4cAAMhh [info] POST /myhandler
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:11.266 request_id=Fs_spw7dU-OemyMAAMhx [info] POST /myhandler
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:11.327 request_id=Fs_sn_A476UwWa0AAMXB [info] Sent 200 in 30639ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:11.378 request_id=Fs_spxWF6Xi3MZAAAMiB [info] POST /myhandler
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:11.895 request_id=Fs_soDY0Jz3zRKcAAMXR [info] Sent 200 in 30033ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:12.065 request_id=Fs_soDwNIVNMmAEAAMXh [info] Sent 200 in 30105ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:12.151 request_id=Fs_soFq12AwnvIUAAMXx [info] Sent 200 in 29677ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:12.285 request_id=Fs_sp0udluOsbhAAAMiR [info] POST /myhandler
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:12.497 request_id=Fs_soIHCgI0ZJZgAAMYB [info] Sent 200 in 29367ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:12.671 request_id=Fs_soKfNPVvxpHQAAMYR [info] Sent 200 in 28903ms
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:12.838 request_id=Fs_spSSCStkBEHQAAMex [info] Fly Header: fly-region iad fly-request-id 01FTWTRJ7KAERDFZT0NMJ89Z39
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:13.182 request_id=Fs_spTcDAhV0a90AAMfB [info] Fly Header: fly-region iad fly-request-id 01FTWTRJH8FSC1AA1H3PNVSS8B
2022-02-02T09:03:22Z app[dd723ea0] fra [info]09:03:13.345 request_id=Fs_sp4rKTJwrOOQAAMih [info] POST /myhandler
2022-02-02T09:03:22Z app[b1bf1696] cdg [info]09:03:21.562 request_id=Fs_sqXBhD4rxpoIAAB2B [info] Sent 200 in 70ms
2022-02-02T09:03:22Z app[b1bf1696] cdg [info]09:03:22.302 request_id=Fs_sqaCjXR31XIIAAB2x [info] POST /myhandler
2022-02-02T09:03:22Z app[b1bf1696] cdg [info]09:03:22.325 request_id=Fs_sqaCjXR31XIIAAB2x [info] Fly Header: fly-region iad fly-request-id 01FTWTS54KW5AQWRZGWS45VZB9
2022-02-02T09:03:22Z app[b1bf1696] cdg [info]09:03:22.368 request_id=Fs_sqaCjXR31XIIAAB2x [info] Sent 200 in 66ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:13.756 request_id=Fs_soTx0q69Hsl4AAMYh [info] Sent 200 in 27494ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:13.940 request_id=Fs_soU_igfiWxm8AAMYx [info] Sent 200 in 27352ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:14.183 request_id=Fs_sp7y7p758i9QAAMix [info] POST /myhandler
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:14.533 request_id=Fs_sp9Gblr60kMgAAMjB [info] POST /myhandler
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:14.952 request_id=Fs_spdoUaINIWmwAAMfR [info] Fly Header: fly-region iad fly-request-id 01FTWTRN6SP51RS1SZTQDEZ358
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:15.124 request_id=Fs_spe46mKkAQvoAAMfh [info] Fly Header: fly-region iad fly-request-id 01FTWTRNHBC460NZA6VJ9H331J
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:15.297 request_id=Fs_soayuvhYhI50AAMZB [info] Sent 200 in 27152ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:16.274 request_id=Fs_spk9-HjuMYaUAAMfx [info] Fly Header: fly-region iad fly-request-id 01FTWTRQ4B18C7GPB4RY9TBSPT
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:16.296 request_id=Fs_sqDqv0yuVlO8AAMjR [info] POST /myhandler
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:16.360 request_id=Fs_splDLWlas_2MAAMgB [info] Fly Header: fly-region iad fly-request-id 01FTWTRQ501FW4NCNFN771YNKY
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:16.413 request_id=Fs_sqEGpTY5MuAcAAMjh [info] POST /myhandler
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:16.549 request_id=Fs_sogOScMycA-cAAMZR [info] Sent 200 in 26947ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:16.721 request_id=Fs_spmA84imGy5oAAMgR [info] Fly Header: fly-region iad fly-request-id 01FTWTRQD5QYMA9JX3NWS04AMS
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:17.333 request_id=Fs_sohmcKoqjuOUAAMZh [info] Sent 200 in 27361ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:17.334 request_id=Fs_sqHiJHyRnUCgAAMjx [info] POST /myhandler
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:17.377 request_id=Fs_sqHsiLO6oNd0AAMkB [info] POST /myhandler
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:17.578 request_id=Fs_soh5A3pCe4VwAAMZx [info] Sent 200 in 27529ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:17.639 request_id=Fs_sqIqz2pqR73MAAMkR [info] POST /myhandler
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:17.932 request_id=Fs_sqJw1qdFkv5AAAMkh [info] POST /myhandler
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:17.947 request_id=Fs_sojnT3sifLJgAAMaB [info] Sent 200 in 27435ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:18.290 request_id=Fs_somLVewtsN7oAAMaR [info] Sent 200 in 27090ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:18.402 request_id=Fs_spq68wh7lUHgAAMgh [info] Fly Header: fly-region iad fly-request-id 01FTWTRRPCHVQ8V1WBK75J164Q
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:18.575 request_id=Fs_sprymLzNNgmMAAMgx [info] Fly Header: fly-region iad fly-request-id 01FTWTRRXM4G62FN77CRTYVGMD
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:18.663 request_id=Fs_som7-Hly6BXMAAMah [info] Sent 200 in 27259ms
2022-02-02T09:03:25Z app[dd723ea0] fra [info]09:03:18.760 request_id=Fs_snycrrxmaGmIAAMVR [info] Sent 200 in 41446ms
2022-02-02T09:03:27Z app[b1bf1696] cdg [info]09:03:27.111 request_id=Fs_sqr9NXB95FLgAAB3B [info] POST /myhandler
2022-02-02T09:03:27Z app[b1bf1696] cdg [info]09:03:27.135 request_id=Fs_sqr9NXB95FLgAAB3B [info] Fly Header: fly-region iad fly-request-id 01FTWTS9TW5SRA7NZ51WY78MT3
2022-02-02T09:03:27Z app[b1bf1696] cdg [info]09:03:27.179 request_id=Fs_sqr9NXB95FLgAAB3B [info] Sent 200 in 67ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:19.215 request_id=Fs_soq42Cj70FZQAAMax [info] Sent 200 in 26750ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:19.344 request_id=Fs_sqPBZ012wMEcAAMkx [info] POST /myhandler
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:19.453 request_id=Fs_sqPbdrMOWet8AAMlB [info] POST /myhandler
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:19.680 request_id=Fs_spwC7RL_Y6noAAMhB [info] Fly Header: fly-region iad fly-request-id 01FTWTRT1BKEDSVSGXZGPB5N3X
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:19.767 request_id=Fs_spwcRYLgeb9QAAMhR [info] Fly Header: fly-region iad fly-request-id 01FTWTRT4PKGV65T0N75BA6N35
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:19.854 request_id=Fs_spwfgfhbjX4cAAMhh [info] Fly Header: fly-region iad fly-request-id 01FTWTRT521R28AA2GS8FPJJHG
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:19.893 request_id=Fs_sqREMweGsh3kAAMlR [info] POST /myhandler
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:19.942 request_id=Fs_sos8FRIIsPvEAAMbB [info] Sent 200 in 26927ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:20.027 request_id=Fs_spw7dU-OemyMAAMhx [info] Fly Header: fly-region iad fly-request-id 01FTWTRT8RH1BERTQNSJTSA8CP
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:20.199 request_id=Fs_spxWF6Xi3MZAAAMiB [info] Fly Header: fly-region iad fly-request-id 01FTWTRTC735B009PDV8YW7GEW
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:20.226 request_id=Fs_sqSTvsuUnicEAAMlh [info] POST /myhandler
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:20.286 request_id=Fs_sotd-Gpz5nNQAAMbR [info] Sent 200 in 27129ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:20.994 request_id=Fs_sqVK2TdQX2CoAAMlx [info] POST /myhandler
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:21.198 request_id=Fs_sp0udluOsbhAAAMiR [info] Fly Header: fly-region iad fly-request-id 01FTWTRV8J7813ZCDWTVXM0XG8
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:21.285 request_id=Fs_sovLeFQoGYcwAAMbh [info] Sent 200 in 27668ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:21.374 request_id=Fs_sovPHKbcxmKUAAMbx [info] Sent 200 in 27742ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:21.886 request_id=Fs_soxnGzMt0ifMAAMcB [info] Sent 200 in 27616ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:21.972 request_id=Fs_soxxqgyQ9fBQAAMcR [info] Sent 200 in 27658ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.144 request_id=Fs_sp4rKTJwrOOQAAMih [info] Fly Header: fly-region iad fly-request-id 01FTWTRW9PSC4N0GGKTN2X03MP
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.236 request_id=Fs_sozUwq2Vf6BgAAMch [info] Sent 200 in 27506ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.490 request_id=Fs_sp7y7p758i9QAAMix [info] Fly Header: fly-region iad fly-request-id 01FTWTRX3XYJWN64E7VHPHM76T
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.578 request_id=Fs_so16RKp0yFu8AAMcx [info] Sent 200 in 27154ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.665 request_id=Fs_so2PO0Vp6-gIAAMdB [info] Sent 200 in 27153ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.739 request_id=Fs_sqbq5HttHd7gAAMmB [info] POST /myhandler
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.748 request_id=Fs_sp9Gblr60kMgAAMjB [info] Fly Header: fly-region iad fly-request-id 01FTWTRXEVV4R7FDD1MYB4A6P1
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.921 request_id=Fs_so5Ed65LOXksAAMdR [info] Sent 200 in 26649ms
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.941 request_id=Fs_sqcbFHclE1bgAAMmR [info] POST /myhandler
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:22.963 request_id=Fs_sqcgNrnaSyNIAAMmh [info] POST /myhandler
2022-02-02T09:03:28Z app[dd723ea0] fra [info]09:03:23.193 request_id=Fs_so6j7QL3yT34AAMdh [info] Sent 200 in 26521ms
2022-02-02T09:03:29Z app[b1bf1696] cdg [info]09:03:29.338 request_id=Fs_sq0QDzloeB5gAAB3R [info] POST /myhandler
2022-02-02T09:03:29Z app[b1bf1696] cdg [info]09:03:29.361 request_id=Fs_sq0QDzloeB5gAAB3R [info] Fly Header: fly-region iad fly-request-id 01FTWTSC0FJWF9Y2G793J29KR4
2022-02-02T09:03:29Z app[b1bf1696] cdg [info]09:03:29.404 request_id=Fs_sq0QDzloeB5gAAB3R [info] Sent 200 in 66ms
2022-02-02T09:03:30Z app[b1bf1696] cdg [info]09:03:30.776 request_id=Fs_sq5m7w748tnIAAB3h [info] POST /myhandler
2022-02-02T09:03:30Z app[b1bf1696] cdg [info]09:03:30.799 request_id=Fs_sq5m7w748tnIAAB3h [info] Fly Header: fly-region iad fly-request-id 01FTWTSDDDXMWXVE809KG5BJ5C
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:23.480 request_id=Fs_sqDqv0yuVlO8AAMjR [info] Fly Header: fly-region iad fly-request-id 01FTWTRZ5WT3F0EG3487YCH70G
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:23.652 request_id=Fs_sqEGpTY5MuAcAAMjh [info] Fly Header: fly-region iad fly-request-id 01FTWTRZ9KZ8E6E26RAX9XJ04H
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:23.739 request_id=Fs_so-39WNGiq-cAAMeB [info] Sent 200 in 25909ms
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:24.091 request_id=Fs_sqHiJHyRnUCgAAMjx [info] Fly Header: fly-region iad fly-request-id 01FTWTS06CPS9ADWBDB7SHK2DP
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:24.178 request_id=Fs_sqHsiLO6oNd0AAMkB [info] Fly Header: fly-region iad fly-request-id 01FTWTS07N4P7CS69K4PBV7AP2
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:24.348 request_id=Fs_sqIqz2pqR73MAAMkR [info] Fly Header: fly-region iad fly-request-id 01FTWTS0FT9D44WA8JPXWMN7K1
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:24.435 request_id=Fs_sqJw1qdFkv5AAAMkh [info] Fly Header: fly-region iad fly-request-id 01FTWTS0S0YYH1112YWG0RN7Z0
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:24.611 request_id=Fs_spEJORvUcLJIAAMeR [info] Sent 200 in 25366ms
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:25.296 request_id=Fs_sqPBZ012wMEcAAMkx [info] Fly Header: fly-region iad fly-request-id 01FTWTS252VE4XBMXQ2DVAF59C
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:25.380 request_id=Fs_sqPbdrMOWet8AAMlB [info] Fly Header: fly-region iad fly-request-id 01FTWTS28KXHHPZNTNVSM74ERH
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:25.721 request_id=Fs_sqREMweGsh3kAAMlR [info] Fly Header: fly-region iad fly-request-id 01FTWTS2P9JCMEJ0MGDXBHKK2Y
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:25.925 request_id=Fs_sqnidnBmsX_oAAMmx [info] POST /myhandler
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:26.062 request_id=Fs_sqSTvsuUnicEAAMlh [info] Fly Header: fly-region iad fly-request-id 01FTWTS30QQA891CV06VR6WM8G
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:26.234 request_id=Fs_sqVK2TdQX2CoAAMlx [info] Fly Header: fly-region iad fly-request-id 01FTWTS3RRX3TN4XY07081FK7R
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:26.309 request_id=Fs_sqo9_sAwLDjUAAMnB [info] POST /myhandler
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:26.370 request_id=Fs_sqpMjnjKrtfoAAMnR [info] POST /myhandler
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:26.580 request_id=Fs_spSSCStkBEHQAAMex [info] Sent 200 in 23540ms
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:26.836 request_id=Fs_spTcDAhV0a90AAMfB [info] Sent 200 in 23486ms
2022-02-02T09:03:31Z app[dd723ea0] fra [info]09:03:27.275 request_id=Fs_sqskJmziyObAAAMnh [info] POST /myhandler
2022-02-02T09:03:31Z app[b1bf1696] cdg [info]09:03:30.843 request_id=Fs_sq5m7w748tnIAAB3h [info] Sent 200 in 67ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:27.645 request_id=Fs_sqbq5HttHd7gAAMmB [info] Fly Header: fly-region iad fly-request-id 01FTWTS5F7M47HRT2ZAHFRM8WN
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:27.818 request_id=Fs_spdoUaINIWmwAAMfR [info] Sent 200 in 21732ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:27.836 request_id=Fs_squp52iRiDtMAAMnx [info] POST /myhandler
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:27.988 request_id=Fs_sqcbFHclE1bgAAMmR [info] Fly Header: fly-region iad fly-request-id 01FTWTS5NHPYHJH2BGKK1F1D47
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:28.074 request_id=Fs_sqcgNrnaSyNIAAMmh [info] Fly Header: fly-region iad fly-request-id 01FTWTS5P9JQVNK21063018EBC
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:28.164 request_id=Fs_spe46mKkAQvoAAMfh [info] Sent 200 in 21740ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:28.331 request_id=Fs_so7KHnP2JuvkAAMdx [info] Sent 200 in 31498ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:28.409 request_id=Fs_sqwym2VSfu-AAAMoB [info] POST /myhandler
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:28.426 request_id=Fs_spk9-HjuMYaUAAMfx [info] Sent 200 in 20370ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:28.596 request_id=Fs_splDLWlas_2MAAMgB [info] Sent 200 in 20518ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:28.853 request_id=Fs_spmA84imGy5oAAMgR [info] Sent 200 in 20517ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:29.373 request_id=Fs_spq68wh7lUHgAAMgh [info] Sent 200 in 19719ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:29.455 request_id=Fs_spGoHlU6ZwWoAAMeh [info] Sent 200 in 29544ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:29.543 request_id=Fs_sprymLzNNgmMAAMgx [info] Sent 200 in 19656ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:29.806 request_id=Fs_spwC7RL_Y6noAAMhB [info] Sent 200 in 18776ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:29.891 request_id=Fs_spwcRYLgeb9QAAMhR [info] Sent 200 in 18755ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:29.978 request_id=Fs_spwfgfhbjX4cAAMhh [info] Sent 200 in 18828ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:30.237 request_id=Fs_sqnidnBmsX_oAAMmx [info] Fly Header: fly-region iad fly-request-id 01FTWTS8JTAR17WQW1YT9927CM
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:30.341 request_id=Fs_spxWF6Xi3MZAAAMiB [info] Sent 200 in 18963ms
2022-02-02T09:03:34Z app[dd723ea0] fra [info]09:03:30.397 request_id=Fs_sq4MkRkIoIhEAAMoR [info] POST /myhandler
2022-02-02T09:03:35Z app[b1bf1696] cdg [info]09:03:35.725 request_id=Fs_srMC4LcyutwkAAB3x [info] POST /myhandler
2022-02-02T09:03:35Z app[b1bf1696] cdg [info]09:03:35.747 request_id=Fs_srMC4LcyutwkAAB3x [info] Fly Header: fly-region iad fly-request-id 01FTWTSJ827WZX3D29FG0473RV
2022-02-02T09:03:36Z app[b1bf1696] cdg [info]09:03:35.747 request_id=Fs_srMC4LcyutwkAAB3x [info] Sent 200 in 22ms
PS: /myhandler is not the real name, but it’s always the same API endpoint that is called.
I just deployed a change so that I can finally run multiple instances in one region. Now there are three instances in FRA. Still there are some longer response times in between. And it looks like only one instance is hit.
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:21.703 request_id=Fs_x2BMztz8sEj4AAIGR [info] Fly Header: fly-region iad fly-request-id 01FTX070GQ2GAP0HRZ9MTEFH3S
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:21.960 request_id=Fs_x1xAYDRqoYDIAAICB [info] Sent 200 in 6957ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:22.480 request_id=Fs_x2ENxWCr42dMAAIGh [info] Fly Header: fly-region iad fly-request-id 01FTX071A1Y7CT46EXAYCMAPSD
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:22.566 request_id=Fs_x2EwCTd_IjKgAAIGx [info] Fly Header: fly-region iad fly-request-id 01FTX071EGM77P3DPWXS9599E6
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:22.653 request_id=Fs_x10LVUJq62rYAAICh [info] Sent 200 in 6798ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:22.820 request_id=Fs_x1t-3UMpjja8AAIBR [info] Sent 200 in 8628ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:23.078 request_id=Fs_x11s4qg1ErcYAAICx [info] Sent 200 in 6814ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:23.295 request_id=Fs_x2P5W2UnOmYsAAIHR [info] POST /myhandler
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:24.004 request_id=Fs_x2Sioxp6n8eoAAIHh [info] POST /myhandler
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:24.295 request_id=Fs_x112Z9ouwJVYAAIDB [info] Sent 200 in 7991ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:24.406 request_id=Fs_x112yESToy68AAIDR [info] Sent 200 in 8100ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:24.487 request_id=Fs_x2HG9y6q_L1kAAIHB [info] Fly Header: fly-region iad fly-request-id 01FTX0722D9HM7930X4G03NH1Q
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:24.581 request_id=Fs_x12BTR-G97YgAAIDh [info] Sent 200 in 8231ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:24.685 request_id=Fs_x12P66NGFxsMAAIDx [info] Sent 200 in 8274ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:24.744 request_id=Fs_x12QWLryVPoQAAIEB [info] Sent 200 in 8331ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:24.835 request_id=Fs_x12TGRZBDw1cAAIER [info] Sent 200 in 8411ms
2022-02-02T10:38:27Z app[73c5cf36] fra [info]10:38:24.915 request_id=Fs_x1uYLV-sKlJEAAIBh [info] Sent 200 in 10616ms
2022-02-02T10:38:28Z app[73c5cf36] fra [info]10:38:25.258 request_id=Fs_x15G4SLAkXqcAAIEh [info] Sent 200 in 8079ms
2022-02-02T10:38:28Z app[73c5cf36] fra [info]10:38:25.354 request_id=Fs_x15cIfyFfGucAAIEx [info] Sent 200 in 8086ms
2022-02-02T10:38:28Z app[73c5cf36] fra [info]10:38:25.523 request_id=Fs_x15h6ucFvVDAAAIFR [info] Sent 200 in 8231ms
2022-02-02T10:38:28Z app[73c5cf36] fra [info]10:38:25.883 request_id=Fs_x18vdnxvpxe8AAIFh [info] Sent 200 in 7729ms
2022-02-02T10:38:28Z app[73c5cf36] fra [info]10:38:26.055 request_id=Fs_x19Eu2tFfdpEAAIFx [info] Sent 200 in 7812ms
2022-02-02T10:38:28Z app[73c5cf36] fra [info]10:38:26.306 request_id=Fs_x2P5W2UnOmYsAAIHR [info] Fly Header: fly-region iad fly-request-id 01FTX074BXE8RMQEGX8BH6Q091
2022-02-02T10:38:28Z app[73c5cf36] fra [info]10:38:26.390 request_id=Fs_x2Sioxp6n8eoAAIHh [info] Fly Header: fly-region iad fly-request-id 01FTX07525KNKJMTVMZ23F9E3J
2022-02-02T10:38:28Z app[73c5cf36] fra [info]10:38:26.777 request_id=Fs_x2c3c95oGZyUAAIHx [info] POST /myhandler
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:27.210 request_id=Fs_x2BMztz8sEj4AAIGR [info] Sent 200 in 7860ms
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:27.459 request_id=Fs_x15hThJwY4-IAAIFB [info] Sent 200 in 10169ms
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:27.634 request_id=Fs_x2ENxWCr42dMAAIGh [info] Sent 200 in 7474ms
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:27.718 request_id=Fs_x2EwCTd_IjKgAAIGx [info] Sent 200 in 7414ms
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:27.974 request_id=Fs_x19GSFVX_L6sAAIGB [info] Sent 200 in 9724ms
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:28.069 request_id=Fs_x2P5W2UnOmYsAAIHR [info] Sent 200 in 4773ms
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:28.149 request_id=Fs_x2Sioxp6n8eoAAIHh [info] Sent 200 in 4143ms
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:28.322 request_id=Fs_x2HG9y6q_L1kAAIHB [info] Sent 200 in 7385ms
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:28.410 request_id=Fs_x2c3c95oGZyUAAIHx [info] Fly Header: fly-region iad fly-request-id 01FTX077RY7G8BMP6YP130TQ1T
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:28.414 request_id=Fs_x2c3c95oGZyUAAIHx [info] Sent 200 in 1637ms
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:28.948 request_id=Fs_x2k9Fspd74YcAAIIB [info] POST /myhandler
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:28.951 request_id=Fs_x2k9Fspd74YcAAIIB [info] Fly Header: fly-region iad fly-request-id 01FTX079ZESH7GQ7AQM9WAFGWX
2022-02-02T10:38:29Z app[73c5cf36] fra [info]10:38:28.955 request_id=Fs_x2k9Fspd74YcAAIIB [info] Sent 200 in 6ms
2022-02-02T10:38:30Z app[73c5cf36] fra [info]10:38:29.638 request_id=Fs_x2nhhekjSz-UAAIIR [info] POST /myhandler
2022-02-02T10:38:30Z app[73c5cf36] fra [info]10:38:29.640 request_id=Fs_x2nhhekjSz-UAAIIR [info] Fly Header: fly-region iad fly-request-id 01FTX07AJB9B02VXAMADFC4XD0
2022-02-02T10:38:30Z app[73c5cf36] fra [info]10:38:29.645 request_id=Fs_x2nhhekjSz-UAAIIR [info] Sent 200 in 7ms
2022-02-02T10:38:30Z app[73c5cf36] fra [info]10:38:30.502 request_id=Fs_x2qvmbF922SgAAIIh [info] POST /myhandler
2022-02-02T10:38:30Z app[73c5cf36] fra [info]10:38:30.506 request_id=Fs_x2qvmbF922SgAAIIh [info] Fly Header: fly-region iad fly-request-id 01FTX07BG12T28EH5QH0WS0D6K
2022-02-02T10:38:30Z app[73c5cf36] fra [info]10:38:30.511 request_id=Fs_x2qvmbF922SgAAIIh [info] Sent 200 in 8ms
2022-02-02T10:38:34Z app[73c5cf36] fra [info]10:38:34.467 request_id=Fs_x25g3xrofh7AAAIIx [info] POST /myhandler
2022-02-02T10:38:34Z app[73c5cf36] fra [info]10:38:34.471 request_id=Fs_x25g3xrofh7AAAIIx [info] Fly Header: fly-region iad fly-request-id 01FTX07F9946KNDPJQVM9957GD
2022-02-02T10:38:35Z app[73c5cf36] fra [info]10:38:34.475 request_id=Fs_x25g3xrofh7AAAIIx [info] Sent 200 in 8ms
2022-02-02T10:38:35Z app[73c5cf36] fra [info]10:38:34.544 request_id=Fs_x25zHrwB8Lf0AAIJB [info] POST /myhandler
2022-02-02T10:38:35Z app[73c5cf36] fra [info]10:38:34.546 request_id=Fs_x25zHrwB8Lf0AAIJB [info] Fly Header: fly-region iad fly-request-id 01FTX07FBNR490VR0BGRNM1PC3
2022-02-02T10:38:35Z app[73c5cf36] fra [info]10:38:34.551 request_id=Fs_x25zHrwB8Lf0AAIJB [info] Sent 200 in 7ms
2022-02-02T10:38:40Z app[73c5cf36] fra [info]10:38:40.197 request_id=Fs_x3O2_c6QGXaEAAIJR [info] POST /myhandler
2022-02-02T10:38:40Z app[73c5cf36] fra [info]10:38:40.204 request_id=Fs_x3O2_c6QGXaEAAIJR [info] Fly Header: fly-region iad fly-request-id 01FTX07MZ33GG03PF1829KX8GJ
2022-02-02T10:38:40Z app[73c5cf36] fra [info]10:38:40.208 request_id=Fs_x3O2_c6QGXaEAAIJR [info] Sent 200 in 11ms
2022-02-02T10:38:42Z app[73c5cf36] fra [info]10:38:42.157 request_id=Fs_x3WKbQRyny9QAAIJh [info] POST /myhandler
2022-02-02T10:38:42Z app[73c5cf36] fra [info]10:38:42.160 request_id=Fs_x3WKbQRyny9QAAIJh [info] Fly Header: fly-region iad fly-request-id 01FTX07PWAVM9JT68VZJGXMEV0
2022-02-02T10:38:42Z app[73c5cf36] fra [info]10:38:42.165 request_id=Fs_x3WKbQRyny9QAAIJh [info] Sent 200 in 7ms
2022-02-02T10:38:42Z app[142d5f71] fra [info]10:38:42.542 request_id=Fs_x3XmBRQoA2lcAAB9x [info] GET /checkly
2022-02-02T10:38:42Z app[73c5cf36] fra [info]10:38:42.721 request_id=Fs_x3YQvtHk1TdAAAIJx [info] POST /myhandler
2022-02-02T10:38:42Z app[73c5cf36] fra [info]10:38:42.724 request_id=Fs_x3YQvtHk1TdAAAIJx [info] Fly Header: fly-region iad fly-request-id 01FTX07QDWCSCA7YW1BX3G6VX8
2022-02-02T10:38:42Z app[142d5f71] fra [info]10:38:42.542 request_id=Fs_x3XmBRQoA2lcAAB9x [info] Sent 302 in 260µs
2022-02-02T10:38:43Z app[73c5cf36] fra [info]10:38:42.729 request_id=Fs_x3YQvtHk1TdAAAIJx [info] Sent 200 in 8ms
I was also checking what exactly is happening when we got an API hit. Basically it’s updating a record IF the information is different. So one SELECT (based on indexed ID) and maybe an UPDATE.
It could be that we get many change events at once. How is Fly handling that? Currently mostly all of the requests are processed by one instance although we have 3 in total in FRA. How does the load balancing work? It’s obviously not round robin… @kurt
If you don’t mind, could you show a skeleton of the SQL statements and logic you use for this.
Reason for asking - have you measured how long it takes to do this conditional update logic if you try this stand-alone, on a test copy of the DB; and if you can perf test your bunch-of-updates scenario to tune the bit of app code (that is potentially writing across regions in each of these rapid-fire calls).
EDIT: Example: If each conditional update takes 1s and you get a rapid-fire of 30 requests, that’ll be 30s. So my above Q is just to see if that process can be tuned.
On searching about conditional update with pg, I came across this.
Sharing just for reference - Conditional update in PostgreSQL (updated!) | by Tamás Polgár | Developer rants | Medium
It’s an Elixir app with Ecto. So I load a record into a defined struct (basically SELECT * FROM table WHERE id = <id>). Then I apply a changeset with the changed data and trigger an Ecto update operation. If there is no change (attributes on struct and changeset are same), we just don’t trigger an SQL UPDATE statement. I’ve checked that already - to be sure.
Actually it’s happening a lot that there is no change on the attributes I am checking.
Moreover I’ve checked the query time and CPU utilization today when I had longer response times. The query time was constant while the response time went up. The CPU utilization wasn’t higher than normal.
And as I wrote above, now all instances are in the same region. No cross-region writes anymore.
Are you running any replicas or only a primary in the primary region?
ignore me. I see the comment above about the primary and everything doing reads and writes there.
I saw something like this, might be related or I could just be adding noise to the conversation, in the Singapore region a few days ago
Communications between my Elixir app (like yours, via Ecto) and the Postgres database was extremely slow. Live Dashboard was telling me that queries were taking ~1s to complete when hitting the database. As a result, I was seeing 15s+ load times on pages that made a substantial amount of calls to the database.
Over time, the performance has improved to drop the average query time down to the 7ms mark as shown in this chart.
@mathiasn do you have GitHub - phoenixframework/phoenix_live_dashboard: Realtime dashboard with metrics, request logging, plus storage, OS and VM insights installed in your production environment? I would be very interested to see the query latency charts if you have them (if you need some help installing it, let me know)
I’m terrified the problem is going to come back again 
Hey @sam,
yes, I’ve actually used Live Dashboard to check for the query time. But I didn’t see spikes there, it was constant as I wrote in my previous post. But I will check it when it happens again.
@kurt: I have another theory why loadbalancing does not seem to work properly. My Phoenix LiveApp basically consists of two parts: one handles API requests, the other handles a LiveApp. I do see long response times sometimes on the API. When this happens more or less only one instance is hit, no visible loadbalancing. In my fly.toml there is connections configured for services.concurrency as this was recommended for websocket apps. Could this be the problem why loadbalancing of usual requests isn’t working?
The connection between the application and the database is slow, possibly because the application and database are deployed in different regions.
Yesterday I found that the application with the region set to hkg was deployed to the sin (backup region), so I also set the backup region to hkg to solve it.
flyctl regions backup set REGION