Bug 2035662

During subscription-manager triage, there was some question whether or not the warning message logged to rhsm.log was truncated.  It was not truncated.  It spans multiple lines as shown here...

[root@rhsm-auto9-client1 ~]# subscription-manager facts --list > /tmp/facts && tail -20 /var/log/rhsm/rhsm.log | grep WARNING -B1 -A4
2022-01-06 10:44:44,221 [DEBUG] subscription-manager:2922470:MainThread @dmiinfo.py:73 - Using dmidecode dump file: /dev/mem
2022-01-06 10:44:44,229 [WARNING] subscription-manager:2922470:MainThread @dmiinfo.py:128 - Error reading system DMI information: # SMBIOS implementations newer than version 2.7 are not
# fully supported by this version of dmidecode.

NoneType: None
2022-01-06 10:44:44,320 [DEBUG] subscription-manager:2922470:MainThread @hwprobe.py:656 - Parsing lscpu JSON: b'{\n   "lscpu": [\n      {\n         "field": "Architecture:",\n         "data": "x86_64"\n      },{\n         "field": "CPU op-mode(s):",\n         "data": "32-bit, 64-bit"\n      },{\n         "field": "Address sizes:",\n         "data": "40 bits physical, 48 bits virtual"\n      },{\n         "field": "Byte Order:",\n         "data": "Little Endian"\n      },{\n         "field": "CPU(s):",\n         "data": "1"\n      },{\n         "field": "On-line CPU(s) list:",\n         "data": "0"\n      },{\n         "field": "Vendor ID:",\n         "data": "GenuineIntel"\n      },{\n         "field": "BIOS Vendor ID:",\n         "data": "QEMU"\n      },{\n         "field": "Model name:",\n         "data": "Intel Xeon E312xx (Sandy Bridge, IBRS update)"\n      },{\n         "field": "BIOS Model name:",\n         "data": "pc-q35-3.0"\n      },{\n         "field": "CPU family:",\n         "data": "6"\n      },{\n         "field": "Model:",\n         "data": "42"\n      },{\n         "field": "Thread(s) per core:",\n         "data": "1"\n      },{\n         "field": "Core(s) per socket:",\n         "data": "1"\n      },{\n         "field": "Socket(s):",\n         "data": "1"\n      },{\n         "field": "Stepping:",\n         "data": "1"\n      },{\n         "field": "BogoMIPS:",\n         "data": "3999.99"\n      },{\n         "field": "Flags:",\n         "data": "fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology cpuid tsc_known_freq pni pclmulqdq vmx ssse3 cx16 pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx hypervisor lahf_lm cpuid_fault pti ssbd ibrs ibpb stibp tpr_shadow vnmi flexpriority ept vpid tsc_adjust xsaveopt arat umip arch_capabilities"\n      },{\n         "field": "Virtualization:",\n         "data": "VT-x"\n      },{\n         "field": "Hypervisor vendor:",\n         "data": "KVM"\n      },{\n         "field": "Virtualization type:",\n         "data": "full"\n      },{\n         "field": "L1d cache:",\n         "data": "32 KiB (1 instance)"\n      },{\n         "field": "L1i cache:",\n         "data": "32 KiB (1 instance)"\n      },{\n         "field": "L2 cache:",\n         "data": "4 MiB (1 instance)"\n      },{\n         "field": "L3 cache:",\n         "data": "16 MiB (1 instance)"\n      },{\n         "field": "NUMA node(s):",\n         "data": "1"\n      },{\n         "field": "NUMA node0 CPU(s):",\n         "data": "0"\n      },{\n         "field": "Vulnerability Itlb multihit:",\n         "data": "Not affected"\n      },{\n         "field": "Vulnerability L1tf:",\n         "data": "Mitigation; PTE Inversion; VMX flush not necessary, SMT disabled"\n      },{\n         "field": "Vulnerability Mds:",\n         "data": "Vulnerable: Clear CPU buffers attempted, no microcode; SMT Host state unknown"\n      },{\n         "field": "Vulnerability Meltdown:",\n         "data": "Mitigation; PTI"\n      },{\n         "field": "Vulnerability Spec store bypass:",\n         "data": "Mitigation; Speculative Store Bypass disabled via prctl and seccomp"\n      },{\n         "field": "Vulnerability Spectre v1:",\n         "data": "Mitigation; usercopy/swapgs barriers and __user pointer sanitization"\n      },{\n         "field": "Vulnerability Spectre v2:",\n         "data": "Mitigation; Full generic retpoline, IBPB conditional, IBRS_FW, STIBP disabled, RSB filling"\n      },{\n         "field": "Vulnerability Srbds:",\n         "data": "Not affected"\n      },{\n         "field": "Vulnerability Tsx async abort:",\n         "data": "Not affected"\n      }\n   ]\n}\n'
[root@rhsm-auto9-client1 ~]#

This is a warning of dmidecode and not an hard error: the "dmi" facts are properly created.

This behaviour depends on the actual DMI bits on the machine: on my P1 Gen3, I get the same warnings:
  # SMBIOS implementations newer than version 2.7 are not
  # fully supported by this version of dmidecode.
... because the system has:
  SMBIOS 3.2.0 present.

The code triggering this is the following in dmiinfo.py:

    def log_warnings(self, dmidecode):
        dmiwarnings = dmidecode.get_warnings()
        if dmiwarnings:
            log.warning(_("Error reading system DMI information: {dmiwarnings}").format(dmiwarnings=dmiwarnings), exc_info=True)
            dmidecode.clear_warnings()

I think there are two possible steps here:
a) definitely improve the wording for the dmidecode warnings: they are logged as sub-man warnings, so the text "error reading" seems a bit odd; this wording was introduced years ago with commit 1d53970848bf4412234f6d93d6a2e2a62f75e59e
b) maybe downgrade the sub-man logging priority from warning to info? after all, it is not something too actionable, IMHO...

The DMI information are extracted using python-dmidecode: https://github.com/nima/python-dmidecode
Unfortunately, it does not have an active development at the time of this writing, and thus newer DMI versions are not supported -- e.g. https://github.com/nima/python-dmidecode/issues/2

We discussed this bug in a recent triaging meeting, and we agreed that the only actionable thing to do is to soften the wording of the message with dmidecode warnings to not mention "error". We agreed that it was still a good idea to log the dmidecode warnings with a "warning" priority.

Pre-verifying version...

[root@rhsm-auto90-client2 ~]# rpm -q subscription-manager
subscription-manager-1.29.24-1.git.0.db28224.el9.x86_64
[root@rhsm-auto90-client2 ~]# rpm -q subscription-manager --changelog | grep 2035662 
- 2035662: facts: tweak message for dmidecode warnings (ptoscano)
[root@rhsm-auto90-client2 ~]# 
[root@rhsm-auto90-client2 ~]# 
[root@rhsm-auto90-client2 ~]# 
[root@rhsm-auto90-client2 ~]# subscription-manager config --logging.default_log_level=DEBUG
[root@rhsm-auto90-client2 ~]# dmidecode | head -6
# dmidecode 3.3
Getting SMBIOS data from sysfs.
SMBIOS 2.8 present.
9 structures occupying 367 bytes.
Table at 0x000F59C0.

[root@rhsm-auto90-client2 ~]# subscription-manager facts --list > /tmp/facts && tail -20 /var/log/rhsm/rhsm.log | grep WARNING -B1 -A4
2022-02-10 14:15:57,488 [DEBUG] subscription-manager:1440055:MainThread @dmiinfo.py:71 - Using dmidecode dump file: /dev/mem
2022-02-10 14:15:57,497 [WARNING] subscription-manager:1440055:MainThread @dmiinfo.py:125 - Warnings while reading system DMI information:
# SMBIOS implementations newer than version 2.7 are not
# fully supported by this version of dmidecode.


[root@rhsm-auto90-client2 ~]# 

VERIFIED: As shown above on a system with SMBIOS 2.8 (or newer) present, the wording in the rhsm.log WARNING has been softened from an "Error reading system DMI information:" to a "Warnings while reading system DMI information:" and the former NoneType: None formatting from logging the warning has been corrected.

Verifying subscription-manager-1.29.26-1.el9 which has landed in compose RHEL-9.0.0-20220221.2 ...

[root@rhsm-auto90-client1 ~]# rpm -q subscription-manager
subscription-manager-1.29.26-1.el9.x86_64
[root@rhsm-auto90-client1 ~]# rpm -q subscription-manager --changelog | grep 2035662
- 2035662: facts: tweak message for dmidecode warnings (ptoscano)
[root@rhsm-auto90-client1 ~]# 
[root@rhsm-auto90-client1 ~]# 
[root@rhsm-auto90-client1 ~]# subscription-manager config --logging.default_log_level=DEBUG
[root@rhsm-auto90-client1 ~]# dmidecode | head -6
# dmidecode 3.3
Getting SMBIOS data from sysfs.
SMBIOS 2.8 present.
9 structures occupying 367 bytes.
Table at 0x000F59C0.

[root@rhsm-auto90-client1 ~]# subscription-manager facts --list > /tmp/facts && tail -20 /var/log/rhsm/rhsm.log | grep WARNING -B1 -A4
2022-02-21 08:58:06,257 [DEBUG] subscription-manager:612659:MainThread @dmiinfo.py:71 - Using dmidecode dump file: /dev/mem
2022-02-21 08:58:06,267 [WARNING] subscription-manager:612659:MainThread @dmiinfo.py:125 - Warnings while reading system DMI information:
# SMBIOS implementations newer than version 2.7 are not
# fully supported by this version of dmidecode.


[root@rhsm-auto90-client1 ~]# 


VERIFIED: As shown above on a system with SMBIOS 2.8 (or newer), the wording in the rhsm.log WARNING has been softened from an "Error reading system DMI information:" to "Warnings while reading system DMI information:" and the former NoneType: None formatting (as encountered in comment 1) from logging the warning has been corrected.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (new packages: subscription-manager), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2022:3984