CI tests fail in testing-farm because advisory time stamps are printed with subsecond resolution

[ppisar]

Some tests started to fail https://artifacts.dev.testing-farm.io/e6610d2f-b1e5-40b5-97d6-173d74dd3f80/work-behave-dnf531egve3a/plans/integration/behave-dnf5/execute/data/guest/default-0/script-00-1/output.txt like this:

  Scenario: use both advisories even if they are duplicates but with different issued and updated dates (from one repo)  # dnf/security-upgrade.feature:328
    Given I use repository "security-upgrade-duplicates-1"                                                               # dnf/steps/repo.py:182
    When I execute dnf with args "install E-1-1"                                                                         # dnf/steps/cmd.py:110
    Then the exit code is 0                                                                                              # common/output.py:60
    Then Transaction is following                                                                                        # dnf/steps/transaction.py:200
      | Action  | Package        |
      | install | E-0:1-1.x86_64 |
    When I execute dnf with args "updateinfo list"                                                                       # dnf/steps/cmd.py:110
    Then dnf5 stdout is                                                                                                  # common/output.py:177
      """
      <REPOSYNC>
      Name      Type     Severity      Package              Issued
      custom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00
      custom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00
      """
      Assertion Failed: Stdout is not: <REPOSYNC>
      Name      Type     Severity      Package              Issued
      custom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00
      custom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00
      Captured stdout:
      expected                                                      |  found
      �[31m�[1mName      Type     Severity      Package              Issued  |  Name      Type     Severity      Package                        Issued�[0m
      �[31m�[1mcustom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00  |  custom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00.000000000�[0m
      �[31m�[1mcustom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00  |  custom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00.000000000�[0m
      �[31m
      Last Command: �[31m�[1mdnf5 -y --installroot=/tmp/dnf_ci_installroot_o11k264y --releasever=29 --setopt=module_platform_id=platform:f29 --setopt=reposdir=/tmp/dnf_ci_installroot_o11k264y/etc/yum.repos.d --setopt=config_file_path=/tmp/dnf_ci_installroot_o11k264y/etc/dnf/dnf.conf --setopt=cachedir=/tmp/dnf_ci_installroot_o11k264y/var/cache/dnf updateinfo list
      �[36m�[1m
      Last Command stdout:�[90m
      Updating and loading repositories:
      Repositories loaded.
      Name      Type     Severity      Package                        Issued
      custom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00.000000000
      custom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00.000000000
      �[0m

    Then dnf4 stdout is                                                                                                  # None
      """
      <REPOSYNC>
      custom_id Moderate/Sec. E-2-2.x86_64
      """
    When I execute dnf with args "upgrade --security"                                                                    # None
    Then the exit code is 0                                                                                              # None
    Then Transaction is following                                                                                        # None
      | Action  | Package        |
      | upgrade | E-0:2-2.x86_64 |
[...]
Failing scenarios:
  dnf/security-upgrade.feature:328  use both advisories even if they are duplicates but with different issued and updated dates (from one repo)
  dnf/security-upgrade.feature:360  use all (3) advisories even if they are duplicates but with different issued and updated dates (from diff repos)
  dnf/security-upgrade.feature:392  use both advisories even if they are duplicates but with just summary different (from diff repos)
[...]
Failing scenarios:
  dnf/updateinfo.feature:10  Listing available updates
  dnf/updateinfo.feature:106  advisory info
  dnf/updateinfo.feature:223  advisory list
  dnf/updateinfo.feature:260  advisory list all security
  dnf/updateinfo.feature:276  advisory list updates
  dnf/updateinfo.feature:295  advisory list installed
  dnf/updateinfo.feature:313  advisory list available enhancement
  dnf/updateinfo.feature:330  advisory list all bugfix
  dnf/updateinfo.feature:360  advisory list updates plus --bzs -- @1.1 
  dnf/updateinfo.feature:361  advisory list updates plus --cves -- @1.2 
  dnf/updateinfo.feature:362  advisory list updates plus --cves -- @1.3 
  dnf/updateinfo.feature:363  advisory list updates plus  -- @1.4 
  dnf/updateinfo.feature:381  advisory info <advisory>
  dnf/updateinfo.feature:421  advisory info <advisory-with-respin-suffix>
  dnf/updateinfo.feature:451  advisory lists advisories referencing CVE
  dnf/updateinfo.feature:488  advisory lists advisories referencing bugzilla
  dnf/updateinfo.feature:522  advisory show <advisory> of the running kernel after a kernel update
  dnf/updateinfo.feature:688  advisory lists advisories referencing CVE with dates
  dnf/updateinfo.feature:703  advisory lists advisories with custom type and severity
  dnf/updateinfo.feature:721  advisory prints info for advisories with custom type and severity
  dnf/updateinfo.feature:909  advisory list --contains-pkgs doesn't list other packages (including running kernel)
[...]
Error: Failed test(s):
dnf/security-upgrade.feature
dnf/updateinfo.feature

The cause is that an advisory issue time is now printed with a subsecond precision:

# dnf5 updateinfo list
Updating and loading repositories:
Repositories loaded.
Name                   Type        Severity                                    Package                        Issued
FEDORA-2023-0035d68f2d unspecified None            glibc-debuginfo-2.38-10.fc39.x86_64 2023-11-06 01:29:36.000000000

But the tests expect an integer seconds value.

Is it a bug, or a feature? Should we fix the code or the tests?

[j-mracek]

I am thinking that we should fix the code. From my point of view, custom_id security Moderate E-2-2.x86_64 2022-12-17 00:00:00 looks better then the second option.

[kontura]

Given that the precision was originally only in full seconds and this issue was caused by a change in fmt I made a PR to remove the sub-seconds.