XPost: linux.debian.bugs.dist
From: [email protected]

Control: severity -1 normal

Hi!

On Mon, 2024-04-29 at 00:01:02 +0200, Chris Hofstaedtler wrote:

Control: reassign -1 dpkg

* Vincent Lefevre <[email protected]> [240428 22:33]:

Package: fdisk
Version: 2.40-8
Severity: serious

...

Setting up util-linux (2.40-8) ...
fstrim.service is a disabled or a static unit not running, not starting it. dpkg: error: dpkg frontend lock was locked by another process with pid 58569
Note: removing the lock file is always wrong, can damage the locked area and the entire system. See <https://wiki.debian.org/Teams/Dpkg/FAQ#db-lock>.
====== How can you help? (doc: https://wiki.debian.org/how-can-i-help ) ======

----- Show old opportunities as well as new ones: how-can-i-help --old -----
E: Sub-process /usr/bin/dpkg returned an error code (2)
Setting up bsdextrautils (2.40-8) ...
dpkg: dependency problems prevent configuration of fdisk:
fdisk depends on libfdisk1 (= 2.40-8); however:
Version of libfdisk1:amd64 on system is 2.40-6.

dpkg: error processing package fdisk (--configure):
dependency problems - leaving unconfigured
Setting up eject (2.40-8) ...
Setting up perl-modules-5.38 (5.38.2-4) ...
Setting up mount (2.40-8) ...
Setting up libperl5.38t64:amd64 (5.38.2-4) ...
Setting up util-linux-extra (2.40-8) ...
Setting up perl (5.38.2-4) ...
Processing triggers for libc-bin (2.37-19) ...
Processing triggers for man-db (2.12.1-1) ...
Processing triggers for mailcap (3.70+nmu1) ...
Errors were encountered while processing:
fdisk

There seem to be 2 issues: one with the dpkg lock (which may be
bug 1069183 in aptitude) and one

Possible.

I don't think dpkg is at fault here, I assume something else is either
getting activated in the middle of the transaction while the package
manager frontend driving dpkg has released the lock (which it should
not), or the package manager frontend driving dpkg is performing the
locking dance incorrectly.

with fdisk.

I see no evidence of that in the log.

Right, it seems to me, like when dpkg fails due to the already held
lock, then the frontend is not recomputing the transaction and keeps
as if nothing had gone incorrectly, until it then notices later on.


In any case, given that dpkg is not being very helpful in diagnosing
this, I'll implement support to print the process name in addition to
the pid, as this has also hit me, and it's never clear what was the
actual culprit. So that's why I'm leaving this assigned to dpkg, but
with a lower severity. If you'd like to file this elsewhere, then
please clone and reassign that.

Thanks,
Guillem

--- SoupGate-Win32 v1.05
* Origin: you cannot sedate... all the things you hate (1:229/2)

XPost: linux.debian.bugs.dist
From: [email protected]

On 2024-04-29 03:05:50 +0200, Guillem Jover wrote:

I don't think dpkg is at fault here, I assume something else is either getting activated in the middle of the transaction while the package
manager frontend driving dpkg has released the lock (which it should
not), or the package manager frontend driving dpkg is performing the
locking dance incorrectly.

Isn't dpkg able to install/uninstall a set of packages in an atomic
way (where dpkg itself would set a lock at the beginning and release
the lock once every install/uninstall has been done, so that a lock
failure would not be possible in the middle of the installation)?

with fdisk.

I see no evidence of that in the log.

Right, it seems to me, like when dpkg fails due to the already held
lock, then the frontend is not recomputing the transaction and keeps
as if nothing had gone incorrectly, until it then notices later on.

Alternatively, if this is too complicated, it could abort and let
the user fix things (which is currently needed anyway).

In any case, given that dpkg is not being very helpful in diagnosing
this, I'll implement support to print the process name in addition to
the pid, as this has also hit me, and it's never clear what was the
actual culprit. So that's why I'm leaving this assigned to dpkg, but
with a lower severity. If you'd like to file this elsewhere, then
please clone and reassign that.

It seems that the "dpkg frontend lock is locked by another process"
error almost always occurs with the same packages: either util-linux
or apt. See bugs

* 933335

Unpacking util-linux (2.34-0.1) over (2.33.1-0.1) ...
dpkg: error: dpkg frontend lock is locked by another process

Setting up apt (2.6.1) ...
dpkg: error: dpkg frontend lock was locked by another process with pid 4191235

* 940961

Unpacking apt (1.8.4) over (1.8.3) ...
dpkg: error: dpkg frontend lock is locked by another process

* 1069183

Setting up util-linux-extra (2.38.1-5+deb12u1) ...
dpkg: error: dpkg frontend lock was locked by another process with pid 1064194

* 1070027 (this bug)

Setting up util-linux (2.40-8) ...
fstrim.service is a disabled or a static unit not running, not starting it. dpkg: error: dpkg frontend lock was locked by another process with pid 58569

I'm wondering whether there could be a reason...

But there's also bug 1062190:

Unpacking locales (2.36-9+deb12u4) over (2.36-9+deb12u3) ...
dpkg: error: dpkg frontend lock was locked by another process with pid 567573

--
Vincent Lef�vre <[email protected]> - Web: <https://www.vinc17.net/>
100% accessible validated (X)HTML - Blog: <https://www.vinc17.net/blog/>
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)

--- SoupGate-Win32 v1.05
* Origin: you cannot sedate... all the things you hate (1:229/2)

XPost: linux.debian.bugs.dist
From: [email protected]

Hi!

On Mon, 2024-04-29 at 04:37:18 +0200, Vincent Lefevre wrote:

On 2024-04-29 03:05:50 +0200, Guillem Jover wrote:

I don't think dpkg is at fault here, I assume something else is either getting activated in the middle of the transaction while the package manager frontend driving dpkg has released the lock (which it should
not), or the package manager frontend driving dpkg is performing the locking dance incorrectly.

Isn't dpkg able to install/uninstall a set of packages in an atomic
way (where dpkg itself would set a lock at the beginning and release
the lock once every install/uninstall has been done, so that a lock
failure would not be possible in the middle of the installation)?

Sure, but that's not how apt-based frontends do it, as they call
dpkg multiples times over an upgrade process.

with fdisk.

I see no evidence of that in the log.

Right, it seems to me, like when dpkg fails due to the already held
lock, then the frontend is not recomputing the transaction and keeps
as if nothing had gone incorrectly, until it then notices later on.

Alternatively, if this is too complicated, it could abort and let
the user fix things (which is currently needed anyway).

I'd first focus on finding and fixing the part that is interfering
with the locking. But in any case that would be something for
apt-based frontends to handle.

In any case, given that dpkg is not being very helpful in diagnosing
this, I'll implement support to print the process name in addition to
the pid, as this has also hit me, and it's never clear what was the
actual culprit. So that's why I'm leaving this assigned to dpkg, but
with a lower severity. If you'd like to file this elsewhere, then
please clone and reassign that.

It seems that the "dpkg frontend lock is locked by another process"
error almost always occurs with the same packages: either util-linux
or apt. See bugs

* 933335

Unpacking util-linux (2.34-0.1) over (2.33.1-0.1) ...
dpkg: error: dpkg frontend lock is locked by another process

Setting up apt (2.6.1) ...
dpkg: error: dpkg frontend lock was locked by another process with pid 4191235

* 940961

Unpacking apt (1.8.4) over (1.8.3) ...
dpkg: error: dpkg frontend lock is locked by another process

* 1069183

Setting up util-linux-extra (2.38.1-5+deb12u1) ...
dpkg: error: dpkg frontend lock was locked by another process with pid 1064194

* 1070027 (this bug)

Setting up util-linux (2.40-8) ...
fstrim.service is a disabled or a static unit not running, not starting it. dpkg: error: dpkg frontend lock was locked by another process with pid 58569

I'm wondering whether there could be a reason...

But there's also bug 1062190:

Unpacking locales (2.36-9+deb12u4) over (2.36-9+deb12u3) ...
dpkg: error: dpkg frontend lock was locked by another process with pid 567573

Perhaps because these are Essential:yes (or apt considers them so),
and they are executed each as their own dpkg run.

I've been running now for a while with a modified dpkg with the improved reporting, which I'll be merging for the next release. And managed to get
the failure with the process name. I was running this this session with aptitude. I got this:

,---
[…]
(Reading database ... 343670 files and directories currently installed.) Preparing to unpack .../util-linux_2.40.1-7_amd64.deb ...
Unpacking util-linux (2.40.1-7) over (2.40.1-4) ...
Setting up util-linux (2.40.1-7) ...
fstrim.timer is a disabled or a static unit not running, not starting it. fstrim.service is a disabled or a static unit not running, not starting it. dpkg: error: dpkg frontend lock was locked by /usr/bin/apt-get process with pid 1310180
Note: removing the lock file is always wrong, can damage the locked area
and the entire system. See <https://wiki.debian.org/Teams/Dpkg/FAQ#db-lock>. dpkg: error: dpkg frontend lock was locked by /usr/bin/apt-get process with pid 1310180
Note: removing the lock file is always wrong, can damage the locked area
and the entire system. See <https://wiki.debian.org/Teams/Dpkg/FAQ#db-lock>. dpkg: error: dpkg frontend lock was locked by /usr/bin/apt-get process with pid 1310180
Note: removing the lock file is always wrong, can damage the locked area
and the entire system. See <https://wiki.debian.org/Teams/Dpkg/FAQ#db-lock>.
E: Sub-process /usr/bin/dpkg returned an error code (2)
E: Sub-process dpkg --set-selections returned an error code (2)
E: Couldn't revert dpkg selection for approved remove/purge after an error was encountered!
E: Sub-process dpkg --set-selections returned an error code (2)
E: Couldn't restore dpkg selection states which were present before this interaction!
dpkg: error: dpkg frontend lock was locked by /usr/bin/apt-get process with pid 1310180
Note: removing the lock file is always wrong, can damage the locked area
and the entire system. See <https://wiki.debian.org/Teams/Dpkg/FAQ#db-lock>. Press Return to continue, 'q' followed by Return to quit.
`---

Checking around I see that the systemd apt-daily.timer triggered at just
the same time, so that seems like the most likely culprit. So I guess it
makes sense for this report to be cloned and reassigned or so.

Regards,
Guillem

--- SoupGate-Win32 v1.05
* Origin: you cannot sedate... all the things you hate (1:229/2)

XPost: linux.debian.bugs.dist
From: [email protected]

Hi,

On 2024-06-03 00:38:01 +0200, Guillem Jover wrote:

Hi!

On Mon, 2024-04-29 at 04:37:18 +0200, Vincent Lefevre wrote:

On 2024-04-29 03:05:50 +0200, Guillem Jover wrote:

I don't think dpkg is at fault here, I assume something else is either getting activated in the middle of the transaction while the package manager frontend driving dpkg has released the lock (which it should not), or the package manager frontend driving dpkg is performing the locking dance incorrectly.

Isn't dpkg able to install/uninstall a set of packages in an atomic
way (where dpkg itself would set a lock at the beginning and release
the lock once every install/uninstall has been done, so that a lock
failure would not be possible in the middle of the installation)?

Sure, but that's not how apt-based frontends do it, as they call
dpkg multiples times over an upgrade process.

Why do they do that while it is possible to give dpkg several packages
to install (upgrade)?

And why doesn't the frontend log the different calls in/var/log/apt/history.log?

I'm talking specifically about

https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1070027#19

Checking around I see that the systemd apt-daily.timer triggered at just
the same time, so that seems like the most likely culprit. So I guess it makes sense for this report to be cloned and reassigned or so.

Hmm... That was also the case for me. Let's recall:

Start-Date: 2024-04-28 22:05:30
[...]
Error: Sub-process /usr/bin/dpkg returned an error code (2)
End-Date: 2024-04-28 22:05:34

and in the journalctl output at this time:

Apr 28 22:05:33 disset systemd[1]: Reloading requested from client PID 58469 ('systemctl') (unit session-796.scope)...
Apr 28 22:05:33 disset systemd[1]: Reloading...
Apr 28 22:05:34 disset systemd[1]: Reloading finished in 102 ms.
Apr 28 22:05:34 disset systemd[1]: Starting apt-daily.service - Daily apt download activities...
Apr 28 22:05:34 disset systemd[1]: fstrim.timer: Deactivated successfully.
Apr 28 22:05:34 disset systemd[1]: Stopped fstrim.timer - Discard unused filesystem blocks once a week.
Apr 28 22:05:34 disset systemd[1]: Stopping fstrim.timer - Discard unused filesystem blocks once a week...
Apr 28 22:05:34 disset systemd[1]: Started fstrim.timer - Discard unused filesystem blocks once a week.
Apr 28 22:05:34 disset systemd[1]: Reloading requested from client PID 58516 ('systemctl') (unit session-796.scope)...
Apr 28 22:05:34 disset systemd[1]: Reloading...
Apr 28 22:05:34 disset systemd[1]: Reloading finished in 110 ms.
Apr 28 22:05:34 disset systemd[1]: apt-daily.service: Deactivated successfully. Apr 28 22:05:34 disset systemd[1]: Finished apt-daily.service - Daily apt download activities.

But I've never requested a reloading at this time!
So there's something broken related to systemd.

--
Vincent Lef�vre <[email protected]> - Web: <https://www.vinc17.net/>
100% accessible validated (X)HTML - Blog: <https://www.vinc17.net/blog/>
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)

--- SoupGate-Win32 v1.05
* Origin: you cannot sedate... all the things you hate (1:229/2)