New containers cannot be started with DeadlineExceeded #266
Comments
|
Hi @nudgegoonies, thanks for filing the report. Would it be possible for you to attach the sysbox-fs log?
This generally means that sysbox-fs is not responding, which is not good. The sysbox-fs log will likely help. Restarting sysbox should fix it, but we still need to understand why sysbox-fs stopped responding. Also: what sysbox version / commits are you using (you can see this in the Thanks! |
|
Thank you for very much your answer. We use sysbox v0.3.0 built from source with the one journald commit cherry-picked: I havn't tried master yet. This is the complete log of sysbox-fs: And you are right. After a restart of sysbox it works again. |
|
@nudgegoonies, looks like you just restarted sysbox-fs and things are working fine again. For next time, please collect a core-dump of the affected sysbox daemon so that we can look deeper into the issue. Thanks. |
|
One last hint to the logs from yesterday. In the syslog the following mount operations can be seen exactly at the time where the sysbox-fs warnings appear: I can reproduce the error with heavy load on the gitlab runner. I created a core file the core file you requested. This was the output of the gcore command: The file is nearly 4 GB big. I try to find a way to make the file available for you. |
|
Thanks @nudgegoonies, will take a look and get back to you later today. Btw, I would expect the core-file to be just a few MBs once that you compress it. See our new core-generation procedure here. |
|
@nudgegoonies, i didn't realize that you were running a custom Sysbox build so it has been impossible for me to analyze your core-dump. Can you please do all this when have a chance?
rmolina@dev-vm1:~/issues/sysbox/sysbox-fs$ git log --oneline -10
886b404 (HEAD) fix: Use os.Stderr if no logging filename is given
bb001b7 Minor correction in mount-hardening's log instruction
3319778 Adjust mount-hardening logic to log at 'info' level upon remount/unmount rejection
3031e2f Sysbox-fs changes to prevent race-conditions stalling seccomp-bpf tracees
566e41e Rename 'platform' field to 'edition' as per code-review feedback
c5391c1 Add 'platform' keyword to reference the Sysbox product edition
fa5b476 Populate missing fields in '--version' cli knob
95042ca Create README file with high-level description of sysbox-fs features
c1601f0 Fix on nsenter's SendRequest() method to include missing reaper's termination instruction
5022668 Fix in nsenter's sendRequest() to ensure that pipes are properly closed at return time
rmolina@dev-vm1:~/issues/sysbox/sysbox-fs$Thanks. |
|
@rodnymolina I have sent you a mail with all details. |
|
Thanks for providing all the requested info @nudgegoonies. It has been very helpful. We are dealing with a deadlock scenario as can be seen from the following debugger traces. I suspect i've found the smoking-gun that will allow me to identify the root-cause. Will look into it tomorrow.
|
|
Short executive summary of where we are with this issue:
Both bugs are mainly reproduced in scaling scenarios with relatively-high churn of system-containers and inner containers going up and down in small fractions of time. |
|
The second issue proved to be very hard to reproduce (timing condition), so the following diagnosis is fruit of core-dump analysis (thanks @nudgegoonies), code-inspection and empirical results. High-level descriptionAt high-level, this second issue is a dead-lock problem caused by the recently introduced 'asynchronous' nsenter logic in charge of collecting This logic relies on the utilization of two consecutive nsenter proceses for the extraction of the mountinfo state: the first one enters the namespaces of the desired context (sys-container or inner-container), and then it serves as the underlying channel (pid) for the second nsenter process to extract the required information. There's nothing wrong with the above approach, except for the fact that its implementation relies on the utilization of a single RWmutex (reaper) whose acquisition-protocol can break in corner case scenarios such as the one triggering this deadlock (see details below). Low-level descriptionProblem is triggered by the following sequence of events:
|
rodnymolina
added a commit
to nestybox/sysbox-fs
that referenced
this issue
May 15, 2021
Problem diagnosis has been well documented as part of issue [#266](nestybox/sysbox#266). Here I'm briefly explaining the fix that I've identified for this bug. As described in the issue's notes, the problem is caused by a deadlock scenario while dealing with the reaper's RWmutex. The fix is fairly simple: have 'async' nsenter logic remove its reaper's dependency. See that there's no real need for the reaper in the 'async' nsenter case as the SendRequest() callee will always sigkill() the nsenter process, so we can safely remove all this concurrency complexity in this case. Fix has been heavily tested over the last couple of weeks in the same scaling scenario where the problem was originally reported. No deadlock issues have been observed ever since. Signed-off-by: Rodny Molina <rmolina@nestybox.com>
rodnymolina
added a commit
to nestybox/sysbox-fs
that referenced
this issue
May 15, 2021
Problem diagnosis has been well documented as part of issue [#266](nestybox/sysbox#266). Here I'm briefly explaining the fix that I've identified for this bug. As described in the issue's notes, the problem is caused by a deadlock scenario while dealing with the reaper's RWmutex. The fix is fairly simple: have 'async' nsenter logic remove its reaper's dependency. See that there's no real need for the reaper in the 'async' nsenter case as the SendRequest() callee will always sigkill() the nsenter process, so we can safely remove all this concurrency complexity in this case. Fix has been heavily tested over the last couple of weeks in the same scaling scenario where the problem was originally reported. No deadlock issues have been observed ever since. Signed-off-by: Rodny Molina <rmolina@nestybox.com>
|
The second issue described above has been fixed as part of sysbox-fs PR #36. Will proceed to close this issue now as fix has been properly validated over the last few days. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
On our sysbox enabled gitlab runners we encounter the following warning and errors after some time and from then on no new containers can be started.
This warning in sysbox-fs appears shortly before containers cannot be started anymore:
These errors appear shortly afterwards, here i grepped for the container id:
The error message regarding DeadlineExceeded is the same as in these issues:
#244
#176
#72
This time there is no mount like in #244 involved.
systemctl status shows sysbox, sysbox-fs, sysbox-mgr, docker, containerd working but every start of a container fails with the DeadlineExceeded message.
The text was updated successfully, but these errors were encountered: