Description of problem: I've noticed that in F31 dnf ignores the metadata-expire limit in the configuration file /etc/dnf/dnf.conf. I have it set as metadata_expire=72000 yet whenever I run any dnf command, it automatically updates the repo information, even if it ran just 5 minutes before. Version-Release number of selected component (if applicable): Version : 4.2.7 Release : 3.fc31 Architecture: noarch How reproducible: Every time. Steps to Reproduce: 1. Set metadata-expire to large number. 2. Do update or install of package. 3. Wait 5 minutes, and do another install or update. Actual results: Repo data is updated with each command. Expected results: Repo data is not updated until the metadata-expire limit is passed, unless specifically requested. Additional info: I don't do updates more frequently than once a day very often, so I'm not sure how long this has been happening. The repo data updates can take minutes to complete during busy internet times, so it is annoying.
It seems to work for me, there are however couple of options. First: configurations in .repo files in /etc/yum.repos.d/ actually override those in /etc/dnf/dnf.conf. Its possible some of the repositories you are using have different metadata_expire value overridden there. And second: we had a bug recently (bz1722493) that caused options followed by a blank line with white spaces on it to be buggy, this could also be causing your problem. Does any of this help?
The shortest repo expiry is 6 hours, so that wouldn't have affected this, though there are several repos with no expiry. And there are no blank lines in the dnf.conf file. I just ran an update that updated several packages, waited a few minutes, and tried to update one of the skipped packages. It ran the check on the repos even though the metadata was only a few minutes old. However, when I tried it again with the same command, it *didn't* rerun the check on the repos. And, trying just an update also skipped the check on the repos. Maybe it only happens the first time? I'll keep an eye out, maybe try in an hour to see if that affects it. I've also turned off the modular repos, because when I ran a reset on libgit2 after reading a message on the devel list, it suddenly wanted to install a bunch of modules. I'm holding off on creating a hybrid system until I'm more confident that there aren't issues that haven't been discovered yet; I'm not convinced that modules aren't a long term security hole and don't have combinatorial issues. But that has nothing to do with this problem, except that turning off modules repos might have changed the code path through dnf, and thus changed the character of the problem I'm seeing. If you aren't experiencing this, and neither or others, it could be an obscure corner case somehow triggered by my system configuration. Hardly worth spending the time to pursue, when there are bigger fish to fry. It is only an irritation, and doesn't affect the correct functioning of dnf in its primary purpose.
Yes, but I would still like to figure this out. If possible could you provide the /var/log/dnf.log? Also reliable reproducer for example in a container would be ideal of course but I understand if you don't want to spend that much time on this.
I tried to reproduce it today, and it didn't have the problem when I tried to perform an update of one of the skipped packages. Instead I've attached the output from the dnf logs for the transaction in comment 2 where I did have the problem, and then didn't. The command at line 2645 trying to update pulseaudio is the command that reloaded the metadata though it was just a few minutes old. The command at line 2700 trying to update ghc is the command that didn't exhibit the problem.
Created attachment 1618689 [details] This is the dnf log info for comment 4. An update, then an attempt to update a package that pulls the metadata again just a few minutes later, then an attempt to update a package that doesn't pull the metadata just a few minutes after that.
I forgot to comment about the reliable reproducer in a container. I couldn't reproduce it originally, but I just tried the command again and it pulled the repodata again. Here is the log of the two attempts. I left one line from the system update to show the time difference (the first line). So, the first update of gnome-do (17:22) doesn't get the metadata, but the second (18:13) does. I'm not sure why dnf is still checking fedora-updates-modular.repo, since it is disabled. 2019-09-24T17:19:06Z DDEBUG Cleaning up. 2019-09-24T17:22:19Z INFO --- logging initialized --- 2019-09-24T17:22:19Z DDEBUG timer: config: 2 ms 2019-09-24T17:22:19Z DEBUG Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, sys tem-upgrade 2019-09-24T17:22:19Z DEBUG DNF version: 4.2.9 2019-09-24T17:22:19Z DDEBUG Command: dnf update gnome-do 2019-09-24T17:22:19Z DDEBUG Installroot: / 2019-09-24T17:22:19Z DDEBUG Releasever: 31 2019-09-24T17:22:19Z DEBUG cachedir: /var/cache/dnf 2019-09-24T17:22:19Z DDEBUG Base command: update 2019-09-24T17:22:19Z DDEBUG Extra commands: ['update', 'gnome-do'] 2019-09-24T17:22:19Z DEBUG Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist 2019-09-24T17:22:19Z DEBUG Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist 2019-09-24T17:22:19Z DEBUG Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist 2019-09-24T17:22:22Z DEBUG repo: using cache for: updates-testing 2019-09-24T17:22:22Z DEBUG updates-testing: using metadata from Mon 23 Sep 2019 05:39:09 PM MST. 2019-09-24T17:22:22Z DEBUG repo: using cache for: updates 2019-09-24T17:22:22Z DEBUG updates: using metadata from Tue 20 Feb 2018 12:18:14 PM MST. 2019-09-24T17:22:23Z DEBUG repo: using cache for: fedora 2019-09-24T17:22:23Z DEBUG fedora: using metadata from Mon 23 Sep 2019 02:11:33 AM MST. 2019-09-24T17:22:23Z DEBUG repo: using cache for: rpmfusion-free-updates-testing 2019-09-24T17:22:23Z DEBUG rpmfusion-free-updates-testing: using metadata from Mon 23 Sep 2019 04:42:43 AM MST. 2019-09-24T17:22:23Z DEBUG repo: using cache for: rpmfusion-free 2019-09-24T17:22:23Z DEBUG rpmfusion-free: using metadata from Mon 23 Sep 2019 04:56:04 AM MST. 2019-09-24T17:22:23Z DEBUG repo: using cache for: rpmfusion-nonfree-updates-testing 2019-09-24T17:22:23Z DEBUG rpmfusion-nonfree-updates-testing: using metadata from Mon 23 Sep 2019 05:15:42 AM MST. 2019-09-24T17:22:23Z DEBUG repo: using cache for: rpmfusion-nonfree 2019-09-24T17:22:23Z DEBUG rpmfusion-nonfree: using metadata from Mon 23 Sep 2019 05:22:37 AM MST. 2019-09-24T17:22:23Z INFO Last metadata expiration check: 0:10:40 ago on Tue 24 Sep 2019 10:11:43 AM MST. 2019-09-24T17:22:23Z DEBUG No module defaults found 2019-09-24T17:22:23Z DDEBUG timer: sack setup: 4442 ms 2019-09-24T17:22:23Z DEBUG Completion plugin: Generating completion cache... 2019-09-24T17:22:24Z DEBUG --> Starting dependency resolution 2019-09-24T17:22:25Z DEBUG --> Finished dependency resolution 2019-09-24T17:22:25Z DDEBUG timer: depsolve: 865 ms 2019-09-24T17:22:25Z INFO Dependencies resolved. 2019-09-24T17:22:25Z INFO Nothing to do. 2019-09-24T17:22:25Z INFO Complete! 2019-09-24T17:22:25Z DDEBUG Cleaning up. 2019-09-24T18:08:29Z INFO --- logging initialized --- 2019-09-24T18:08:29Z DDEBUG timer: config: 4 ms 2019-09-24T18:08:29Z DEBUG Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2019-09-24T18:08:29Z DEBUG DNF version: 4.2.9 2019-09-24T18:08:29Z DDEBUG Command: dnf makecache --timer 2019-09-24T18:08:29Z DDEBUG Installroot: / 2019-09-24T18:08:29Z DDEBUG Releasever: 31 2019-09-24T18:08:29Z DEBUG cachedir: /var/cache/dnf 2019-09-24T18:08:29Z DDEBUG Base command: makecache 2019-09-24T18:08:29Z DDEBUG Extra commands: ['makecache', '--timer'] 2019-09-24T18:08:29Z DEBUG Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist 2019-09-24T18:08:29Z DEBUG Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist 2019-09-24T18:08:29Z DEBUG Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist 2019-09-24T18:08:29Z DEBUG Making cache files for all metadata files. 2019-09-24T18:08:29Z INFO Metadata timer caching disabled. 2019-09-24T18:08:29Z DDEBUG Cleaning up. 2019-09-24T18:13:07Z INFO --- logging initialized --- 2019-09-24T18:13:07Z DDEBUG timer: config: 234 ms 2019-09-24T18:13:07Z DEBUG Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2019-09-24T18:13:07Z DEBUG DNF version: 4.2.9 2019-09-24T18:13:07Z DDEBUG Command: dnf update gnome-do 2019-09-24T18:13:07Z DDEBUG Installroot: / 2019-09-24T18:13:07Z DDEBUG Releasever: 31 2019-09-24T18:13:07Z DEBUG cachedir: /var/cache/dnf 2019-09-24T18:13:07Z DDEBUG Base command: update 2019-09-24T18:13:07Z DDEBUG Extra commands: ['update', 'gnome-do'] 2019-09-24T18:13:07Z DEBUG Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist 2019-09-24T18:13:07Z DEBUG Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist 2019-09-24T18:13:07Z DEBUG Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist 2019-09-24T18:13:12Z DEBUG reviving: 'updates-testing' can be revived - metalink checksums match. 2019-09-24T18:13:12Z DEBUG updates-testing: using metadata from Mon 23 Sep 2019 05:39:09 PM MST. 2019-09-24T18:13:13Z DEBUG reviving: 'updates' can be revived - metalink checksums match. 2019-09-24T18:13:13Z DEBUG updates: using metadata from Tue 20 Feb 2018 12:18:14 PM MST. 2019-09-24T18:13:14Z DEBUG reviving: 'fedora' can be revived - metalink checksums match. 2019-09-24T18:13:15Z DEBUG fedora: using metadata from Mon 23 Sep 2019 02:11:33 AM MST. 2019-09-24T18:13:16Z DEBUG reviving: 'rpmfusion-free-updates-testing' can be revived - metalink checksums match. 2019-09-24T18:13:16Z DEBUG rpmfusion-free-updates-testing: using metadata from Mon 23 Sep 2019 04:42:43 AM MST. 2019-09-24T18:13:16Z DEBUG reviving: 'rpmfusion-free' can be revived - metalink checksums match. 2019-09-24T18:13:16Z DEBUG rpmfusion-free: using metadata from Mon 23 Sep 2019 04:56:04 AM MST. 2019-09-24T18:13:17Z DEBUG reviving: 'rpmfusion-nonfree-updates-testing' can be revived - metalink checksums match. 2019-09-24T18:13:17Z DEBUG rpmfusion-nonfree-updates-testing: using metadata from Mon 23 Sep 2019 05:15:42 AM MST. 2019-09-24T18:13:18Z DEBUG reviving: 'rpmfusion-nonfree' can be revived - metalink checksums match. 2019-09-24T18:13:18Z DEBUG rpmfusion-nonfree: using metadata from Mon 23 Sep 2019 05:22:37 AM MST. 2019-09-24T18:13:18Z DEBUG No module defaults found 2019-09-24T18:13:18Z DDEBUG timer: sack setup: 11142 ms 2019-09-24T18:13:18Z DEBUG Completion plugin: Generating completion cache... 2019-09-24T18:13:19Z DEBUG --> Starting dependency resolution 2019-09-24T18:13:20Z DEBUG --> Finished dependency resolution 2019-09-24T18:13:20Z DDEBUG timer: depsolve: 1021 ms 2019-09-24T18:13:20Z INFO Dependencies resolved. 2019-09-24T18:13:20Z INFO Nothing to do. 2019-09-24T18:13:20Z INFO Complete! 2019-09-24T18:13:20Z DDEBUG Cleaning up.
I see that there is something about makecache --timer in the logs. But, I have that disabled in /etc/dnf/dnf.conf. metadata_timer_sync=0 From man dnf.conf metadata_timer_sync time in seconds The minimal period between two consecutive makecache timer runs. The command will stop immediately if it's less than this time period since its last run. Does not affect simple makecache run. Use 0 to completely disβ able automatic metadata synchronizing. The default corresponds to three hours. The value is rounded to the next commenced hour.
I was able to find the bug thanks to the logs you provided. If a command (such as the disabled makecache --timer) didn't load repository caches it expired all repos. PR: https://github.com/rpm-software-management/dnf/pull/1493 test: https://github.com/rpm-software-management/ci-dnf-stack/pull/645
That's great! Thanks a lot.
FEDORA-2019-7cafbe66ba has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-7cafbe66ba
FEDORA-2019-94393775ec has been submitted as an update to Fedora 31. https://bodhi.fedoraproject.org/updates/FEDORA-2019-94393775ec
dnf-4.2.15-1.fc30, dnf-plugins-core-4.0.11-1.fc30, dnf-plugins-extras-4.0.8-1.fc30, libdnf-0.37.2-2.fc30, librepo-1.11.0-1.fc30, microdnf-3.0.2-1.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-7cafbe66ba
dnf-4.2.15-1.fc31, dnf-plugins-core-4.0.11-1.fc31, dnf-plugins-extras-4.0.8-1.fc31, libdnf-0.37.2-2.fc31, librepo-1.11.0-1.fc31, microdnf-3.0.2-1.fc31 has been pushed to the Fedora 31 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-94393775ec
dnf-4.2.15-3.fc30, dnf-plugins-core-4.0.11-1.fc30, dnf-plugins-extras-4.0.8-1.fc30, libdnf-0.37.2-2.fc30, librepo-1.11.0-1.fc30, microdnf-3.0.2-1.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-7cafbe66ba
dnf-4.2.15-2.fc31, dnf-plugins-core-4.0.11-1.fc31, dnf-plugins-extras-4.0.8-1.fc31, libdnf-0.37.2-2.fc31, librepo-1.11.0-1.fc31, microdnf-3.0.2-1.fc31 has been pushed to the Fedora 31 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-94393775ec
dnf-4.2.15-2.fc31, dnf-plugins-core-4.0.11-1.fc31, dnf-plugins-extras-4.0.8-1.fc31, libdnf-0.37.2-2.fc31, librepo-1.11.0-1.fc31, microdnf-3.0.2-1.fc31 has been pushed to the Fedora 31 stable repository. If problems still persist, please make note of it in this bug report.
dnf-4.2.15-3.fc30, dnf-plugins-core-4.0.11-1.fc30, dnf-plugins-extras-4.0.8-1.fc30, libdnf-0.37.2-2.fc30, librepo-1.11.0-1.fc30, microdnf-3.0.2-1.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.