Bug 2383375 - etckeeper-dnf5 slows down all dnf commands
Summary: etckeeper-dnf5 slows down all dnf commands
Keywords:
Status: NEW
Alias: None
Product: Fedora
Classification: Fedora
Component: etckeeper
Version: 42
Hardware: noarch
OS: Linux
unspecified
low
Target Milestone: ---
Assignee: Thomas Moschny
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2025-07-25 12:51 UTC by vywunm0jfimu
Modified: 2025-07-30 12:43 UTC (History)
3 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed:
Type: ---
Embargoed:


Attachments (Terms of Use)

Description vywunm0jfimu 2025-07-25 12:51:34 UTC
With etckeeper-dnf5 enabled etckeeper is triggered for each dnf command-line causing significant delay (in particular for scripts iterating over dnf meta data). 

It should be triggered only for dnf transactions which may apply changes to system configs (i.e. install, upgrade and remove packages or change repo configs).

Furthermore error messages are emitted if dnf is called by non-root users (because missing permission for etckeeper cache).

Reproducible: Always

Steps to Reproduce:

1. etckeeper-dnf5 enabled:
$ sed -i 's/^#p/p/' /etc/dnf/libdnf5-plugins/actions.d/etckeeper.actions
$ time dnf history list >/dev/null

2. etckeeper-dnf5 disabled:
$ sed -i 's/^p/#p/' /etc/dnf/libdnf5-plugins/actions.d/etckeeper.actions
$ time dnf history list >/dev/null

Actual Results:

- etckeeper-dnf5 enabled: 

$ time dnf history list >/dev/null

real	0m1,787s
user	0m1,694s
sys	0m0,102s

- etckeeper-dnf5 enabled, etckeeper triggers garbage collection for worktree repo:

$ time dnf history list >/dev/null
Enumerating objects: 5, done.
Counting objects: 100% (5/5), done.
Delta compression using up to 6 threads
Compressing objects: 100% (3/3), done.
Writing objects: 100% (3/3), 603 bytes | 603.00 KiB/s, done.
Total 3 (delta 2), reused 0 (delta 0), pack-reused 0 (from 0)
To /home/git/etckeeper
   01df0dee..21d797d4  f42 -> f42

real	0m5,443s
user	0m5,097s
sys	0m0,405s

- etckeeper-dnf5 enabled, non-root user:

$ time dnf history list>/dev/null
/etc/etckeeper/pre-install.d/10packagelist: line 4: /var/cache/etckeeper/packagelist.pre-install: Permission denied
/etc/etckeeper/pre-install.d/10packagelist: line 5: /var/cache/etckeeper/packagelist.fmt: Permission denied

real	0m0,060s
user	0m0,038s
sys	0m0,023s


Expected Results:

- etckeeper-dnf5 disabled:
 
$ time dnf history list >/dev/null
real	0m0,058s
user	0m0,031s
sys	0m0,015s


Additional Information:

Work-around is to disable the dnf plugin:

$ sed -i 's/^p/#p/' /etc/dnf/libdnf5-plugins/actions.d/etckeeper.actions

Comment 1 Martin B. 2025-07-27 12:19:03 UTC
Maybe this can be addressed by selecting a better dnf5 hook for pre-install as I note here: https://bugzilla.redhat.com/show_bug.cgi?id=2326283#c19?

Comment 2 vywunm0jfimu 2025-07-27 15:02:23 UTC
The culprit seems to the "pre_base_setup" callback in "etckeeper.actions". If the callback name is changed to "pre_transaction" then the unwanted 
delay was no longer observed abd etckeeper commits changes below /etc before/after transaction (however with a strange subject line):

$ dnf remove -y fedora-repos-archive-42
...
Running transaction
[1/2] Prepare transaction                                                                               100% |   2.0   B/s |   1.0   B |  00m00s
[2/2] Removing fedora-repos-archive-0:42-1.noarch                                  100% [==================] |   0.0   B/s |   1.0   B |  00m00s
error: file /etc/yum.repos.d/fedora-updates-archive.repo: No such file or directory
[2/2] Removing fedora-repos-archive-0:42-1.noarch                                                       100% |   0.0   B/s |   1.0   B |  00m06s
Complete!

$ git log -1
commit 834c6f20c4855e5fdc5eef4ec17828e609502f5e (HEAD -> f42)
Author: root <root@redacted>
Date:   Sun Jul 27 16:33:41 2025 +0200

    committing changes in /etc made by "/usr/bin/sh -c /usr/bin/etckeeper post-install | /usr/bin/sed -e 's/^/log.INFO=/'"
    
    Package changes:
    -0:fedora-repos-archive-42-1.noarch

$ dnf install -y fedora-repos-archive-42
...
Running transaction
1/3] Verify package files                                                                               100% | 333.0   B/s |   1.0   B |  00m00s
[2/3] Prepare transaction                                                                               100% |   2.0   B/s |   1.0   B |  00m00s
[3/3] Installing fedora-repos-archive-0:42-1.noarch                                100% [==================] |   0.0   B/s |   1.2 KiB |  00m00s
[3/3] Installing fedora-repos-archive-0:42-1.noarch                                                     100% | 167.0   B/s |   1.2 KiB |  00m08s
Complete!

$ git log -1
commit 287013724bb75c892c8f20a8b21e7605f4b91f50 (HEAD -> leo_f42, origin/leo_f42)
Author: root <root@redacted>
Date:   Sun Jul 27 16:48:52 2025 +0200

    committing changes in /etc made by "/usr/bin/sh -c /usr/bin/etckeeper post-install | /usr/bin/sed -e 's/^/log.INFO=/'"
    
    Package changes:
    +0:fedora-repos-archive-42-1.noarch

Comment 3 vywunm0jfimu 2025-07-27 15:09:44 UTC
BTW: In the RPM spec /etc/dnf/libdnf5-plugins/actions.d/etckeeper.actions should be flagged as config file.

Comment 4 vywunm0jfimu 2025-07-28 12:01:42 UTC
The capture of the dnf command-line in "etckeeper/post-install.d/50vcs-commit" no longer works because the bash process 
created by the "post_action" command is now the etckeeper parent process. Following diff contains a fix for this:

$ git diff 21d797d405fde157bed3231be6015768fdbf330b -- dnf/ etckeeper/
diff --git a/dnf/libdnf5-plugins/actions.d/etckeeper.actions b/dnf/libdnf5-plugins/actions.d/etckeeper.actions
index f654e216..c22cfadd 100644
--- a/dnf/libdnf5-plugins/actions.d/etckeeper.actions
+++ b/dnf/libdnf5-plugins/actions.d/etckeeper.actions
@@ -1,4 +1,4 @@
 # to be placed in /etc/dnf/libdnf5-plugins/actions.d
 # requires dnf5 5.2.11.0 or later
-pre_base_setup:::raise_error=1:/usr/bin/sh -c /usr/bin/etckeeper\ pre-install\ \|\ /usr/bin/sed\ -e\ 's/^/log.INFO=/'
-post_transaction::::/usr/bin/sh -c /usr/bin/etckeeper\ post-install\ \|\ /usr/bin/sed\ -e\ 's/^/log.INFO=/'
+pre_transaction:::raise_error=1:/usr/bin/sh -c /usr/bin/etckeeper\ pre-install\ \|\ /usr/bin/sed\ -e\ 's/^/log.INFO=/'
+post_transaction::::/usr/bin/sh -c DNF_PID=${pid}\ /usr/bin/etckeeper\ post-install\ \|\ /usr/bin/sed\ -e\ 's/^/log.INFO=/'
diff --git a/etckeeper/post-install.d/50vcs-commit b/etckeeper/post-install.d/50vcs-commit
index 40cb12ae..b06efba3 100755
--- a/etckeeper/post-install.d/50vcs-commit
+++ b/etckeeper/post-install.d/50vcs-commit
@@ -10,8 +10,12 @@ ETCKEEPER_PID=$( ps --no-headers -o ppid "$$" 2>/dev/null | sed 's/^ *//' )
 
 # Find the parent of etckeeper and get the command line of the process
 if ! [ -z "${ETCKEEPER_PID}" ]; then
-       ETCKEEPER_PPID=$( ps --no-headers -o ppid "${ETCKEEPER_PID}" | sed 's/^ *//' )
-       ETCKEEPER_PARENT_COMMAND_LINE=$( ps --no-headers -o args "${ETCKEEPER_PPID}" )
+       if [ -n "$DNF_PID" ] ; then
+               ETCKEEPER_PPID=$DNF_PID
+       else
+               ETCKEEPER_PPID=$( ps --no-headers -o ppid "${ETCKEEPER_PID}" | sed 's/^ *//' )
+       fi
+       ETCKEEPER_PARENT_COMMAND_LINE=$( ps --no-headers -o args "${ETCKEEPER_PPID}" )
 fi
 
 get_changes () {

Test:

$ dnf install -y fedora-repos-archive-42
...
[1/1] Total                                                                                                                                                                                                           100% |   0.0   B/s |   0.0   B |  00m00s
Running transaction
[1/3] Verify package files                                                                                                                                                                                            100% | 500.0   B/s |   1.0   B |  00m00s
[2/3] Prepare transaction                                                                                                                                                                                             100% |   2.0   B/s |   1.0   B |  00m00s
[3/3] Installing fedora-repos-archive-0:42-1.noarch                                                                                                                                                                   100% | 167.0   B/s |   1.2 KiB |  00m08s
Complete!

$ git log -1
commit e05886377141ca11f15191ffc80bb381e0d6dd1a (HEAD -> f42)
Author: root <root@redacted>
Date:   Mon Jul 28 13:33:32 2025 +0200

    committing changes in /etc made by "dnf install -y fedora-repos-archive-42"
    
    Package changes:
    +0:fedora-repos-archive-42-1.noarch

Comment 5 vywunm0jfimu 2025-07-30 12:37:09 UTC
To avoid commit subjects exceeding usual line length limits following statement may be inserted after "ETCKEEPER_PARENT_COMMAND_LINE=.."

[ ${#ETCKEEPER_PARENT_COMMAND_LINE} -le 75 ] || ETCKEEPER_PARENT_COMMAND_LINE="${ETCKEEPER_PARENT_COMMAND_LINE:0:72} .."


Note You need to log in before you can comment on or make changes to this bug.