[systemd-devel] Troubleshooting Failed Nspawn Starts

[Rich Freeman]

Occassionally I'll have nspawn containers that freeze up when they're
loading.  What is the best way to troubleshoot these and get useful
info to devs?

This is on systemd-218, on Gentoo.

Also, is there any way to detect these freezes, perhaps getting the
service launching it to at least fail?  Short of installing nagios/etc
something like this is hard to spot right now.

Example of a frozen container:

systemctl status mariadb-contain
● mariadb-contain.service - mariadb container
   Loaded: loaded (/etc/systemd/system/mariadb-contain.service;
enabled; vendor preset: enabled)
   Active: active (running) since Mon 2015-08-10 07:21:48 EDT; 37min ago
     Docs: man:systemd-nspawn(1)
 Main PID: 1033 (systemd-nspawn)
   Status: "Container running."
   CGroup: /system.slice/mariadb-contain.service
           ├─1033 /usr/bin/systemd-nspawn --quiet --keep-unit --boot
--link-journal=guest --directory=/sstorage3/cont...
           ├─1044 /usr/lib/systemd/systemd
           └─system.slice
             ├─systemd-journald.service
             │ └─1407 /usr/lib/systemd/systemd-journald
             └─systemd-journal-flush.service
               └─1340 /usr/bin/journalctl --flush

Aug 10 07:57:45 rich64 systemd-nspawn[1033]: [1.5K blob data]
Aug 10 07:57:55 rich64 systemd-nspawn[1033]: [1.5K blob data]
Aug 10 07:58:05 rich64 systemd-nspawn[1033]: [1.5K blob data]
Aug 10 07:58:14 rich64 systemd-nspawn[1033]: [1.5K blob data]
Aug 10 07:58:24 rich64 systemd-nspawn[1033]: [1.5K blob data]
Aug 10 07:58:34 rich64 systemd-nspawn[1033]: [1.6K blob data]
Aug 10 07:58:44 rich64 systemd-nspawn[1033]: [1.6K blob data]
Aug 10 07:58:54 rich64 systemd-nspawn[1033]: [1.5K blob data]
Aug 10 07:59:04 rich64 systemd-nspawn[1033]: [1.5K blob data]
Aug 10 07:59:13 rich64 systemd-nspawn[1033]: [1.6K blob data]


Journal for this boot:
Aug 10 07:20:04 mariadb systemd-journal[16]: Journal stopped
-- Reboot --
Aug 10 07:21:54 mariadb systemd-journal[13]: Runtime journal is using
8.0M (max allowed 793.0M, trying to leave 1.1G fre
Aug 10 07:21:57 mariadb systemd-journal[13]: Permanent journal is
using 544.0M (max allowed 4.0G, trying to leave 4.0G f
Aug 10 07:22:02 mariadb systemd-journal[13]: Time spent on flushing to
/var is 5.461887s for 2 entries.
Aug 10 07:22:04 mariadb systemd-journal[13]: Journal started
Aug 10 07:22:07 mariadb systemd[1]: Starting Flush Journal to
Persistent Storage...
Aug 10 07:23:07 mariadb systemd-journal[19]: Runtime journal is using
8.0M (max allowed 793.0M, trying to leave 1.1G fre
Aug 10 07:23:10 mariadb systemd-journal[19]: Permanent journal is
using 544.0M (max allowed 4.0G, trying to leave 4.0G f
Aug 10 07:23:21 mariadb systemd-journal[19]: Time spent on flushing to
/var is 10.996266s for 2 entries.
Aug 10 07:23:21 mariadb systemd-journal[19]: Journal started
Aug 10 07:23:07 mariadb systemd[1]: systemd-journald.service watchdog
timeout (limit 1min)!
Aug 10 07:24:27 mariadb systemd[1]: Time has been changed


--
Rich