On Thu, Aug 12, 2021 at 7:00 PM Milan Zamazal <mzamazal(a)redhat.com> wrote:
Milan Zamazal <mzamazal(a)redhat.com> writes:
> Milan Zamazal <mzamazal(a)redhat.com> writes:
>
>> Nir Soffer <nsoffer(a)redhat.com> writes:
>>
>>> VDSM CI is failing now consistently. Last related change is:
>>>
https://gerrit.ovirt.org/c/vdsm/+/116090
>>
>> It doesn't look related.
>>
>>> Build:
>>>
https://jenkins.ovirt.org/job/vdsm_standard-check-patch/29212//artifact/c...
>>>
>>> _____________________ QemuGuestAgentTests.test_pci_devices
_____________________
>>>
>>> self = <virt.qemuguestagent_test.QemuGuestAgentTests
>>> testMethod=test_pci_devices>
>>>
>>> def test_pci_devices(self):
>>> devices =
self.qga_poller._qga_call_get_devices(self.vm)['pci_devices']
>>> # Ethernet is returned twice by the agent but should appear only
>>> # once in the list
>>> assert len(devices) == 2
>>> eth = [d for d in devices if d['device_id'] == 4096][0]
>>> assert eth == {
>>> 'device_id': 4096,
>>> 'driver_date': '2019-08-12',
>>> 'driver_name': 'Red Hat VirtIO Ethernet
Adapter',
>>> 'driver_version': '100.80.104.17300',
>>> 'vendor_id': 6900,
>>> }
>>> balloon = [d for d in devices if d['device_id'] == 4098][0]
>>>> assert balloon == {
>>> 'device_id': 4098,
>>> 'driver_date': '2019-08-12',
>>> 'driver_name': 'VirtIO Balloon Driver',
>>> 'driver_version': '100.80.104.17300',
>>> 'vendor_id': 6900,
>>> }
>>> E AssertionError: assert {'device_id':...4.17300', ...}
==
>>> {'device_id':...4.17300', ...}
>>> E Omitting 4 identical items, use -vv to show
>>> E Differing items:
>>> E {'driver_date': '2019-08-11'} !=
{'driver_date': '2019-08-12'}
>>>
>>> Are we using real time in this test?
>>
>> No, I think the problem is related to the following line
>>
>> 'driver-date': 1565568000000000000,
>>
>> in qemuguestagent_test.py and the corresponding conversion
>>
>> date = datetime.date.fromtimestamp(date // 1e9).isoformat()
>>
>> in guestagenthelpers.py.
>>
>> The test passes on my computer so I wonder whether it may be a bug in
>> some version of python3-dateutil. I also wonder whether the fact that
>> it occurred on 12 August is just a coincidence.
>
> Looks correct also on current CentOS Stream 8:
>
> >>> datetime.datetime.fromtimestamp(1565568000000000000 //
1e9).isoformat()
> '2019-08-12T00:00:00'
>
> And there was no leap second this year that could cause it.
>
> I guess it could be fixed by shifting the driver timestamp a bit forward
> but then the test wouldn't check for these kinds of errors anymore. So
> I'd suggest disabling the test if it causes trouble until the failing
> part is identified.
Or could it be an issue, under some circumstances, with using float in
the computation (which is wrong anyway)? Let's try:
https://gerrit.ovirt.org/c/vdsm/+/116182
Creating datetime from timestamp means we use real time instead of
monotonic time which is suspected.
I hope we don't use real time in the actual code and this is only a test issue.
We have other issues now:
- consistent timeout in merge tests
[2021-08-12T15:54:08.218Z] storage/merge_test.py .........x..x..
=============================================================
[2021-08-12T15:54:08.218Z] = Watched process timed out
=
[2021-08-12T15:54:08.218Z]
=============================================================
[2021-08-12T15:54:08.218Z] [New LWP 31618]
[2021-08-12T15:54:08.218Z] [Thread debugging using libthread_db enabled]
[2021-08-12T15:54:08.218Z] Using host libthread_db library
"/lib64/libthread_db.so.1".
[2021-08-12T15:54:08.218Z] 0x00007f0bcb0a4a41 in poll () from /lib64/libc.so.6
[2021-08-12T15:54:08.218Z]
[2021-08-12T15:54:08.218Z] Thread 2 (Thread 0x7f0bb1e35700 (LWP 31618)):
[2021-08-12T15:54:08.218Z] Undefined command: "py-bt". Try "help".
[2021-08-12T15:54:08.218Z] [Inferior 1 (process 22705) detached]
I'm trying to debug it here:
- network tests failing:
[2021-08-12T15:56:17.928Z] network/integration/link_bond_test.py
...F...FFFFFF.FF..... [ 11%]
Maybe changes in centos stream are breaking us again.
Nir