dnf needs-restarting reports a service restart is needed even if it was already restarted in the package %post script

[RomanSoloweow]

Problem description
The dnf needs-restarting command reports that some services need a restart even if they were already restarted in the package %post script.

The reason is that needs-restarting compares the package installtime with the service process boot_time. If installtime > boot_time, the service is marked as outdated. However, in cases where the %post script explicitly starts or restarts the service, the process boot_time is still older than the installtime, which causes a false positive.

Relevant code snippet (from needs-restarting.py):

if self.opts.reboothint:
    need_reboot = set()
    installed = self.base.sack.query().installed()
    for pkg in installed.filter(provides=NEED_REBOOT):
        if pkg.installtime > process_start.boot_time:
            need_reboot.add(pkg.name)

[RomanSoloweow]

cc @kontura @ppisar

[m-blaha]

The issue is certainly valid. The logic behind printing the reboot hint is rather simplistic. It only checks the installation times of the configured list of packages and compares them to the system boot time.
Would tracer provide better results for you?

[ppisar]

The code you quoted is about packages which request a reboot. Therefore the boot time is compared, not execution time.

Did you execute need-restarting with --reboothint option?

[ppisar]

Could you give us an example of what package upgrade and what needs-restaring invocation exhibits the unwanted behavior? The code handles differently systemd services and other processes and accounts for their execution time. And I don't see it should not work.

The only what comes to my mind is that RPM would record an installation time after finishing the %post script, making the installation time younger than the execution time.

[m-blaha]

According to my experiment (didn't investigate rpm sources) the installation time is recorded before the post script execution.

[RomanSoloweow]

It looks like the timestamp is written to the database before the %post script is executed:
https://github.com/rpm-software-management/rpm/blob/ba9ac3c8af097f94d7859731b1acb8e0fcf37a55/lib/psm.cc#L889

if (!(rpmtsFlags(ts) & RPMTRANS_FLAG_NODB)) {
    // ...
    rc = dbAdd(ts, psm->te);
    if (rc) break;
}
// ...
if (!(rpmtsFlags(ts) & RPMTRANS_FLAG_NOPOST)) {
    rc = runInstScript(psm, RPMTAG_POSTIN);
    if (rc) break;
}

However, the timestamp written into the database is taken from a library call to time():
https://github.com/rpm-software-management/rpm/blob/ba9ac3c8af097f94d7859731b1acb8e0fcf37a55/lib/psm.cc#L728C30-L728C42
https://github.com/rpm-software-management/rpm/blob/ba9ac3c8af097f94d7859731b1acb8e0fcf37a55/lib/rpmts.cc#L1015

rpm_time_t rpmtsGetTime(rpmts ts, time_t step)
{
    time_t tstime;
    if (ts->overrideTime == (time_t)-1) {
        tstime = time(NULL);
    } else {
        tstime = ts->overrideTime;
        ts->overrideTime += step;
    }
    return (rpm_time_t)tstime;
}

So the database gets the current wall clock time (REALTIME) with one-second resolution.

But the process start time is calculated differently: it’s measured as kernel boot time + ticks since process start:

dnf-plugins-core/plugins/needs_restarting.py

Line 294 in 1f5d725

def __call__(self, pid):

def __call__(self, pid):
    stat_fn = '/proc/%d/stat' % pid
    with open(stat_fn) as stat_file:
        stats = stat_file.read().split()
    ticks_after_kernel_boot = int(stats[21])
    secs_after_kernel_boot = ticks_after_kernel_boot / self.sc_clk_tck
    # The process's start time is always measured relative to the kernel
    # start time, not either of the other methods we use to get "boot time".
    return self.kernel_boot_time + secs_after_kernel_boot

This mismatch can lead to situations where, if a process starts immediately inside a %post script, its start time appears earlier than the package installation time.

Here’s a Bash script that reproduces the issue:

#!/bin/bash
i=0
while true; do
    printf "Iter %3d\n" $(( ++i ))
    date +%s    # emulate db time
    sleep 2 &   # emulate service start
    p=$!
    PYTHONPATH="/usr/lib/python3.9/site-packages/dnf-plugins"         python3 -c 'print(__import__("needs_restarting").ProcessStart()('"$p"'))'
    wait "$p" || :
done

Sometimes it fails on the very first iteration, sometimes after 100–200 iterations:

Iter   1
1756739445
1756739444.71
Iter   2
1756739447
1756739446.72
Iter   3

[ppisar]

Thanks for the analysis. Yes, there is this rounding error. time(7) documents "accuracy to the nearest second".

Yet arithmetical rounding the ProcessStart()($PID) value won't help because I can observe these values from your script:

Iter   1
1756898592
1756898591.24
Iter   2
1756898594
1756898593.25

ProcessStart() value is a sum of a boot time and a relative start of the process:

Iter   1
1756899185
self.kernel_boot_time=1756883995.0 + secs_after_kernel_boot=15189.48
1756899184.48

That a process can start at non-whole second is natural. So I believe the boot time is a fake. That value comes from btime in /proc/stat. I guess that value is already rounded, and the rounding error accumulates.

I worry there is nothing dnf-plugins-core can do to mitigate this issue.

I'm not persuaded thar lowering granularity of the comparison, e.g. to 2 seconds would be beneficial. You would only have more false reports in absolute numbers.

[ppisar]

I opened an enhancement request to RPM for storing installation time in subsecond resolution rpm-software-management/rpm#3934. I don't have high hopes in RPM implementing it any soon. Even so, the value travels from RPM via libsolv, via libdnf, to needs-restarting. All the layers have the second precision in their API.

Regarding needs-restarting side, current algorithm is:

if pkg.installtime <= process_start(pid):
              do not report it
else:
              report it

The most correct algorithm should look like this (where round() rounds to the more gross granularity of the two timers):

if round(pkg.installtime) < round(process_start(pid)):
             do not report it
else round(pkg.installtime) == round(process_start(pid)):
             inconclusive, warn
else:
             report it