alloc logs returns 500 if alloc has been garbage collected #18216
Labels
stage/accepted
Confirmed, and intend to work on. No timeline committment though.
theme/allocation API
type/bug
Comments
|
Thank you for the report and kind words @johnnyplaydrums 💚 I was able to easily reproduce the problem following your detailed steps and it turns that distributed systems are hard 😅 The different results happen because when the allocation is only garbage collected from the client (not servers) the client still holds a reference to it until the servers also GC it: Lines 205 to 207 in e21ab7d But the client GC does delete all of the alloc files, so it's not possible to read the logs, resulting in the 500. I've opened #18232 to fix this and return a 404 instead. |
lgfa29
added
theme/allocation API
stage/accepted
|
Hi @lgfa29, thanks for turning this around so quickly! The PR looks great. It noticed I could approve the PR, which I wasn't expecting, but since I'm not a core contributor or super well-versed in Go I figured I would leave that to others? Looks great though! |
|
Ah yes, it is possible to approve PRs as community members. It's a good signal to us when people try the fix before merge, but we don't expect that to happen 😄 |
|
Sounds good! I've never built Nomad locally so I wanted to give it a shot :) I built via Go since I didn't have Vangrant/VirtualBox set up and wasn't able to get it working correctly after a short try. The Go build was very fast. I did discover an issue, not sure if you're already aware of this or not, and wasn't sure whether to put this in the PR or here, but didn't want to clutter the PR so here I am 😅 I built
Logs➜ nomad git:(b-return-404-on-gc-alloc) bin/nomad --version Nomad v1.6.2-dev BuildDate 2023-08-18T15:53:13Z Revision 48a5407 ➜ nomad git:(b-return-404-on-gc-alloc) sudo bin/nomad agent -dev -config=client.hcl Password: ==> Loaded configuration from client.hcl ==> Starting Nomad agent... ==> Nomad agent configuration:==> Nomad agent started! Log data will stream in below: results= results= results= |
|
Oof nice catch! And nice job getting the custom binary running 😄 I missed the early returns when the error happens, so the HTTP handler was stuck waiting for log data. c14d770 fixes this problem, and the branch should be working now. Thanks for giving it a try! |
|
Awesome, just tested the most recent |
This was referenced Aug 21, 2023
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Long time listener,
firstsecond time caller 😁. Nomad rocks, thank you for all you do. I tried to make the reproducibility as simple as possible. Let me know if there's anything I can improve on for next time. This is a minor bug and we're already working around it, so if we think this isn't worth investigating/resolving, we can close it.Nomad version
Nomad v1.6.1Operating system and Environment details
Ubuntu 22.04 and MacOS 13.4.1
Issue
The
v1/client/fs/logs/<alloc_id>endpoint, and thenomad alloc logscommand, returns a 500 if the allocation has been garbage collected due tonew allocations and over max (<gc_max_allocs>). Interestingly, if you run thev1/system/gcendpoint ornomad system gccli command, the 500 turns into a 404 (expected).Reproduction steps
Run the nomad agent in dev mode with
gc_max_allocs = 1(for faster reproducibility)client.hcl contains
Then trigger at least 2 jobs/allocations so that the
gc_max_allocs = 1triggers garbage collection. I used a periodic job and dispatched it twice (job file below).In the logs you will see something similar to this, referring to the first alloc that is now being garbage collected:
Then curl the logs endpoint for that allocation (or issue cli command), and you'll get a 500:
We see this happen daily in our Nomad cluster running Nomad version
v1.5.3on Ubuntu 22.04. We are running a lot of batch/parameterized jobs and use the logs endpoint heavily to retrieve logs (so they're viewable in airflow). I was able to reproduce it locally on MacOS 13.4.1 with the newest Nomad versionv1.6.1.Expected Result
We'd expect nomad to return a 404 with the text
Unknown allocation "afb4c8c8-1d33-357b-2b43-602a07c2213d".Actual Result
We get a 500 from the API with the text
failed to list entries: open /private/var/folders/q4/srtw1qzj1gv6261h2lnyx2440000gn/T/NomadClient1395255995/afb4c8c8-1d33-357b-2b43-602a07c2213d/alloc/logs: no such file or directory%.Same thing if we use the
nomad alloc logscommand:In my local testing I occasionally noticed that the first time I curl the logs endpoint, I actually get a 200. But after the first one I always get the 500. This only seemed to happen some of the time; most of the time I get a 500 right away. Query the logs api a 2nd time if you get a 200 the first time.
Job file (if appropriate)
This will happen with any job file but I used this for reproducing the issue:
Nomad Server & Client (dev) logs
This is the full log output when reproducing the issue locally. You'll see the 500 error at the bottom. I ran this about 5 times (just to be sure) and got the same results every time.
Let me know what else you need from me. Thanks again team!
The text was updated successfully, but these errors were encountered: