V2 + App Sleep = first response always empty
I recently deployed a new Bun API on V2 with App Sleep, and I've noticed that the first request to a sleeping app always returns an empty response. This hasn't happened on non-V2 Bun apps with App Sleep on.
The following are tests with curl using the same URL/endpoint.
Normal request (non-sleeping app,
{"status": "OK"} is the response from my API):
First request on the same app but sleeping:
Project ID: 34304961-2ebf-4d0b-b2ae-3585cf6b9353200 Replies
Project ID:
34304961-2ebf-4d0b-b2ae-3585cf6b9353can you also provide the same data for the same app running on the legacy runtime
you mean change the runtime for that app, right?
I tested a different app running on Legacy and the issue didn't happen
but I'll change the runtime
testing a different app is not conclusive, when testing you need to change only one variable at a time, a completely different app changes too many variables
it was another Bun app, but I can see the variables
I'm deploying the reported app on Legacy and have to wait for it to sleep 🙂
I'm not talking about environment variables
yeah I meant variables as not in environment variables but how the apps are different despite both being Bun apis
deploy is done, will report back in about 10 mins
Test done, request on sleeping app worked fine:
switching back to V2 to repeat the test
btw that cold boot time = 🏆
1.795s is good?
for a cold boot time? I'd say excellent
I have another Rails app running on Railway that cold-boots in about 10s, kinda bad
but that's mostly Rails to blame
similarly I have a feeling this is bun to blame
I'm running a compiled executable, so very likely
isn't that the recommended way to run in production though
it is, I'm following their guide on that
for comparison, this is normal request time
the increased memory usage on V2 is a bit of a bummer though
how much of an increase.
Legacy was running ~36MB
V2 is running 53~61MB
is this the exact same app, or are you comparing different apps again lol
it's the same app
someone else reported higher memory usage on the v2 runtime, but I can't reproduce it just by purely allocating bytes
just by looking at its memory metrics
looking further back (the app has been up only for a couple hours) the lowest it got on V2 was 42MB, but I only had one run of it on Legacy, so probably needs more data
but the difference is quite noticeable, maybe not in the image because the chart ceiling is a bit too high
btw the app went to sleep again and curl returned an empty response
if it matters, the service has a volume
remove the volume and try again?
I'll try, that might break the app though
app broke, trying to fix it
alright it's back up, now waiting for sleep
Network graph also wild on Legacy
then it's a good thing the legacy runtime will be phased out
got empty response on sleeping app, so volume is not it
okay can you provide a minimal reproducible bun app that sends an empty response on the v2 runtime
I'll try
I deployed a smaller app, and could not replicate the issue
but here's the thing... the affected app also stops having the issue 👀
uh.. task failed successfully?
ugh, technology these days 😛
ugh, bun these days
now that I have both apps running, I'll try to replicate it again with the affected app
then try to replicate it with the smaller app
code btw: https://github.com/pauldps/bun-railway-v2-test
I'll try deploying to separate project in case of same project shenanigans
that's definitely minimal
I was able to reproduce the issue with the minimal app in a separate project
and the original app also started showing blank responses after I removed the minimal app from that project 👀
this is looking more like instabilities with bun
try the same code with node?
added a
node branch to the minimal app and deployed it, now waiting for sleepjust a question, why do you have the healthcheck timeout set to a low value like 30 seconds?
because I want it to fail fast
usually if the first request fails, the deploy is likely busted, and I don't want to wait 5 minutes for the deployment to fail
makes sense
I think for Rails apps with slower boot times I set a higher value
got the empty response with the Node app as well
interesting
can you link the applicable deployment
two requests
the deployment? or the project?
the deployment
oh, got it
7368d15e-ed13-4684-aab3-72e2b3bdaa74
full link please
the url in the browser when the deployment is open?
https://railway.app/project/46548220-e0ba-4a16-b80a-706a55133413/service/8da48915-af62-477c-b850-17671fee4e86?id=7368d15e-ed13-4684-aab3-72e2b3bdaa74
would it be too much to ask you to also do an express app?
lemme see if I can do it quickly, I never used express before lol
that's a crazy sentence, I had never imagined someone who uses bun and Elysia to say they've never used express
when express was a thing I was mostly working with Rails
when I moved to Node it was during a time where express was considered too slow compared to other libs, so I never touched it
express app is up
waiting for sleep
code in the
express branch
the express app responds correctlyyou're still on the v2 runtime?
yes, I just changed the branch and nothing else
I wonder what's going on with Node's http server, which is probably what Bun servers are based off of
using express is not an option for me though
well that seems like this isn't an issue with railway then
hold on
got an empty response with express
I think my first test was too fast
it seems like an issue with V2 to me
could potentially test with non-Javascript frameworks but that would be a bit too much for me to do atm
ill test with a go server
what happens if i dont experience the same issue?
I can test with Ruby later, but for now I need to go sleep myself lol
good question, I have a theory, but want to test a slow language first
remember to deploy in a new project since it seems multiple services in a project can affect the results, I'd like to test more about that part too
i have indeed created a new project
I have deployed a Ruby/Sinatra app, and was not able to replicate the issue on the first cold boot. But I'm seeing a pattern in the logs that I want to investigate
these are the logs from the Express app. My first request did not trigger the problem, but my second did.
The second request was after the "container event container died" log entry that was absent from the first request. So I'm trying to get that log entry to show on the Sinatra app
the "Stopping Container" spam seems to indicate there's a problem somewhere with V2
was not able to replicate the issue with Ruby after 2 attempts. I'm going back to the main branch (Bun) to see if maybe the problem resolved itself
stopping container is it being put to sleep
does it show even if the app is already sleeping?
"Stopping Container" logs did not show up for the Ruby app 🤔
but it did go to sleep
(according to the dashboard)
maybe the ruby app is on the legacy runtime
I will doublecheck after I test one more time with the Bun branch
the problem is still there with the Bun app. The logs:
no "Stopping Container" tho
switching to the ruby branch for now to investigate more, made sure it's on V2
got to reproduce the issue with the Sinatra app. It was a little worse as two requests gave empty responses before the third one returned the correct response
logs
(those are not errors btw, wtf Sinatra)
printed to stderr
I have requested my go app a few times when it has gone to sleep and was not able to get an empty response
were the logs like the above? I let my app sleep for about an hour or so before making requests
from observation the problem seems to be related to those "contained died" and "stopping container" errors
those are regular event logs, nothing to be concerned about
right, I meant logs, not errors 👍
yeah the container log stuff is perfectly normal
I do think they seem to indicate the container is going into a state where it fails to render responses on wakeup
so far V2 is the common denominator; I've changed projects and languages, and the problem doesn't happen on Legacy. What else could we try?
not sure, I'll report it to the team anyway
thanks, I'll keep the project up if the team wants to debug/investigate
So you can repro this on both bun and sinatra?
correct, also Node-http and express
Ack and escalated
It should be triaged on Monday
fairly certain that the blank response should in fact be a 503 application failed to respond page, but railway is no longer sending that page at the moment due to what i believe to be a bug.
so lets assume your first response to a sleeping service is a 503 status code, meaning your app did not respond to the first request in time, that explains why a statically compiled go app did not exhibit this behavior.
when a request comes in for a slept app the container is started and a tcp connection attempt is done on a loop every 30ms, once that succeeds the request is forwarded to your app, but if your app is not ready to handle http traffic just yet you will get the 503 app failed to respond page, the apps health check is not taken into account.
theres definitely some room for improvement here on the railway side of things for waking sleeping services aside from fixing the blank page being sent instead of 503.
Is this for the new proxy or?
yep all testing done with only the new proxy enabled
Great. Miguel merged a fix for this. Should be good to go
for clarity, the fix was for the blank response instead of the 503 application failed to respond page that should have been shown
I can handle the 503 response better than a blank page, can set my client to retry or something
(although it would be nice if the 503 didn't happen)
We now no longer return a 200
We should return a 500 as was the previous behavior
just ran a test now and got a 502 with a long HTML error page
That's correct ye?
that's better than a 200 for sure
What's "Best"
Best would be 200 with my app returning the correct response
Well yes
Is your app returning the correct response?
no, it's returning that huge HTML from Railway
No I mean like
that's just the first request though
What happens is this intermittent is it always
the next requests work fine
it's always when the app is sleeping
"first request when app is sleeping"
"First request when app sleeping results in 503"
Gotchu
Esclating again
This is only on the V2 runtime ye?
correct
does not happen on Legacy
I suspect it wasn't more widely noticed because it was returning a 200
Yep I suspect so too. Bubbled up
@Brody , is this application one of those app sleep healthcheck candidates ?
The fact the legacy proxy would work but new one does not makes me think the healthcheck feature we talked about wouldn't matter.
The new proxy is using the same timeouts as legacy and these edge proxies are not aware of application sleep logic. There must be a timeout setting that is different.
yep I feel like this could benefit from having the heath check checked on waking up the service
oh this is saying that this issue with app sleep waking only happens on v2 runtime but works on legacy runtime.
Correct ?
We just happen to be on the new proxy and saw those 200s (sorry about that...will work on ensuring issues that like that don't through)
I was able to reproduce and have a strong lead on the issue.
I'm continuing to work on this and will share updates here when I have some.
Hello, I'm still looking into this.
heads up, I saw a few reports of 502s and the people's containers were stopped
if you don't exit with non-0 the restart policy won't start it again.
unsure what stopped the people's applications but pointing out that checking the logs for container exits and restart the container resolved the issue.
noted, thanks for the heads up
I’m not sure if I’ll be digging in to the more since I found in 2 examples of this the container was stopped.
Next time someone brings this up I’ll just ask to restart their container to see if it comes back
I’ll have to look in to it if more people report of course
OP did say it was reproducible between multiple deployments
ok I don't think it's stopped containers in that case.
!remind me to reproduce this in 1 hour
Got it, I will remind you to
reproduce this at Fri, 12 Jul 2024 19:39:21 GMT
Hey @Mig, remember to reproduce this - https://discord.com/channels/713503345364697088/1258304003930984531/1261391468778487909BTW I don't think we have the cycles ATM to repro stuff for people
They'll have to come to us with reproductions that we can have a look at
In production I have an app with app sleep and v2 runtime. On my first request it says the app is unavailable. The container starts though. Second request it works.
So easy to reproduce.
Okay then givr
I don't understand this part: "the container was stopped". Do you mean the container was stopped manually? In my case the container stopped because it went to sleep. I didn't do anything to stop the container and my app is a long-running http server, so it doesn't stop on its own. The only reason it stops is the App Sleeping feature.
I can assure you applications can stop on their own
I think like, even if it does stop on it's own, we should probably restart it?
Cause like if it crashes and another request or something comes in IDK
if it exits with an error code, yes, if it exits with a success code, maybe not? but yes if restart is set to always
Brody got it for the restart behaviour
The fact I could reproduce this though means we can disregard what I said about the container being stopped.
I think mentioning it might have been a mistake as I was jumping between a few threads debugging stuff.
I will dig into this more next week.
New reply sent from Help Station thread:
I have same problem...With legacy runtime work well but with new V2 not.The first http(s) request via browser is allways 502, nexts working normally.Build with custom Dockerfile based on alpine+nginx+phpfpmYou're seeing this because this thread has been automatically linked to the Help Station thread.
hey folks, I spent some time on this and basically, the v2 runtime wakes and forwards http requests differently than v1 runtime. I have observed the success rate of starting and getting an HTTP response to be pretty flakey (sometimes it works, sometimes it does not). I believe this is something to do with how fast the container can start in v2 runtime before the request times out.
I can't spend more time on this right now because the number of reports for this has been small and have to prioritize some other issues.
If you need app sleep right now I advise just using the v1 (legacy) runtime.
New reply sent from Help Station thread:
Thanks for the update, I just want to say that I also faced the same issue with my python instance. Mainly observing that the first request wakes up the instance (but the request does not go through) but any subsequent request s work. Will try v1 for the time being but would be nice if resolved.You're seeing this because this thread has been automatically linked to the Help Station thread.
another report of it here - https://help.railway.app/feedback/app-sleeping-65af513a#solution
We’re expressly not going to be able to prioritize this until the new proxy is out unfortunately
Has something changed with this issue? My Legacy apps are starting to show 502 errors after coming back from sleep
Most of my apps also no longer allow me to change between Legacy and V2
We have indeed removed the ability for users to switch back to legacy
Is Legacy going to be removed soon?
when we move to metal legacy will not be supported, thus in the intrest of moving to metal faster all deploys for all plan tiers use runtime v2
I really need App Sleep to work reliably 😦
well then you will be pleased to know that the new proxy is indeed fully rolled out and 100% of the nearly half a million domains used on our platform now have their traffic served via the new proxy, thus we should be able to take a look at picking back up the 502 app sleeping issue.
That would be great, V2 working with App Sleep would be ideal
i've also bumped the linear ticket on your behalf
Appreciate that, thanks!
We will make sure this works reliably within the next 2 weeks
!remind me to circle back in 2 weeks
Got it, I will remind you to
circle back at Mon, 11 Nov 2024 16:28:32 GMTJust wanna say that we are actively working on a solution to this!
Hey @Cooper, remember to circle back - https://discord.com/channels/713503345364697088/1258304003930984531/1300496436382797896
Circling has been done
We have a solution and hoping to have it out this week.
Solution is being tested and trying to get it out tomorrow.
I'll be sure to comment here when it is.
A fix has been merged and in production now. @pauldps give it a try whenever you can and let me know. Current implementation allows your app to take up to 10 seconds to accept the incoming connection.
They do at least have to redeploy for the new chances to take effect right?
oh yes. Please trigger a redeploy. This action applies some settings for the network to be aware of your application has application sleep set.
since this issue impacted applications that started slower than 100 ms, making something that backfilled the applications did not seem worth it given a redeploy would fix.
My go application for example never has this issue because it starts up fast enough to accept the connection before the host rejects it thinking there's no app listening.
started slower than 100 msthis number is a guess. I think it's roughly correct. Might be 30-100ms
So this is what I did:
- Changed the app to V2
- Triggered a redeploy (also made some code changes etc, it's a GraphQL Yoga API running in Bun)
- Service starts fine (health check worked on first try) and runs fine in a browser
- Service goes to sleep
- I refresh the website
- Got the error in the first image
Did I miss anything?
request id please
n6zQAxIuT5ysSFbJ-GY0nA_3118653284ill let mig comment on this
though, might be worth trying a newer version of bun, you're on 1.1.18
I'll do that soon, but I don't think it will fix the issue
the app is booting in about ~1s
i was able to confirm app sleeping works with a node app that took 8 seconds to start, so this may just be bun being bun
maybe my project is stuck in some old/cached workflow?
what region?
us-west, the default one
same, we'll see if mig wants to work around bun's strange networking issues on monday
I can test with a Ruby/Sinatra app later
I tested it with another Bun app but in a different project and it worked
I think my project/service is borked somehow
the Sinatra app also worked fine on first try
just re-tested the project that had the issue and it still showed the error
This project works:
46548220-e0ba-4a16-b80a-706a55133413
This one does not: 34304961-2ebf-4d0b-b2ae-3585cf6b9353 (service: e2a687a5-9ce2-4694-81ae-12c6756b0bce)maybe try with the same code but in a new project?
for the project that's not working it'll be a bit more difficult since it has other dependencies inside that project that I'd have to deploy too, but I will do it if time permits
you could create a template from the project and then create a new project from it
its in project settings
oh, didn't know that. I'll give it a try
will the new project use the same env variables and stuff?
If someone gives me the source code for reproducible bug I will check it out!
I copied my services to another project and it seems to be working without issues, no 502s on wakeup
so it seems my old project is somehow bugged
I'll make one last test, as my old service had a volume attached that I wasn't using. I've deleted the volume, redeployed the service, and will wait for it to sleep
just did ☝️ and it errored the same, so it doesn't seem to be volume-related
@pauldps - as mig said, we would need a reproducible example in order to look into it
I'm not sure that's reproducible
both projects are running the same code with the same env vars, one works, one does not
I have given the project IDs of both, feel free to look into them
unfortunately we wont be able to spend time doing that, we would need a reproducible example
you're probably going to get other people with old projects facing the issue but some of them won't be able to do what I did (copy/move everything to a new project)
i had a service i deployed 8 months ago, with the changes done it can now properly wake up from sleep
same-ish with my Sinatra project
that's why I think it's a problem with my project specifically
it's not something related to source code
something about my project, infrastructure/configuration-wise, not code-wise, might be causing the issue
but I can't look at infra/configs
if you think that is the case you are welcome to try duplicating the gesund-api service
I already did that
... ah, the service, into the same project?
yes
I duplicated the entire project
let me give that a try
done, will wait for it to sleep
also have an update:
the second project's first request failed on wake up, just tried now
that said, how do I actually send the code of this repo for reproduction?
Request ID:
f5B_p5h0T5SopI4KU
the exact same code as gesund-api. Bun as well
just since its easy, I'd still recommend trying the latest bun version
Bun upgraded to 1.1.34
and if this doesn't work, we would need that MRE
it's going to be very hard for me to have a MRE if my other Bun example (let's call that Project 3) isn't failing
I'll upgrade Bun there too and test it again
project id?
46548220-e0ba-4a16-b80a-706a55133413
this one is just a plain Bun server
it doesn't seem to be affected by the issue
I have other branches where I have other servers like Sinatra for testing purposesalso bun 1.1.18
as for that MRE I mean how i can make it actually minimal, it's a graphql api with multiple endpoints, I don't know what is making it fail if anything.
this testing takes time, I have to wait the app to sleep and test the first request, it doesn't seem like I can make several code changes removing stuff until I find the culprit if there's one
its up to you to remove as much code from the current app while still retaining the issue
that might take me a very long time
there is no rush
I'll see what I can do but I'm not happy about having to do this when the server is returning a 502 which seems to be out of my control
what your app is doing is out of our control too, and thus we need that MRE to reproduce and patch around it
don't you think it it was an error on my app we'd at least see it in the logs?
there are no logs for the failed request
no i dont think we would see logs for this
does Railway use the health check path during wakeup?
no
how does it know it is up and ready to serve requests?
we replay the incoming connection for up to 10 seconds
I have a MRE.
Instead of changing my project, I deployed a minimal Graphql-yoga+Bun server to Project 3.
Just tried the first request on sleep and it failed with a 502.
Here's the code: https://github.com/pauldps/bun-railway-v2-test/tree/graphql-yoga
so the newer bun version didnt help it seems
yup, the previous version (no graphql) running Bun 1.1.18 also didn't have the issue
alright, thank you
Strangely: I deployed the same app on Project 2 (
a0aefb5f-15c4-49c6-a7ec-020b58d0cfc5)
same branch and everything. It's working fine!
I've checked it twice now and both requests worked fine. So I don't know what's going onwell i have your code deployed so ill let you know if i can reproduce it
I got an error on the app running on Project 2. The fact that it occasionally works seems to be a bit random.
I got your bun MRE to cause a 502 on wake
so yeah, some strange issue with bun
is Bun networking known to cause issues?
yeah, it's not the first time
since we got a MRE I could try it out tomorrow.
Thanks for the persistence on wanting to get this fixed. Sometimes it's a 50/50 effort for us to help when the issue is rare.
here is their MRE repo in template form -
https://railway.com/template/lGBlqd
is it deploying the graphql-yoga branch? (can't tell)
yes