pwFoo
commented
4 years ago Have to check something... I think it is a problem with my script!
Closed pwFoo closed 4 years ago
pwFoo
commented
4 years ago Have to check something... I think it is a problem with my script!
pwFoo
commented
4 years ago There was an error with my script, but I think it's a problem with ending crun / runc process and rustysd maybe not know about the child / container process?
pwFoo
commented
4 years ago Looks like pid problem because of container process id? Found the runc way to do it, but it looks like PIDFile is needed.
[Unit]
Description=Start test container
[Service]
Type=forking
WorkingDirectory=/tmp/test
ExecStartPre=/usr/local/sbin/runc create --pid-file /tmp/test/pid test
ExecStart=/usr/local/sbin/runc start test
ExecStop=/usr/local/sbin/runc kill test
ExecStopPost=/usr/local/sbin/runc delete test
PIDFile=/tmp/test/pid
[Install]
WantedBy=multi-user.target@KillingSpark Would it possible to add PIDFile support?
KillingSpark
commented
4 years ago Is that unit starting? Type forking should throw an error while parsing the unit file. Type=forking is currently not supported. Initially I thought that that is not a thing anyone needs but it seems with the whole docker environment that it actually is used a lot. I will look into whats exactly needed to support it! The PIDFile support should be relatively trivial
pwFoo
commented
4 years ago I changed the example to type simple. See example from initial issue description.
[Unit]
Description=Start services rngd
[Service]
ExecStart=/usr/bin/crun --log /var/log/crun.log run --no-pivot --bundle /containers/services/rngd/ rngd
ExecStop=/usr/bin/crun kill rngd
ExecStopPost=/usr/bin/crun delete rngd; /bin/rm -rf /run/crun/docker
Type=simple
[Install]
WantedBy=services.targetI think type simple should / could work too, but crun will end after the container process is started with it's own process id!
So maybe PIDFile could fix it... Podman (docker alternative from RedHat) also works with systemd and PIDFile. Podman also just spawn the container process and stops if done. PIDFile should be the container process PID?
If easier to do we should work around type=forking with PIDFile?
KillingSpark
commented
4 years ago I think type=forking shouldn't be too hard to implement. Doing a work around doesn't seem really necessary tbh
Update: It would probably be better to have a wrapper that starts forking executables and waits for the forked child. Implementing this in rustysd seems like unecessary complexity.
The wrapper would look like this (pseudo code):
start_forking (exec_name, args):
start_subproc(exec_name, args)
loop {
exited_pid, exit_code = wait_pid(-1)
if (exited_pid == pidfile_content) {
exit(exit_code)
}
}Update 2: Doing this in a wrapper is significantly simple because rustysd needs to separate the different types of exiting pids etc. This wrapper has exactly one PID it waits for to exit
Update 3: Looking at how runc starts containers it should be relatively trivial to make it wait for the containers init process to exit instead of exiting directly after starting it. You might want to open an issue with them about this :)
pwFoo
commented
4 years ago At the moment I use crun (c based runc, compatible), but maybe it's done similar to runc... I don't know how to explain as issue at runc / crun, because I'm have no experience with rust / c / go.
Would it possible to add PIDFile support to rustysd a simple way? Maybe it would fix it für runc / crun?
KillingSpark
commented
4 years ago The problem isn't really that rustysd doesn't support pidfiles. It's more a problem that rustysd expects services to stay alive the wholeduration of their lifetime. Runc / crun seem tot exit after they started the container. That is just a concept that rustysd currently doesn't support. Is using a wrapper like I described feasible for you? I could provide that in another repo if you'd like.
KillingSpark
commented
4 years ago Looking further into crun it seems like it should not close but stay open until the container dies. Are you sure that your containers are running? The errors they throw before exiting seem like they try to bind to an unix socket that already exist, do you create these sockets somewhere else (like in some .socket units for example?)
pwFoo
commented
4 years ago That wrapper isn't just a flag or option and need to be used to wrap crun / runc? I would test the wrapper if it works for that case.
Because I need some more preparation like overlayfs mount and maybe another step... I could also write a shell / bash script which prepare, then execute crun and finally read and return the container pid?
It looks like rustysd try to start the container twice. Before starting rustysd /run/crun is empty. After it try to start the services there are files inside. With empty /run/crun I'm able to start the container sucessfully without rustysd...
But I don't understand why it fails triggered by rustysd... Also there is no stopped container, but the files /run/crun still there... Looks like rustysd kills the process (wihthout cleanup?) and try to start it again?
KillingSpark
commented
4 years ago I am not sure what happens but rustysd tries to start them once (according to the trace you gave in the very beginning of this issue). And those seem to encounter the already existing socket files
pwFoo
commented
4 years ago Directory is empty:
/ # ls -lh /run/crun/
total 0Start rustysd:
/ # rustysd &
/ # [2020-02-08][20:32:11][rustysd::units::loading][TRACE] "./unitfiles/default.target", 1
[2020-02-08][20:32:11][rustysd::units::loading][TRACE] "./unitfiles/docker.service", 2
[2020-02-08][20:32:11][rustysd::units::unit_parsing::service_unit][TRACE] UID: Uid(0)
[2020-02-08][20:32:11][rustysd::units::loading][TRACE] "./unitfiles/init.target", 3
[2020-02-08][20:32:11][rustysd::units::loading][TRACE] "./unitfiles/mdevd.service", 4
[2020-02-08][20:32:11][rustysd::units::unit_parsing::service_unit][TRACE] UID: Uid(0)
[2020-02-08][20:32:11][rustysd::units::loading][TRACE] "./unitfiles/network.target", 5
[2020-02-08][20:32:11][rustysd::units::loading][TRACE] "./unitfiles/onboot.target", 6
[2020-02-08][20:32:11][rustysd::units::loading][TRACE] "./unitfiles/rngd.service", 7
[2020-02-08][20:32:11][rustysd::units::unit_parsing::service_unit][TRACE] UID: Uid(0)
[2020-02-08][20:32:11][rustysd::units::loading][TRACE] "./unitfiles/services.target", 8
[2020-02-08][20:32:11][rustysd][TRACE] Finished loading units
[2020-02-08][20:32:11][rustysd::units::dependency_resolving][TRACE] Id 1 references ids: [8]
[2020-02-08][20:32:11][rustysd::units::dependency_resolving][TRACE] Id 8 references ids: [1, 2, 4, 5, 7]
[2020-02-08][20:32:11][rustysd::units::dependency_resolving][TRACE] Id 2 references ids: [8]
[2020-02-08][20:32:11][rustysd::units::dependency_resolving][TRACE] Id 4 references ids: [8]
[2020-02-08][20:32:11][rustysd::units::dependency_resolving][TRACE] Id 5 references ids: [6, 8]
[2020-02-08][20:32:11][rustysd::units::dependency_resolving][TRACE] Id 6 references ids: [3, 5]
[2020-02-08][20:32:11][rustysd::units::dependency_resolving][TRACE] Id 3 references ids: [6]
[2020-02-08][20:32:11][rustysd::units::dependency_resolving][TRACE] Id 7 references ids: [8]
[2020-02-08][20:32:11][rustysd][TRACE] Finished pruning units
[2020-02-08][20:32:11][rustysd][TRACE] Unit dependencies passed sanity checks
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Root unit: init.target
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Root unit: rngd.service
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Root unit: docker.service
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Root unit: mdevd.service
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Activate id: 3
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock unit: 3
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked unit: 3
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock status for: init.target
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked status for: init.target
[2020-02-08][20:32:11][rustysd::units::units][TRACE] Reached target init.target
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Activate id: 7
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock unit: 7
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked unit: 7
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock status for: rngd.service
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked status for: rngd.service
[2020-02-08][20:32:11][rustysd::services::services][TRACE] Start service rngd.service
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Activate id: 2
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock unit: 2
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked unit: 2
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock status for: docker.service
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked status for: docker.service
[2020-02-08][20:32:11][rustysd::services::services][TRACE] Start service docker.service
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Activate id: 4
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock unit: 4
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked unit: 4
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock status for: mdevd.service
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked status for: mdevd.service
[2020-02-08][20:32:11][rustysd::services::services][TRACE] Start service mdevd.service
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Activate id: 6
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock unit: 6
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked unit: 6
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock status for: onboot.target
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked status for: onboot.target
[2020-02-08][20:32:11][rustysd::units::units][TRACE] Reached target onboot.target
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Activate id: 5
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock unit: 5
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked unit: 5
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock status for: network.target
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked status for: network.target
[2020-02-08][20:32:11][rustysd::units::units][TRACE] Reached target network.target
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Activate id: 8
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Lock unit: 8
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Locked unit: 8
[2020-02-08][20:32:11][rustysd::units::activate][TRACE] Unit: services.target ignores activation. Not all dependencies have been started (still waiting for: [2, 4, 7])
[2020-02-08][20:32:11][rustysd::socket_activation][TRACE] Interrupted socketactivation select because the eventfd fired
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:11][rustysd::socket_activation][TRACE] Reset eventfd value
[2020-02-08][20:32:11][rustysd::services::fork_parent][TRACE] [FORK_PARENT] Service: rngd.service forked with pid: 841
[2020-02-08][20:32:11][rustysd::services::fork_parent][TRACE] [FORK_PARENT] service rngd.service doesnt notify
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::services::fork_parent][TRACE] [FORK_PARENT] Service: docker.service forked with pid: 842
[2020-02-08][20:32:11][rustysd::services::fork_parent][TRACE] [FORK_PARENT] service docker.service doesnt notify
[2020-02-08][20:32:11][rustysd::socket_activation][TRACE] Interrupted socketactivation select because the eventfd fired
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:11][rustysd::socket_activation][TRACE] Reset eventfd value
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-08][20:32:11][rustysd::services::fork_parent][TRACE] [FORK_PARENT] Service: mdevd.service forked with pid: 843
[2020-02-08][20:32:11][rustysd::services::fork_parent][TRACE] [FORK_PARENT] service mdevd.service doesnt notify
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Interrupted stderr select because the eventfd fired
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Reset eventfd value
[rngd.service][STDERR] EXECV: "/usr/bin/crun" ["crun", "--log", "/var/log/crun.log", "run", "--no-pivot", "--bundle", "/containers/services/rngd/", "rngd"]
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Interrupted stderr select because the eventfd fired
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Interrupted stderr select because the eventfd fired
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Interrupted stdout select because the eventfd fired
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Interrupted stdout select because the eventfd fired
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Interrupted stdout select because the eventfd fired
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:11][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-08][20:32:11][rustysd::socket_activation][TRACE] Interrupted socketactivation select because the eventfd fired
[2020-02-08][20:32:11][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:12][rustysd::socket_activation][TRACE] Reset eventfd value
[2020-02-08][20:32:12][rustysd::notification_handler][TRACE] Interrupted notification select because the eventfd fired
[2020-02-08][20:32:12][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:12][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-08][20:32:12][rustysd::notification_handler][TRACE] Interrupted notification select because the eventfd fired
[2020-02-08][20:32:12][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:12][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-08][20:32:12][rustysd::notification_handler][TRACE] Interrupted notification select because the eventfd fired
[2020-02-08][20:32:12][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-08][20:32:12][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Activate id: 8
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Lock unit: 8
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Locked unit: 8
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Lock status for: services.target
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Locked status for: services.target
[2020-02-08][20:32:12][rustysd::units::units][TRACE] Reached target services.target
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Activate id: 8
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Lock unit: 8
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Locked unit: 8
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Lock status for: services.target
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Locked status for: services.target
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Don't activate Unit: "services.target". Has status: Started
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Activate id: 1
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Lock unit: 1
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Activate id: 8
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Lock unit: 8
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Locked unit: 8
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Lock status for: services.target
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Locked status for: services.target
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Don't activate Unit: "services.target". Has status: Started
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Locked unit: 1
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Lock status for: default.target
[2020-02-08][20:32:12][rustysd::units::activate][TRACE] Locked status for: default.target
[2020-02-08][20:32:12][rustysd::units::units][TRACE] Reached target default.target
[docker.service][STDERR] EXECV: "/usr/bin/crun" ["crun", "--log", "/var/log/crun.log", "run", "--no-pivot", "--bundle", "/containers/services/docker/", "docker"]
[mdevd.service][STDERR] EXECV: "/usr/bin/crun" ["crun", "--log", "/var/log/crun.log", "run", "--no-pivot", "--bundle", "/containers/services/mdevd/", "mdevd"]
[rngd.service][STDERR] bind socket to `/run/crun/rngd/notify`: Address already in use
[2020-02-08][20:32:12][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 844
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] All processes spawned by rustysd have a pid entry. This did not: 844. Probably a rerooted orphan that got killed.
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 841
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Check if we want to restart the unit
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Service with id: 7, name: rngd.service pid: 841 exited with: Exit(1)
[docker.service][STDERR] bind socket to `/run/crun/docker/notify`: Address already in use
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Recursively killing all services requiring service rngd.service
[2020-02-08][20:32:12][rustysd::units::units][TRACE] Deactivate unit: rngd.service
[2020-02-08][20:32:12][rustysd::services::services][TRACE] Run /usr/bin/crun kill rngd for service: rngd.service
[2020-02-08][20:32:12][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-08][20:32:12][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 848
[2020-02-08][20:32:12][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 842
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 845
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 849
[2020-02-08][20:32:12][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-08][20:32:12][rustysd::services::services][TRACE] Wait for /usr/bin/crun kill rngd for service: rngd.service
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] All processes spawned by rustysd have a pid entry. This did not: 848. Probably a rerooted orphan that got killed.
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Check if we want to restart the unit
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Service with id: 2, name: docker.service pid: 842 exited with: Exit(1)
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Recursively killing all services requiring service docker.service
[2020-02-08][20:32:12][rustysd::units::units][TRACE] Deactivate unit: docker.service
[2020-02-08][20:32:12][rustysd::services::services][TRACE] Run /usr/bin/crun kill docker for service: docker.service
[2020-02-08][20:32:12][rustysd::services::services][TRACE] Wait for /usr/bin/crun kill docker for service: docker.service
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] All processes spawned by rustysd have a pid entry. This did not: 845. Probably a rerooted orphan that got killed.
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] All processes spawned by rustysd have a pid entry. This did not: 849. Probably a rerooted orphan that got killed.
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 852
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] All processes spawned by rustysd have a pid entry. This did not: 852. Probably a rerooted orphan that got killed.
[2020-02-08][20:32:12][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 843
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Check if we want to restart the unit
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Service with id: 4, name: mdevd.service pid: 843 exited with: Exit(1)
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Recursively killing all services requiring service mdevd.service
[2020-02-08][20:32:12][rustysd::units::units][TRACE] Deactivate unit: mdevd.service
[2020-02-08][20:32:12][rustysd::services::services][TRACE] Run /usr/bin/crun kill mdevd for service: mdevd.service
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 856
[2020-02-08][20:32:12][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-08][20:32:12][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-08][20:32:12][rustysd::services::services][TRACE] Wait for /usr/bin/crun kill mdevd for service: mdevd.service
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] All processes spawned by rustysd have a pid entry. This did not: 856. Probably a rerooted orphan that got killed.
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 854
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Helper process for service: rngd.service exited with: Exit(1)
[2020-02-08][20:32:12][rustysd::services::services][TRACE] success running /usr/bin/crun kill rngd for service: rngd.service
[2020-02-08][20:32:12][rustysd::services::services][ERROR] Error killing process group for service rngd.service: ESRCH: No such process
[2020-02-08][20:32:12][rustysd::services::services][TRACE] Success killing process os specificly for service rngd.service
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][ERROR] Service rngd.service (ID 7) failed to stop cleanly because: Perstart failed: /usr/bin/crun kill rngd exited with: Exit(1)
[rngd.service][STDERR] error opening file `/run/crun/rngd/status`: No such file or directory
[rngd.service][STDERR] sync socket closed
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 859
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Helper process for service: docker.service exited with: Exit(1)
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 861
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][TRACE] Helper process for service: mdevd.service exited with: Exit(1)
[2020-02-08][20:32:12][rustysd::services::services][TRACE] success running /usr/bin/crun kill docker for service: docker.service
[2020-02-08][20:32:12][rustysd::services::services][ERROR] Error killing process group for service docker.service: ESRCH: No such process
[2020-02-08][20:32:12][rustysd::services::services][TRACE] Success killing process os specificly for service docker.service
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][ERROR] Service docker.service (ID 2) failed to stop cleanly because: Perstart failed: /usr/bin/crun kill docker exited with: Exit(1)
[2020-02-08][20:32:12][rustysd::services::services][TRACE] success running /usr/bin/crun kill mdevd for service: mdevd.service
[2020-02-08][20:32:12][rustysd::services::services][ERROR] Error killing process group for service mdevd.service: ESRCH: No such process
[2020-02-08][20:32:12][rustysd::services::services][TRACE] Success killing process os specificly for service mdevd.service
[2020-02-08][20:32:12][rustysd::services::service_exit_handler][ERROR] Service mdevd.service (ID 4) failed to stop cleanly because: Perstart failed: /usr/bin/crun kill mdevd exited with: Exit(1)
[mdevd.service][STDERR] error opening file `/run/crun/mdevd/status`: No such file or directory
[mdevd.service][STDERR] bind socket to `/run/crun/mdevd/notify`: Address already in use
[mdevd.service][STDERR] sync socket closed
[docker.service][STDERR] error opening file `/run/crun/docker/status`: No such file or directory
[docker.service][STDERR] sync socket closedCheck directory again:
/ # ls -lh /run/crun/
total 0
drwx------ 3 root root 80 Feb 8 20:32 docker
drwx------ 3 root root 80 Feb 8 20:32 mdevd
drwx------ 3 root root 80 Feb 8 20:32 rngdCheck containers:
/ # crun list
NAME PID STATUS BUNDLE PATH Try to start manually:
/ # /usr/bin/crun --log /var/log/crun.log run --no-pivot --bundle /containers/se
rvices/rngd/ rngd
2020-02-08T20:34:47.000981332Z: container `rngd` already existsCleanup ...
/ # rm -rf /run/crun/*Try to start again (started in qemu shell without --detach... so it blocks now the shell and is running)
/ # /usr/bin/crun --log /var/log/crun.log run --no-pivot --bundle /containers/services/rngd/ rngd
So it looks like start fails, but /var/run/crun files still there. But I think ExecStop and ExecStopPost should clean up (kill + delete) the failed container...?
run + kill + delete works fine used in a shell
pwFoo
commented
4 years ago I don't know why and how the socket would be used / exist...?
KillingSpark
commented
4 years ago As for why the cleanup is not working: it's probably because /usr/bin/crun delete rngd; /bin/rm -rf /run/crun/docker these should be two lines. You can specify multiple poststop commands.
[Unit]
Description=Start services rngd
[Service]
ExecStart=/usr/bin/crun --log /var/log/crun.log run --no-pivot --bundle /containers/services/rngd/ rngd
ExecStop=/usr/bin/crun kill rngd
ExecStopPost=/usr/bin/crun delete rngd
ExecStopPost=/bin/rm -rf /run/crun/docker
Type=simple
[Install]
WantedBy=services.targetFor why the containers fail, I am very confused
pwFoo
commented
4 years ago Good to know!
The rm was additional to work around the problem. With normal run + kill / delete the files should be deleted without that.
Would it a problem to detach or NOT detach the crun process? Without --detach the it would be interactive / block the shell executed in bash / sh.
KillingSpark
commented
4 years ago Pretty sure you want to use crun without the --detach. You want crun to stay alive as long as the container lives
KillingSpark
commented
4 years ago I added some more tracing around exiting/killing of services. Could you run your scenario again and post the output (maybe only with one service to make it easier to attribute pids to services)?
I am still not sure what exactly happens here, but I am pretty sure these lines are from the ExecStop command:
[rngd.service][STDERR] error opening file `/run/crun/rngd/status`: No such file or directory
[rngd.service][STDERR] sync socket closedWhich means even if there were two instances of a container trying to run at the same time none of them comes far enough to open the status file.
Interestingly the ExecStopPost commands never got started so it makes sense that the directories are still there after rustysd killed the services.
pwFoo
commented
4 years ago Hi, I need some time to test it. Maybe in the evening.
Moritz Borcherding notifications@github.com schrieb am Mo., 10. Feb. 2020, 11:38:
I added some more tracing around exiting/killing of services. Could you run your scenario again and post the output (maybe only with one service to make it easier to attribute pids to services)?
I am still not sure what exactly happens here, but I am pretty sure these lines are from the ExecStop command:
[rngd.service][STDERR] error opening file
/run/crun/rngd/status: No such file or directory [rngd.service][STDERR] sync socket closedWhich means even if there were two instances of a container trying to run at the same time none of them comes far enough to open the status file.
Interestingly the ExecStopPost commands never got started so it makes sense that the directories are still there after rustysd killed the services.
— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/KillingSpark/rustysd/issues/22?email_source=notifications&email_token=AACRMYG3AYWOT6XGZCQYDEDRCEVCBA5CNFSM4KR2FXN2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOELIATVY#issuecomment-584059351, or unsubscribe https://github.com/notifications/unsubscribe-auth/AACRMYGWY3TMYF7YI3XYYSTRCEVCBANCNFSM4KR2FXNQ .
pwFoo
commented
4 years ago Hi, tested with one service, disabled ExecStop / ExecStopPost with a new rustysd build.
[Unit]
Description=Start services mdevd
[Service]
ExecStart=/usr/bin/crun --log /var/log/crun.log run --no-pivot --bundle /containers/services/mdevd/ mdevd
#ExecStop=/usr/bin/crun kill mdevd
#ExecStopPost=/usr/bin/crun delete mdevd; /bin/rm -rf /run/crun/docker
Type=simple
[Install]
WantedBy=services.targetDon't know if it added some debugging output. Output:
/ # rustysd &
/ # [2020-02-11][20:49:29][rustysd::units::loading][TRACE] "./unitfiles/default.target", 1
[2020-02-11][20:49:29][rustysd::units::loading][TRACE] "./unitfiles/init.target", 2
[2020-02-11][20:49:29][rustysd::units::loading][TRACE] "./unitfiles/mdevd.service", 3
[2020-02-11][20:49:29][rustysd::units::unit_parsing::service_unit][TRACE] UID: Uid(0)
[2020-02-11][20:49:29][rustysd::units::loading][TRACE] "./unitfiles/network.target", 4
[2020-02-11][20:49:29][rustysd::units::loading][TRACE] "./unitfiles/onboot.target", 5
[2020-02-11][20:49:29][rustysd::units::loading][TRACE] "./unitfiles/services.target", 6
[2020-02-11][20:49:29][rustysd][TRACE] Finished loading units
[2020-02-11][20:49:29][rustysd::units::dependency_resolving][TRACE] Id 1 references ids: [6]
[2020-02-11][20:49:29][rustysd::units::dependency_resolving][TRACE] Id 6 references ids: [1, 3, 4]
[2020-02-11][20:49:29][rustysd::units::dependency_resolving][TRACE] Id 3 references ids: [6]
[2020-02-11][20:49:29][rustysd::units::dependency_resolving][TRACE] Id 4 references ids: [5, 6]
[2020-02-11][20:49:29][rustysd::units::dependency_resolving][TRACE] Id 5 references ids: [2, 4]
[2020-02-11][20:49:29][rustysd::units::dependency_resolving][TRACE] Id 2 references ids: [5]
[2020-02-11][20:49:29][rustysd][TRACE] Finished pruning units
[2020-02-11][20:49:29][rustysd][TRACE] Unit dependencies passed sanity checks
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Root unit: mdevd.service
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Root unit: init.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Activate id: 3
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock unit: 3
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked unit: 3
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock status for: mdevd.service
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked status for: mdevd.service
[2020-02-11][20:49:29][rustysd::services::services][TRACE] Start service mdevd.service
[2020-02-11][20:49:29][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-11][20:49:29][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-11][20:49:29][rustysd::notification_handler][TRACE] Interrupted stderr select because the eventfd fired
[2020-02-11][20:49:29][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-11][20:49:29][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-11][20:49:29][rustysd::notification_handler][TRACE] Interrupted stdout select because the eventfd fired
[2020-02-11][20:49:29][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-11][20:49:29][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Activate id: 2
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock unit: 2
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked unit: 2
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock status for: init.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked status for: init.target
[2020-02-11][20:49:29][rustysd::units::units][TRACE] Reached target init.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Activate id: 5
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock unit: 5
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked unit: 5
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock status for: onboot.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked status for: onboot.target
[2020-02-11][20:49:29][rustysd::units::units][TRACE] Reached target onboot.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Activate id: 4
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock unit: 4
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked unit: 4
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock status for: network.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked status for: network.target
[2020-02-11][20:49:29][rustysd::units::units][TRACE] Reached target network.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Activate id: 6
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock unit: 6
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked unit: 6
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Unit: services.target ignores activation. Not all dependencies have been started (still waiting for: [3])
[2020-02-11][20:49:29][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-11][20:49:29][rustysd::socket_activation][TRACE] Interrupted socketactivation select because the eventfd fired
[2020-02-11][20:49:29][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-11][20:49:29][rustysd::socket_activation][TRACE] Reset eventfd value
[2020-02-11][20:49:29][rustysd::platform::eventfd::pipe_eventfd][TRACE] notify eventfd
[2020-02-11][20:49:29][rustysd::services::fork_parent][TRACE] [FORK_PARENT] Service: mdevd.service forked with pid: 871
[2020-02-11][20:49:29][rustysd::services::fork_parent][TRACE] [FORK_PARENT] service mdevd.service doesnt notify
[mdevd.service][Started][STDERR] EXECV: "/usr/bin/crun" ["crun", "--log", "/var/log/crun.log", "run", "--no-pivot", "--bundle", "/containers/services/mdevd/", "mdevd"]
[2020-02-11][20:49:29][rustysd::notification_handler][TRACE] Interrupted notification select because the eventfd fired
[2020-02-11][20:49:29][rustysd::platform::eventfd::pipe_eventfd][TRACE] reset pipe eventfd
[2020-02-11][20:49:29][rustysd::notification_handler][TRACE] Reset eventfd value
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Activate id: 6
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock unit: 6
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked unit: 6
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock status for: services.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked status for: services.target
[2020-02-11][20:49:29][rustysd::units::units][TRACE] Reached target services.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Activate id: 1
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock unit: 1
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked unit: 1
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Lock status for: default.target
[2020-02-11][20:49:29][rustysd::units::activate][TRACE] Locked status for: default.target
[2020-02-11][20:49:29][rustysd::units::units][TRACE] Reached target default.target
[mdevd.service][Started][STDERR] bind socket to `/run/crun/mdevd/notify`: Address already in use
[2020-02-11][20:49:29][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-11][20:49:29][rustysd::signal_handler][TRACE] No more state changes to poll
[2020-02-11][20:49:29][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 871
[2020-02-11][20:49:29][rustysd::services::service_exit_handler][TRACE] Check if we want to restart the unit
[2020-02-11][20:49:29][rustysd::services::service_exit_handler][TRACE] Service with id: 3, name: mdevd.service pid: 871 exited with: Exit(1)
[2020-02-11][20:49:29][rustysd::services::service_exit_handler][TRACE] Recursively killing all services requiring service mdevd.service
[2020-02-11][20:49:29][rustysd::units::units][TRACE] Deactivate unit: mdevd.service
[2020-02-11][20:49:29][rustysd::services::services][TRACE] Success killing process group for service mdevd.service
[2020-02-11][20:49:29][rustysd::services::services][TRACE] Success killing process os specificly for service mdevd.service
[2020-02-11][20:49:29][rustysd::services::services][TRACE] Stop processes for service: mdevd.service ran succesfully. Running poststop commands
[2020-02-11][20:49:29][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 872
[2020-02-11][20:49:29][rustysd::services::service_exit_handler][TRACE] All processes spawned by rustysd have a pid entry. This did not: 872. Probably a rerooted orphan that got killed.
[2020-02-11][20:49:29][rustysd::services::service_exit_handler][TRACE] Exit handler with pid: 873
[2020-02-11][20:49:29][rustysd::services::service_exit_handler][TRACE] All processes spawned by rustysd have a pid entry. This did not: 873. Probably a rerooted orphan that got killed.I startet crun without --detach in the background ( by "&") to check PIDs of crun / container process.
745 root 0:00 {3} crun run --no-pivot --bundle /containers/services/mdev
747 root 0:00 /usr/local/sbin/mdevdCrun is still running, but container process is spawned as child process. But it should be possible for rustysd to handle process with childs, right?
KillingSpark
commented
4 years ago Thanks! I am now pretty confident that rustysd is not the culprit here. If I understand their code there should be exactly those three processes that you can observe in the log:
crun runBut what I noticed is that the behaviour differs if crun detects it is being run by systemd (and therefor detects being run by rustysd). This explains the differing behaviour when you start it manually. Could you confirm that this actually works under systemd?
I think this is a bug with them and filed an issue. I might have found where the error is but I'll wait for them to respond to my issue (see issue here: https://github.com/containers/crun/issues/262)
KillingSpark
commented
4 years ago They confirmed that issue was with them, see PR here: https://github.com/containers/crun/pull/263. If this is merged your unit should work correctly.
pwFoo
commented
4 years ago The fixed version https://github.com/giuseppe/crun/tree/fix-sd-notify-create-detach works for me! docker won't start because I moved to cgroups v2.
[docker.service][Started][STDERR] time="2020-02-12T20:21:36.324817978Z" level=warning msg="Your kernel does not support cgroup memory limit"
[docker.service][Started][STDERR] time="2020-02-12T20:21:36.326927344Z" level=warning msg="Unable to find cpu cgroup in mounts"
[docker.service][Started][STDERR] time="2020-02-12T20:21:36.329094477Z" level=warning msg="Unable to find blkio cgroup in mounts"
[docker.service][Started][STDERR] time="2020-02-12T20:21:36.331028556Z" level=warning msg="Unable to find cpuset cgroup in mounts"
[docker.service][Started][STDERR] time="2020-02-12T20:21:36.333261927Z" level=warning msg="mountpoint for pids not found"
[docker.service][Started][STDERR] time="2020-02-12T20:21:36.335352934Z" level=debug msg="Cleaning up old mountid : start."
[docker.service][Started][STDERR] Error starting daemon: Devices cgroup isn't mountedI think I move to podman or convert docker images to crun / runc images with linuxkit...
Great work @KillingSpark !!! Thanks for fixing that crun bug 👍
pwFoo
commented
4 years ago -rw-r--r-- 1 root root 42 Feb 12 21:20 rustysd-cmdline
-rw-r--r-- 1 root root 76M Feb 12 21:20 rustysd-initrd.img
-rw-r--r-- 1 root root 4,7M Feb 12 21:20 rustysd-kernel/ # rsdctl /notifications/control.socket status
Write cmd: {"jsonrpc":"2.0","method":"status"}
Wait for response
[2020-02-12][20:26:59][rustysd::control::control][TRACE] Execute command: Status(None)
Got response
{
"jsonrpc": "2.0",
"result": [
{
"Name": "mdevd.service",
"Restarted": "0",
"Sockets": [],
"Status": "Started",
"UpSince": "323.484697726s"
},
{
"Name": "default.target",
"Status": "Started"
},
{
"Name": "services.target",
"Status": "Started"
},
{
"Name": "onboot.target",
"Status": "Started"
},
{
"Name": "init.target",
"Status": "Started"
},
{
"Name": "rngd.service",
"Restarted": "0",
"Sockets": [],
"Status": "Started",
"UpSince": "323.459746655s"
},
{
"Name": "network.target",
"Status": "Started"
},
{
"Name": "docker.service",
"Restarted": "0",
"Sockets": [],
"Status": "Stopping",
"UpSince": "323.395984939s"
}
]
} 692 0 0:00 rustysd
706 0 0:00 {11} crun --log /var/log/crun.log run --no-pivot --bundle
707 0 0:00 {11} crun --log /var/log/crun.log run --no-pivot --bundle
712 0 0:00 /usr/local/sbin/mdevd
713 0 0:00 /usr/sbin/rngd -f -r /dev/urandom -p /var/run/rngd.pid@KillingSpark
Looks like --detach works too!
1484 0 0:00 rustysd
1498 0 0:00 {11} crun --log /var/log/crun.log run --detach --no-pivot
1500 0 0:00 {11} crun --log /var/log/crun.log run --no-pivot --bundle
1503 0 0:00 {11} crun --log /var/log/crun.log run --detach --no-pivot
1504 0 0:00 [11]
1505 0 0:00 /usr/local/sbin/mdevd
1509 0 0:00 /usr/sbin/rngd -f -r /dev/urandom -p /var/run/rngd.pid
cdbattags
commented
4 years ago @pwFoo, holy hell this is exciting! Shall we start using your repo as a basis and go from there? Or rather, are you open to outside help on this?
My personal goal is linuxkit -> redox -> rustysd -> process/service x so with your work it looks like we're almost there minus Redox.
pwFoo
commented
4 years ago Would bei great to have some help, but there are many problems / workarounds (rustysd ist unused during boot because of problems with a getty service, prepare overlay / partition mount, how extend / update services and handle users / passwd without rebuild)...
The base should be a minimal, fast and lightweight system (kernel, modules, init) extended by containers (services, gui, ...).
Maybe it's possible to run two rustysd (base and extension part) or the containers / unitfiles need to be extended (overlay mount?) before rustysd starts.
Redox(OS?) or fluxbox should be extension part
KillingSpark
commented
4 years ago Having a multi-stage boot sequence is pretty normal. Having a few scripts to setup all mounts etc and then execing into rustysd sounds good enough tbh.
It is probably even better than duct-taping services that reload the rustysd config after the overlay has been loaded. At least to me that sounds more solid (and easier to debug if something goes wrong).
Hi, I have a problem with unitfiles starting a container. I think because of the process runc / crun which ends after the container process is started... So rustysd thinks the service is dead?
Example unitfile:
services.target