[systemd-devel] systemd-growfs blocks boot until completed

[Mirza Krak]

Den fre 27 sep. 2019 kl 15:23 skrev Lennart Poettering <lennart at poettering.net>:
>
> On Fr, 27.09.19 14:35, Mirza Krak (mirza at mkrak.org) wrote:
>
> > Hi,
> >
> > I have been using the systemd-growfs feature for a while, and been
> > happy with it so far.
> >
> > But recently I upgraded my distribution (custom based on Yocto) which
> > also upgraded systemd from 239 to 241, and I can see that there has
> > been a change in behavior of the "systemd-growfs" feature.
> >
> > In systemd 241, it blocks the boot process while it is growing the
> > filesystem, here is an example log:
> >
> >          Mounting /data...
> > [   10.693190] EXT4-fs (mmcblk0p4): mounted filesystem with ordered
> > data mode. Opts: (null)
> > [  OK  ] Mounted /data.
> >          Starting Grow File System on /data...
> > [   10.780109] EXT4-fs (mmcblk0p4): resizing filesystem from 131072 to
> > 30773248 blocks
> > [    **] A start job is running for Grow File System on /data (11s /
> > no limit)
> > [  *** ] A start job is running for Grow File System on /data (21s /
> > no limit)
> > [***   ] A start job is running for Grow File System on /data (30s / no limit)
> > [***   ] A start job is running for Grow File System on /data (42s / no limit)
> > [    **] A start job is running for Grow File System on /data (52s / no limit)
> > [**    ] A start job is running for Grow Filâ…stem on /data (1min 2s / no limit)
> > [ ***  ] A start job is running for Grow Filâ…tem on /data (1min 15s / no limit)
> > [  *** ] A start job is running for Grow Filâ…tem on /data (1min 26s / no limit)
> > [  *** ] A start job is running for Grow Filâ…tem on /data (1min 36s / no limit)
> > [ ***  ] A start job is running for Grow Filâ…tem on /data (1min 46s / no limit)
> > [   ***] A start job is running for Grow Filâ…tem on /data (1min 56s / no limit)
> > [**    ] A start job is running for Grow Filâ…stem on /data (2min 6s / no limit)
> > [    **] A start job is running for Grow Filâ…tem on /data (2min 17s / no limit)
> > [*     ] A start job is running for Grow Filâ…tem on /data (2min 27s / no limit)
> > [ ***  ] A start job is running for Grow Filâ…tem on /data (2min 35s / no limit)
> >
> > In the previous version (239), this occurred in the background and did
> > not obstruct the boot process in any noticeable way. Which matched my
> > expectations on how this feature would work.
> >
> > So my question is, was the change intentional and if so, what was the reasoning?
>
> Hmm, the tool doesn't do much. It just calls an fs ioctl. If you
> attach gdb to the process (or strace it), can you see what it is
> blocking on?

It seems that the ioctl operation is blocking until the resize is completed,

openat(AT_FDCWD, "/data", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
openat(AT_FDCWD, "/dev/block/179:4", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 4
ioctl(4, BLKBSZGET, [1024])             = 0
ioctl(4, BLKGETSIZE64, [31511805952])   = 0
fstatfs64(3, 88, 0x7eb56bf0)            = 0
ioctl(3, _IOC(_IOC_WRITE, 0x66, 0x10, 0x8), 0x7eb56be

I would like to clarify that it eventually will complete (after 5
minutes on my device), and then the boot proceeds as normal. The ioctl
behavior has not changed, as it was blocking in the kernel in my
previous distribution version as well, but the
systemd-growfs at data.service did not block the boot on systemd 239
where this was performed in parallel, but now it seems to block.

The Linux kernel is: 4.19.71

This is what the systemd-growfs at .service looks like:

# Automatically generated by systemd-fstab-generator
[Unit]
Description=Grow File System on %f
Documentation=man:systemd-growfs at .service(8)
DefaultDependencies=no
BindsTo=%i.mount
Conflicts=shutdown.target
After=%i.mount
Before=shutdown.target local-fs.target

[Service]
Type=oneshot
RemainAfterExit=yes
ExecStart=/lib/systemd/systemd-growfs /data
TimeoutSec=0

-- 
Med Vänliga Hälsningar / Best Regards

Mirza Krak
email: mirza at mkrak.org
web: https://mkrak.org
pgp: https://keybase.io/mirzak/key.asc