Booting with "systemd.log_level=debug" revealed:
Dec 18 17:26:22 ubuntu systemd-udevd[1326]: value '[dmi/id]sys_vendor' is 'QEMU'
Dec 18 17:26:22 ubuntu systemd-udevd[1326]: created db file
'/run/udev/data/b7:2' for '/devices/virtual/block/loop2'
Dec 18 17:26:22 ubuntu systemd[1]: dev-loop2.device: Changed dead -> tentative
Dec 18 17:26:22 ubuntu systemd-udevd[1326]: created db file
'/run/udev/data/b7:2' for '/devices/virtual/block/loop2'
Dec 18 17:26:22 ubuntu systemd-udevd[1326]: passed 293 byte device to netlink
monitor 0x557a8c0f8680
Dec 18 17:26:22 ubuntu systemd[1120]: dev-loop2.device: Changed dead ->
tentative
...
Dec 18 17:26:22 ubuntu systemd[1120]: sys-devices-virtual-block-loop2.device:
Changed dead -> plugged
Dec 18 17:26:22 ubuntu systemd[1120]: dev-loop2.device: Changed tentative ->
plugged
Dec 18 17:26:22 ubuntu systemd-udevd[529]: passed 179 byte device to netlink
monitor 0x557a8c0c7bc0
Dec 18 17:26:22 ubuntu systemd[1]: sys-devices-virtual-block-loop2.device:
Changed dead -> plugged
Dec 18 17:26:22 ubuntu systemd[1]: dev-loop2.device: Changed tentative ->
plugged
...
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dloop2_2edevice
interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=1009
reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dloop2_2edevice
interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=1010
reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
...
Dec 18 17:26:22 ubuntu systemd-udevd[1328]: created db file
'/run/udev/data/b7:2' for '/devices/virtual/block/loop2'
Dec 18 17:26:22 ubuntu systemd-udevd[1328]: created db file
'/run/udev/data/b7:2' for '/devices/virtual/block/loop2'
Dec 18 17:26:22 ubuntu systemd-udevd[1328]: passed 252 byte device to netlink
monitor 0x557a8c0f8680
Dec 18 17:26:22 ubuntu systemd[1]: sys-devices-virtual-block-loop2.device:
Installed new job sys-devices-virtual-block-loop2.device/nop as 412
Dec 18 17:26:22 ubuntu systemd[1]: dev-loop2.device: Installed new job
dev-loop2.device/nop as 413
Dec 18 17:26:22 ubuntu systemd[1]: sys-devices-virtual-block-loop2.device:
Changed plugged -> dead
Dec 18 17:26:22 ubuntu systemd[1120]: sys-devices-virtual-block-loop2.device:
Installed new job sys-devices-virtual-block-loop2.device/nop as 14
Dec 18 17:26:22 ubuntu systemd[1]: dev-loop2.device: Changed plugged -> dead
Dec 18 17:26:22 ubuntu systemd[1120]: dev-loop2.device: Installed new job
dev-loop2.device/nop as 15
Dec 18 17:26:22 ubuntu systemd[1120]: sys-devices-virtual-block-loop2.device:
Changed plugged -> dead
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dloop2_2edevice
interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=1028
reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Dec 18 17:26:22 ubuntu systemd[1120]: dev-loop2.device: Changed plugged -> dead
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a path=/org/freedesktop/systemd1/unit/dev_2dloop2_2edevice
interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=1029
reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Dec 18 17:26:22 ubuntu systemd[1120]: dev-loop2.device: Job
dev-loop2.device/nop finished, result=done
Dec 18 17:26:22 ubuntu systemd[1120]: sys-devices-virtual-block-loop2.device:
Job sys-devices-virtual-block-loop2.device/nop finished, result=done
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a
path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dvirtual_2dblock_2dloop2_2edevice
interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=1030
reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Dec 18 17:26:22 ubuntu systemd[1120]: sys-devices-virtual-block-loop2.device:
Collecting.
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a
path=/org/freedesktop/systemd1/unit/sys_2ddevices_2dvirtual_2dblock_2dloop2_2edevice
interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=1031
reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Dec 18 17:26:22 ubuntu systemd[1120]: dev-loop2.device: Collecting.
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a path=/org/freedesktop/systemd1
interface=org.freedesktop.systemd1.Manager member=JobNew cookie=1032
reply_cookie=0 signature=uos error-name=n/a error-message=n/a
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a path=/org/freedesktop/systemd1
interface=org.freedesktop.systemd1.Manager member=JobNew cookie=1033
reply_cookie=0 signature=uos error-name=n/a error-message=n/a
Dec 18 17:26:22 ubuntu systemd[1]: dev-loop2.device: Job dev-loop2.device/nop
finished, result=done
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a path=/org/freedesktop/systemd1
interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=1034
reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
Dec 18 17:26:22 ubuntu systemd[1]: sys-devices-virtual-block-loop2.device: Job
sys-devices-virtual-block-loop2.device/nop finished, result=done
Dec 18 17:26:22 ubuntu systemd[1]: Sent message type=signal sender=n/a
destination=n/a path=/org/freedesktop/systemd1
interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=1035
reply_cookie=0 signature=uoss error-name=n/a error-message=n/a
Dec 18 17:26:22 ubuntu systemd[1]: sys-devices-virtual-block-loop2.device:
Collecting.
Dec 18 17:26:22 ubuntu systemd[1]: dev-loop2.device: Collecting.
** Description changed:
This is reproducible in Bionic and late.
Here's an example running 'focal':
$ lsb_release -cs
focal
$ uname -r
5.3.0-24-generic
The error is:
blk_update_request: I/O error, dev loop2, sector 0
How to trigger it:
$ sosreport -o block
or more precisely the cmd causing the situation inside the block plugin:
- $ parted -s /dev/$(losetup -f) unit s print
+ $ parted -s $(losetup -f) unit s print
https://github.com/sosreport/sos/blob/master/sos/plugins/block.py#L52
but if I run it on the next next unused loop device, in this case
/dev/loop3 (which is also unused), no errors.
While I agree that sosreport shouldn't query unused loop devices, there
is definitely something going on with the next unused loop device.
What is differentiate loop2 and loop3 and any other unused ones ?
3 things so far I have noticed:
* loop2 is the next unused loop device (losetup -f)
* A reboot is needed (if some loop modification (snap install, mount loop,
...) has been made at runtime
* I have also noticed that loop2 (or whatever the next unused one is) have
some stat as oppose to other unused loop devices. The stat exist already right
after the system boot for the next unused loop device.
/sys/block/loop2/stat
::::::::::::::
2 0 10 0 1 0 0 0 0 0 0
2 = number of read I/Os processed
10 = number of sectors read
1 = number of write I/Os processed
Explanation of each column:
https://www.kernel.org/doc/html/latest/block/stat.html
while /dev/loop3 doesn't
/sys/block/loop3/stat
::::::::::::::
0 0 0 0 0 0 0 0 0 0 0
Which tells me that something during the boot process most likely
acquired (on purpose or not) the next unused loop and possibly didn't
released it well enough.
If loop2 is generating errors, and I install a snap, the snap squashfs
will take loop2, making loop3 the next unused loop device.
If I query loop3 with 'parted' right after, no errors.
If I reboot, and query loop3 again, then no I'll have an error.
To triggers the errors it need to be after a reboot and it only impact
the first unused loop device available (losetup -f).
This was tested with focal/systemd whic his very close to latest
upstream code.
This has been test with latest v5.5 mainline kernel as well.
For now, I don't think it's a kernel problem, I'm more thinking of a
userspace misbehaviour dealing with loop device (or block device) at
boot.
--
You received this bug notification because you are a member of Ubuntu
Touch seeded packages, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1856871
Title:
i/o error if next unused loop device is queried
Status in systemd package in Ubuntu:
New
Status in udev package in Ubuntu:
New
Bug description:
This is reproducible in Bionic and late.
Here's an example running 'focal':
$ lsb_release -cs
focal
$ uname -r
5.3.0-24-generic
The error is:
blk_update_request: I/O error, dev loop2, sector 0
How to trigger it:
$ sosreport -o block
or more precisely the cmd causing the situation inside the block plugin:
$ parted -s $(losetup -f) unit s print
https://github.com/sosreport/sos/blob/master/sos/plugins/block.py#L52
but if I run it on the next next unused loop device, in this case
/dev/loop3 (which is also unused), no errors.
While I agree that sosreport shouldn't query unused loop devices,
there is definitely something going on with the next unused loop
device.
What is differentiate loop2 and loop3 and any other unused ones ?
3 things so far I have noticed:
* loop2 is the next unused loop device (losetup -f)
* A reboot is needed (if some loop modification (snap install, mount loop,
...) has been made at runtime
* I have also noticed that loop2 (or whatever the next unused one is) have
some stat as oppose to other unused loop devices. The stat exist already right
after the system boot for the next unused loop device.
/sys/block/loop2/stat
::::::::::::::
2 0 10 0 1 0 0 0 0 0 0
2 = number of read I/Os processed
10 = number of sectors read
1 = number of write I/Os processed
Explanation of each column:
https://www.kernel.org/doc/html/latest/block/stat.html
while /dev/loop3 doesn't
/sys/block/loop3/stat
::::::::::::::
0 0 0 0 0 0 0 0 0 0 0
Which tells me that something during the boot process most likely
acquired (on purpose or not) the next unused loop and possibly didn't
released it well enough.
If loop2 is generating errors, and I install a snap, the snap squashfs
will take loop2, making loop3 the next unused loop device.
If I query loop3 with 'parted' right after, no errors.
If I reboot, and query loop3 again, then no I'll have an error.
To triggers the errors it need to be after a reboot and it only impact
the first unused loop device available (losetup -f).
This was tested with focal/systemd whic his very close to latest
upstream code.
This has been test with latest v5.5 mainline kernel as well.
For now, I don't think it's a kernel problem, I'm more thinking of a
userspace misbehaviour dealing with loop device (or block device) at
boot.
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1856871/+subscriptions
--
Mailing list: https://launchpad.net/~touch-packages
Post to : touch-packages@lists.launchpad.net
Unsubscribe : https://launchpad.net/~touch-packages
More help : https://help.launchpad.net/ListHelp
