Can't stop artifact pulls sometimes

[ada-magicat]

After trying to stop a build with ctrl-c and choosing terminate, buildstream will fail to terminate any running pulls forever. I get a bunch of logs with STATUS Pull terminating but nothing happens. Nothing more is logged with default logging options. After this I have to kill the bst process.

To my memory, this should always happen if #2156 has also occurred in the same bst invocation. Similar to that one, the machine can be turned offline and the pulls never fail, timeout or stop. Also similarly to that issue, reproduction steps are unclear other than these 2 issues almost always happening together. Although, I believe I have seen this issue happen on its own occasionally as well.

[wsalmonct]

This is todo with how buildstream and buildbox-casd interact.

When you hit ctl-c buildstream tries to gracefully stop, eg its stops creating new jobs and waits for the old ones to finish.

The idea being that if something is mostly finished you might as well let it finish.

The issue is that some actions that we ask of casd are not trivial, eg pulling a large artefact over a slow network or doing a fetch from a remote server that is throttling us.

A tip is to kill casd, so pkill -9 buildbox-casd if everything is really stuck.

Im not sure how this is actually supposed to work, maybe @gtristan @juergbi can say, is it that a second ctl-c should trigger buildstream to ask buildbox-casd to stop more quickly or is it that buildbox-casd stopped listening to buildstream?

[ada-magicat]

A tip is to kill casd, so pkill -9 buildbox-casd if everything is really stuck.

Good idea, unfortunately that does not actually work! You can kill casd, buildstream just re-prints the "Pull terminating" messages and keeps hanging there forever just like before.

is it that a second ctl-c should trigger buildstream to ask buildbox-casd to stop more quickly or is it that buildbox-casd stopped listening to buildstream?

Actually buildstream has the ability to kill casd if it takes too long, however it does not choose to use it very reliably.

The issue is that some actions that we ask of casd are not trivial, eg pulling a large artefact over a slow network or doing a fetch from a remote server that is throttling us.

I don't think it is that difficult to figure out that the network is offline and it is not pulling any data anymore or to just drop a half finished download and quit.

[wsalmonct]

A tip is to kill casd, so pkill -9 buildbox-casd if everything is really stuck.

Good idea, unfortunately that does not actually work! You can kill casd, buildstream just re-prints the "Pull terminating" messages and keeps hanging there forever just like before.

I thought I had had susses with this in the past. Apologies for miss remembering.

is it that a second ctl-c should trigger buildstream to ask buildbox-casd to stop more quickly or is it that buildbox-casd stopped listening to buildstream?

Actually buildstream has the ability to kill casd if it takes too long, however it does not choose to use it very reliably.

Its a long time since i looked at that code, but i have a stonge memory of it not asking buildbox-casd to stop in the past. REAPI and GRPC do not have nice ways to trigger a cancellation. At least in the past it simply didnt ask for any new commands which effectively looks like its stopping buildbox-casd. This is normally a very subtle difference, except when the actions being requested are large.

My point here was not to define what the code does, but to get some input from the main authors / maintainers of the project as to what a good solutions should be.

We can go to the mailing list for high level questions like this but If @tristanvb / @gtristan or @juergbi had a vision for this already then we "simply" need to fix the project, If there is not a clear vision for what good looks like then we probably do need to decide, your issue is highlighting something lots of us have just lived with partly as the "right" solution is not clear. Thank you for highlighting this.

The issue is that some actions that we ask of casd are not trivial, eg pulling a large artefact over a slow network or doing a fetch from a remote server that is throttling us.

I don't think it is that difficult to figure out that the network is offline and it is not pulling any data anymore or to just drop a half finished download and quit.

Ha, you would hope so wouldn't you :) GRPC makes this much harder than it might be. A lot of the API's are setup to favour recovering rather than stopping quickly as soon as there is any blip in the network. But that's not to say we could not improve things.

Also the is the extra issue that this information needs passing back from buildbox-casd to buildstream. Often the bugs in this part of buildstream are caused by buildbox and buildstream being perfectly sensible but miss communicating. This is partly due to them talking mostly REAPI which has a limited API, but they also speak some other GRPC messages.

Also

@ada-magicat It would be interesting to know what REAPI cache you are using.

Most Bst, AFAICT, are on cooperate networks with co located caches, or involved in FD-SDK which has its cache and runners with very good internet connections.

Also most people are using buildbox-casd or buildgrid as there cache server.

Knowing a little bit more about your setup might help us diagnose the underlying buildbox-cad issue.

Ofcourse bst should be handling these pull failures much better.

[ada-magicat]

A lot of the API's are setup to favour recovering rather than stopping quickly as soon as there is any blip in the network

I turned off my network and let it sit overnight once to see how it would behave; I woke up with it still in a "stopping" state. Being offline for hours isn't exactly a blip now is it?

REAPI and GRPC do not have nice ways to trigger a cancellation.
GRPC makes this much harder than it might be.

Now that sounds like a pretty serious limitation to the industry standard protocol for this kind of thing...

Knowing a little bit more about your setup might help us diagnose the underlying buildbox-cad issue.

It is fdsdk and gnome-build-meta, and I'm pretty sure both just use buildbox-casd.

[juergbi]

#2156 (comment) may help here as well, i.e., setting keepalive-time (and possibly also request-timeout) as documented in https://docs.buildstream.build/2.7/using_config.html#connection-configuration.

However, I definitely consider it a bug that Ctrl-C can result in hanging forever, even if no keepalive or timeout is configured. We should fix that.

[wsalmonct]

@juergbi Do you think its clear what we need todo here? If some one could russell up some effort to work on this?

[juergbi]

I would probably try to simulate a hanging pull on the buildbox-casd side and then check where exactly it's hanging in BuildStream to try and fix this in BuildBox and/or BuildStream. (We already do have logic in BuildStream to signal SIGKILL 15s after SIGTERM but it seems it's hanging before even trying SIGTERM). I.e., I can't point to where exactly the fix needs to be right now but I think we should be able to figure this out even if we can't reproduce the reason for the underlying hang (#2156).

[abderrahim]

I've encountered this countless times in the past and tried to investigate / fix it, but it's not really easy.

The main issue here is that terminating a job that is blocking does not actually terminate it. Buildstream offers a blocking_activity helper function to run such blocking calls in a subprocess, but doesn't actually use it when talking to buildbox-casd.

What's happening is when ask buildstream to terminate a job, it schedules an exception in the thread that is running the job. The exception doesn't actually get thrown until control is back to python. So if the thread is in a blocking call into C/C++, it doesn't actually get the exception until that call returns. The workaround devised for this situation is the blocking_activity() helper method mentioned earlier, but it isn't actually used with buildbox-casd. So what happens is that buildstream (main thread) will say that the job is terminating, and schedule the exception. The thread running the job is still stuck waiting for the FetchMissingBlobs/UploadMissingBlobs grpc call to return. Once the call returns (which might take a long time, or possibly never if you don't have the various timeouts configured), the python thread gets the exception and proceeds to terminate.

The workaround for this is, as suggested earlier is to manually kill buildbox-casd (pkill -9 buildbox-casd, or probably better to look up the pid if you have another instance of buildbox-casd running). Buildstream detects this situation and just stops everything. There is a race condition where it doesn't and you need to also kill bst, but it's very rare.

Now the question is what should we do about it? One thing is somehow avoiding blocking grpc calls, the other one (maybe less urgent) is to cancel the grpc call and teach buildbox-casd to properly react to cancellation. I have a proof of concept for the former, I'll try to clean it up and push it today for discussion.

[abderrahim]

Opened #2160

[ada-magicat]

There is a race condition where it doesn't and you need to also kill bst, but it's very rare.

It's not that rare, I managed to hit it both times I needed to stop a pull the other day.