[ovirt-devel] Re: execution failed: javax.net.ssl.SSLPeerUnverifiedException (was: vdsm.storage.exception.UnknownTask: Task id unknown

Thu, 09 Jul 2020 02:35:16 -0700 

Hi,

On 7/8/20 3:34 PM, Yedidyah Bar David wrote:

Did you also get in engine.log "javax.net.ssl.SSLPeerUnverifiedException"?
I was also able to reproduce this on my server, but I'm baffled by this one... 
I enabled debug logs on the engine with [1] and got this stack trace [2],
but the certs seem ok to me:

1. I verified the hostname in the certificate by running on the host:

openssl s_client \
    -connect 127.0.0.1:54321 \
    -CAfile /etc/pki/vdsm/certs/cacert.pem \
    -cert /etc/pki/vdsm/certs/vdsmcert.pem \
    -key /etc/pki/vdsm/keys/vdsmkey.pem \
    -verify_hostname lago-he-basic-suite-master-host-0.lago.local

2. curl is also happy:

curl \
    --cacert /etc/pki/vdsm/certs/cacert.pem \
    --cert /etc/pki/vdsm/certs/vdsmcert.pem \
    --key /etc/pki/vdsm/keys/vdsmkey.pem \
    https://lago-he-basic-suite-master-host-0.lago.local:54321

3. on the hosted engine there is proper entry in '/etc/hosts':

[root@lago-he-basic-suite-master-engine certs]# cat /etc/hosts
127.0.0.1   localhost localhost.localdomain localhost4 localhost4.localdomain4 ::1         localhost localhost.localdomain localhost6 localhost6.localdomain6 
192.168.200.3 lago-he-basic-suite-master-host-0.lago.local
192.168.222.76 lago-he-basic-suite-master-engine.lago.local # hosted-engine-setup-/var/tmp/localvm9k3eqtf7 

4. and dig -x seems to resolve properly:

[root@lago-he-basic-suite-master-engine certs]# dig +short -x 192.168.200.3
lago-he-basic-suite-master-host-0.lago.local.
If anyone else has some ideas what else could be checked then please ping me. 

Marcin

[1] https://gerrit.ovirt.org/110211
[2] http://pastebin.test.redhat.com/882851



On Wed, Jul 8, 2020 at 4:25 PM Artem Hrechanychenko <[email protected]> wrote:

Reproduced locally without using Jenkins


[ INFO  ] TASK [ovirt.hosted_engine_setup : Add HE disks]
[ ERROR ] {'msg': 'Timeout exceed while waiting on result state of the entity.', 'exception': 'Traceback (most recent 
call last):\n  File 
"/tmp/ansible_ovirt_disk_28_payload_vtqyyibx/ansible_ovirt_disk_28_payload.zip/ansible/modules/ovirt_disk_28.py",
 line 678, in main\n  File 
"/tmp/ansible_ovirt_disk_28_payload_vtqyyibx/ansible_ovirt_disk_28_payload.zip/ansible/module_utils/ovirt.py",
 line 646, in create\n    poll_interval=self._module.params[\'poll_interval\'],\n  File 
"/tmp/ansible_ovirt_disk_28_payload_vtqyyibx/ansible_ovirt_disk_28_payload.zip/ansible/module_utils/ovirt.py",
 line 364, in wait\n    raise Exception("Timeout exceed while waiting on result state of the 
entity.")\nException: Timeout exceed while waiting on result state of the entity.\n', 'failed': True, 
'invocation': {'module_args': {'name': 'HostedEngineConfigurationImage', 'size': '1GiB', 'format': 'raw', 'sparse': 
False, 'description': 'Hosted-Engine configuration disk', 'content_type': 'hosted_engine_configuration', 'interface': 
'virtio', 'storage_domain': 'hosted_storage', 'wait': True, 'timeout': 600, 'auth': {'token': 
'rAqX1OJIbJyMrA1aWVR-AR54T2lsiBbalN80dWugpfHFBqwiCe4rz3porngvlFSE90k-FEqagPPFboU6ew1hPw', 'url': 
'https://lago-he-basic-suite-master-engine.lago.local/ovirt-engine/api', 'ca_file': None, 'insecure': True, 'timeout': 
0, 'compress': True, 'kerberos': False, 'headers': None}, 'poll_interval': 3, 'fetch_nested': False, 
'nested_attributes': [], 'state': 'present', 'force': False, 'id': None, 'vm_name': None, 'vm_id': None, 
'storage_domains': None, 'profile': None, 'quota_id': None, 'bootable': None, 'shareable': None, 'logical_unit': None, 
'download_image_path': None, 'upload_image_path': None, 'sparsify': None, 'openstack_volume_type': None, 
'image_provider': None, 'host': None, 'wipe_after_delete': None, 'activate': None}}, '_ansible_no_log': False, 
'changed': False, 'item': {'name': 'HostedEngineConfigurationImage', 'description': 'Hosted-Engine configuration disk', 
'size': '1GiB', 'format': 'raw', 'sparse': False, 'content': 'hosted_engine_configuration'}, 'ansible_loop_var': 
'item', '_ansible_item_label': {'name': 'HostedEngineConfigurationImage', 'description': 'Hosted-Engine configuration 
disk', 'size': '1GiB', 'format': 'raw', 'sparse': False, 'content': 'hosted_engine_configuration'}}


On Tue, Jul 7, 2020 at 4:22 PM Martin Perina <[email protected]> wrote:

Hi,

I'm not aware of change regarding certificates recently. So is this error 
reproducible outside Jenkins? Or even better is it reproducible on some easier 
flow other than HE installation so we can debug what certificate is loaded in 
VDSM?

Thanks,
Martin

On Tue, Jul 7, 2020 at 2:07 PM Yedidyah Bar David <[email protected]> wrote:

On Tue, Jul 7, 2020 at 12:50 PM Yedidyah Bar David <[email protected]> wrote:

On Wed, Jun 24, 2020 at 2:14 PM Evgeny Slutsky <[email protected]> wrote:

Hi,
changing the hostname to include also the domain name fixed the  cert 
deployment issue:
https://gerrit.ovirt.org/#/c/109842/

not sure how it affects the engine certificate content.
from my offline discussion with @Martin Perina  this was that change that could 
cause it:
https://gerrit.ovirt.org/#/c/109636/

any thoughts?

Above two patches are merged, but we still fail the same way:

https://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-master/1664/

https://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-master/1664/artifact/exported-artifacts/test_logs/he-basic-suite-master/post-he_deploy/lago-he-basic-suite-master-host-0/_var_log/ovirt-hosted-engine-setup/engine-logs-2020-07-07T03%3A15%3A01Z/ovirt-engine/engine.log

2020-07-06 23:04:25,555-04 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-38)
[fb28ce9] Command 'UploadStreamVDSCommand(HostName =
lago-he-basic-suite-master-host-0.lago.local,
UploadStreamVDSCommandParameters:{hostId='e096650f-a7d6-4383-b1bb-f2e61327aac0'})'
execution failed: javax.net.ssl.SSLPeerUnverifiedException:
Certificate for <lago-he-basic-suite-master-host-0.lago.local> doesn't
match any of the subject alternative names:
[lago-he-basic-suite-master-host-0.lago.local]

Any idea?

And I now see this is indeed what's failing hosted-engine deploy at:

2020-07-07 05:51:58,573-0400 INFO ansible task start {'status': 'OK',
'ansible_type': 'task', 'ansible_playbook':
'/usr/share/ovirt-hosted-engine-setup/ansible/trigger_role.yml',
'ansible_task': 'ovirt.hosted_engine_setup : Check OVF_STORE volume
status'}

(See other thread: [oVirt Jenkins]
ovirt-system-tests_he-basic-suite-master - Build # 1655 - Still
Failing! )

On a successful run, engine.log has:

2020-07-02 18:01:55,527+03 INFO
[org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStorageDomainCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
  [2b0721d8] Running command: ProcessOvfUpdateForStorageDomainCommand
internal: true. Entities affected :  ID:
e102d7b5-1a37-490f-a3e7-20e56c37791f Type: StorageAction group
MANIPULATE_STORAG
E_DOMAIN with role type ADMIN
2020-07-02 18:01:55,607+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8
] START, SetVolumeDescriptionVDSCommand(
SetVolumeDescriptionVDSCommandParameters:{storagePoolId='b9dccefe-bc61-11ea-8ebe-001a4a231728',
ignoreFailoverLimit='false', storageDomainId='e102d7b
5-1a37-490f-a3e7-20e56c37791f',
imageGroupId='db934a98-4111-4faf-8cb9-6b36928cd61c',
imageId='f898c40e-1f88-48db-b59b-f2c73162ddb7'}), log id: e203e51
2020-07-02 18:01:55,609+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8
] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters:
2020-07-02 18:01:55,609+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8
] ++ spUUID=b9dccefe-bc61-11ea-8ebe-001a4a231728
2020-07-02 18:01:55,609+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8
] ++ sdUUID=e102d7b5-1a37-490f-a3e7-20e56c37791f
2020-07-02 18:01:55,609+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8
] ++ imageGroupGUID=db934a98-4111-4faf-8cb9-6b36928cd61c
2020-07-02 18:01:55,610+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8
] ++ volUUID=f898c40e-1f88-48db-b59b-f2c73162ddb7
2020-07-02 18:01:55,610+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8
] ++ description={"Updated":false,"Last Updated":"Thu Jul 02 17:35:07
IDT 2020","Storage
Domains":[{"uuid":"e102d7b5-1a37-490f-a3e7-20e56c37791f"}],"Disk
Description":"OVF_STORE"}
2020-07-02 18:01:55,717+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8
] FINISH, SetVolumeDescriptionVDSCommand, return: , log id: e203e51
2020-07-02 18:01:55,829+03 INFO
[org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] Lock Acq
uired to object 'EngineLock:{exclusiveLocks='',
sharedLocks='[a4fc6701-e2c7-4770-896a-d0ee74f9c7b8=VDS_EXECUTION]'}'
2020-07-02 18:01:55,912+03 INFO
[org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] Running
command: UploadStreamCommand internal: true. Entities affected :  ID:
e102d7b5-1a37-490f-a3e7-20e56c37791f Type: Storage
2020-07-02 18:01:55,914+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] START,
  UploadStreamVDSCommand(HostName =
didi-centos8-host.lab.eng.tlv2.redhat.com,
UploadStreamVDSCommandParameters:{hostId='a4fc6701-e2c7-4770-896a-d0ee74f9c7b8'}),
log id: 674791e5
2020-07-02 18:01:55,914+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] -- exe
cuteVdsBrokerCommand, parameters:
2020-07-02 18:01:55,914+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ spU
UID=b9dccefe-bc61-11ea-8ebe-001a4a231728
2020-07-02 18:01:55,914+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ sdU
UID=e102d7b5-1a37-490f-a3e7-20e56c37791f
2020-07-02 18:01:55,914+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ ima
geGUID=db934a98-4111-4faf-8cb9-6b36928cd61c
2020-07-02 18:01:55,914+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ vol
UUID=f898c40e-1f88-48db-b59b-f2c73162ddb7
2020-07-02 18:01:55,914+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ siz
e=23552
2020-07-02 18:01:56,419+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]Signed-off-by: 
Marcin Sobczyk <[email protected]>
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] FINISH
, UploadStreamVDSCommand, return: , log id: 674791e5
2020-07-02 18:01:58,732+03 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] CommandAsyncTask::Adding CommandMultiAsyncTasks object for
command 'ed1ff9b8-8cfd-489b-9cad-f078029a3cc1'
2020-07-02 18:01:58,732+03 INFO
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] CommandMultiAsyncTasks::attachTask: Attaching task
'997accaf-aa33-4632-a0bf-24d59a637255' to command
'ed1ff9b8-8cfd-489b-9cad-f078029a3cc1'.
2020-07-02 18:01:58,937+03 INFO
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] Adding task '997accaf-aa33-4632-a0bf-24d59a637255' (Parent
Command 'UploadStream', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'),
polling hasn't started yet..
2020-07-02 18:01:58,963+03 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] BaseAsyncTask::startPollingTask: Starting to poll task
'997accaf-aa33-4632-a0bf-24d59a637255'.
2020-07-02 18:01:58,973+03 INFO
[org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] Lock freed to object 'EngineLock:{exclusiveLocks='',
sharedLocks='[a4fc6701-e2c7-4770-896a-d0ee74f9c7b8=VDS_EXECUTION]'}'
2020-07-02 18:01:58,979+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] START, SetVolumeDescriptionVDSCommand(
SetVolumeDescriptionVDSCommandParameters:{storagePoolId='b9dccefe-bc61-11ea-8ebe-001a4a231728',
ignoreFailoverLimit='false',
storageDomainId='e102d7b5-1a37-490f-a3e7-20e56c37791f',
imageGroupId='db934a98-4111-4faf-8cb9-6b36928cd61c',
imageId='f898c40e-1f88-48db-b59b-f2c73162ddb7'}), log id: 5cea0ad3
2020-07-02 18:01:58,979+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] -- executeIrsBrokerCommand: calling 'setVolumeDescription',
parameters:
2020-07-02 18:01:58,979+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ spUUID=b9dccefe-bc61-11ea-8ebe-001a4a231728
2020-07-02 18:01:58,980+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ sdUUID=e102d7b5-1a37-490f-a3e7-20e56c37791f
2020-07-02 18:01:58,980+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ imageGroupGUID=db934a98-4111-4faf-8cb9-6b36928cd61c
2020-07-02 18:01:58,980+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ volUUID=f898c40e-1f88-48db-b59b-f2c73162ddb7
2020-07-02 18:01:58,980+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84)
[2b0721d8] ++ description={"Updated":true,"Size":23552,"Last
Updated":"Thu Jul 02 18:01:55 IDT 2020","Storage
Domains":[{"uuid":"e102d7b5-1a37-490f-a3e7-20e56c37791f"}],"Disk
Description":"OVF_STORE"}

This ('"Updated":true') is what our ansible code looks for.

In a failed run, e.g.
https://jenkins.ovirt.org/job/ovirt-system-tests_standard-check-patch/10162/artifact/check-patch.he-basic_suite_master.el8.x86_64/test_logs/he-basic-suite-master/post-he_deploy/lago-he-basic-suite-master-host-0/_var_log/ovirt-hosted-engine-setup/engine-logs-2020-07-07T09%3A56%3A20Z/ovirt-engine/engine.log
:

2020-07-07 05:51:53,662-04 INFO
[org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStorageDomainCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] Running command: ProcessOvfUpdateForStorageDomainCommand
internal: true. Entities affected :  ID:
812ecaaa-1227-46f9-92d6-634f6a34a943 Type: StorageAction group
MANIPULATE_STORAGE_DOMAIN with role type ADMIN
2020-07-07 05:51:53,686-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] START, SetVolumeDescriptionVDSCommand(
SetVolumeDescriptionVDSCommandParameters:{storagePoolId='b089490e-c035-11ea-a9e2-5452c0a8c863',
ignoreFailoverLimit='false',
storageDomainId='812ecaaa-1227-46f9-92d6-634f6a34a943',
imageGroupId='33dcdbdd-cc35-403a-9855-7d2eb1176a31',
imageId='7f6b26c9-3eb8-4c58-9627-37b411cb46bd'}), log id: 12e48aac
2020-07-07 05:51:53,686-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] -- executeIrsBrokerCommand: calling 'setVolumeDescription',
parameters:
2020-07-07 05:51:53,687-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ spUUID=b089490e-c035-11ea-a9e2-5452c0a8c863
2020-07-07 05:51:53,687-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ sdUUID=812ecaaa-1227-46f9-92d6-634f6a34a943
2020-07-07 05:51:53,687-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ imageGroupGUID=33dcdbdd-cc35-403a-9855-7d2eb1176a31
2020-07-07 05:51:53,687-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ volUUID=7f6b26c9-3eb8-4c58-9627-37b411cb46bd
2020-07-07 05:51:53,687-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ description={"Updated":false,"Last Updated":null,"Storage
Domains":[{"uuid":"812ecaaa-1227-46f9-92d6-634f6a34a943"}],"Disk
Description":"OVF_STORE"}
2020-07-07 05:51:53,938-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] FINISH, SetVolumeDescriptionVDSCommand, return: , log id:
12e48aac
2020-07-07 05:51:54,006-04 INFO
[org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] Lock Acquired to object 'EngineLock:{exclusiveLocks='',
sharedLocks='[0a166780-eb5b-46c2-a27f-df15d12594b5=VDS_EXECUTION]'}'
2020-07-07 05:51:54,066-04 INFO
[org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] Running command: UploadStreamCommand internal: true.
Entities affected :  ID: 812ecaaa-1227-46f9-92d6-634f6a34a943 Type:
Storage
2020-07-07 05:51:54,068-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] START, UploadStreamVDSCommand(HostName =
lago-he-basic-suite-master-host-0.lago.local,
UploadStreamVDSCommandParameters:{hostId='0a166780-eb5b-46c2-a27f-df15d12594b5'}),
log id: 2704d3cb
2020-07-07 05:51:54,068-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] -- executeVdsBrokerCommand, parameters:
2020-07-07 05:51:54,068-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ spUUID=b089490e-c035-11ea-a9e2-5452c0a8c863
2020-07-07 05:51:54,069-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ sdUUID=812ecaaa-1227-46f9-92d6-634f6a34a943
2020-07-07 05:51:54,069-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ imageGUID=33dcdbdd-cc35-403a-9855-7d2eb1176a31
2020-07-07 05:51:54,069-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ volUUID=7f6b26c9-3eb8-4c58-9627-37b411cb46bd
2020-07-07 05:51:54,069-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] ++ size=23552
2020-07-07 05:51:54,104-04 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-78)
[a0f7806] Command 'UploadStreamVDSCommand(HostName =
lago-he-basic-suite-master-host-0.lago.local,
UploadStreamVDSCommandParameters:{hostId='0a166780-eb5b-46c2-a27f-df15d12594b5'})'
execution failed: javax.net.ssl.SSLPeerUnverifiedException:
Certificate for <lago-he-basic-suite-master-host-0.lago.local> doesn't
match any of the subject alternative names:
[lago-he-basic-suite-master-host-0.lago.local]

(The "successful" log before is from a local test with a deliberately
somewhat-old ovirt-engine-appliance-4.4-20200617065310.1.el8.x86_64
and with a patch to prevent engine-setup from updating the engine,
https://gerrit.ovirt.org/109730 . Verifying this patch was the reason
to run it locally).

Thanks and best regards,





On Wed, Jun 17, 2020 at 9:32 AM Yedidyah Bar David <[email protected]> wrote:

On Wed, Jun 17, 2020 at 6:28 AM <[email protected]> wrote:

Project: https://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-master/
Build: 
https://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-master/1641/

This one failed while trying to create the disk image for the hosted-egnine VM:

https://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-master/1641/artifact/exported-artifacts/test_logs/he-basic-suite-master/post-he_deploy/lago-he-basic-suite-master-host-0/_var_log/ovirt-hosted-engine-setup/ovirt-hosted-engine-setup-ansible-create_target_vm-20200616230220-yfumoc.log
:

2020-06-16 23:03:20,527-0400 INFO ansible task start {'status': 'OK',
'ansible_type': 'task', 'ansible_playbook':
'/usr/share/ovirt-hosted-engine-setup/ansible/trigger_role.yml',
'ansible_task': 'ovirt.hosted_engine_setup : Add HE disks'}
...
2020-06-16 23:14:12,702-0400 DEBUG var changed: host "localhost" var
"add_disks" type "<class 'dict'>" value: "{
...
             "msg": "Timeout exceed while waiting on result state of the 
entity."

https://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-master/1641/artifact/exported-artifacts/test_logs/he-basic-suite-master/post-he_deploy/lago-he-basic-suite-master-host-0/_var_log/ovirt-hosted-engine-setup/engine-logs-2020-06-17T03%3A14%3A18Z/ovirt-engine/engine.log
:

2020-06-16 23:03:22,612-04 INFO
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (default task-1)
[16c24599-0048-44eb-a410-d39b7ce98712]
CommandMultiAsyncTasks::attachTask: Attaching task
'6b2a7648-748c-430b-94b6-5e3f719df2ac' to command
'fa81759d-c57a-4237-81e0-beb210faa64d'.
2020-06-16 23:03:22,659-04 INFO
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-1)
[16c24599-0048-44eb-a410-d39b7ce98712] Adding task
'6b2a7648-748c-430b-94b6-5e3f719df2ac' (Parent Command
'AddImageFromScratch', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'),
polling hasn't started yet..
2020-06-16 23:03:22,699-04 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (default task-1)
[16c24599-0048-44eb-a410-d39b7ce98712]
BaseAsyncTask::startPollingTask: Starting to poll task
'6b2a7648-748c-430b-94b6-5e3f719df2ac'.
...
2020-06-16 23:03:25,835-04 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-25)
[] SPMAsyncTask::PollTask: Polling task
'6b2a7648-748c-430b-94b6-5e3f719df2ac' (Parent Command
'AddImageFromScratch', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters')
returned status 'finished', result 'success'.
2020-06-16 23:03:25,863-04 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-25)
[] BaseAsyncTask::onTaskEndSuccess: Task
'6b2a7648-748c-430b-94b6-5e3f719df2ac' (Parent Command
'AddImageFromScratch', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended
successfully.

But then:

2020-06-16 23:03:25,897-04 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-29)
[16c24599-0048-44eb-a410-d39b7ce98712]
CommandAsyncTask::HandleEndActionResult [within thread]: endAction for
action type 'AddImageFromScratch' succeeded, clearing tasks.
2020-06-16 23:03:25,897-04 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-29)
[16c24599-0048-44eb-a410-d39b7ce98712] SPMAsyncTask::ClearAsyncTask:
Attempting to clear task '6b2a7648-748c-430b-94b6-5e3f719df2ac'
2020-06-16 23:03:25,899-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-29)
[16c24599-0048-44eb-a410-d39b7ce98712] START, SPMClearTaskVDSCommand(
SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='3bcde3b4-b044-11ea-bbb6-5452c0a8c863',
ignoreFailoverLimit='false',
taskId='6b2a7648-748c-430b-94b6-5e3f719df2ac'}), log id: 481c2d3d
2020-06-16 23:03:25,900-04 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-29)
[16c24599-0048-44eb-a410-d39b7ce98712] START,
HSMClearTaskVDSCommand(HostName = lago-he-basic-suite-master-host-0,
HSMTaskGuidBaseVDSCommandParameters:{hostId='85ecc51c-f2cb-46a1-9452-fd487399d8dd',
taskId='6b2a7648-748c-430b-94b6-5e3f719df2ac'}), log id: 17360b3d
...
2020-06-16 23:03:26,054-04 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-29)
[16c24599-0048-44eb-a410-d39b7ce98712]
BaseAsyncTask::removeTaskFromDB: Removed task
'6b2a7648-748c-430b-94b6-5e3f719df2ac' from DataBase

But then:

2020-06-16 23:03:26,315-04 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-55)
[7fe7b467] Command 'UploadStreamVDSCommand(HostName =
lago-he-basic-suite-master-host-0,
UploadStreamVDSCommandParameters:{hostId='85ecc51c-f2cb-46a1-9452-fd487399d8dd'})'
execution failed: javax.net.ssl.SSLPeerUnverifiedException:
Certificate for <lago-he-basic-suite-master-host-0.lago.local> doesn't
match any of the subject alternative names:
[lago-he-basic-suite-master-host-0.lago.local]
2020-06-16 23:03:26,315-04 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-55)
[7fe7b467] FINISH, UploadStreamVDSCommand, return: , log id: 7e3a3e80
2020-06-16 23:03:26,316-04 ERROR
[org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-55)
[7fe7b467] Command
'org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand'
failed: EngineException:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException:
javax.net.ssl.SSLPeerUnverifiedException: Certificate for
<lago-he-basic-suite-master-host-0.lago.local> doesn't match any of
the subject alternative names:
[lago-he-basic-suite-master-host-0.lago.local] (Failed with error
VDS_NETWORK_ERROR and code 5022)

Any idea why?
Anything changed in how we check the certificate?
Perhaps related to upgrade to CentOS 8.2?
And, how come it failed only this late? Don't we check the certificate earlier?

Anyway, this left the host in "not responding" state, so:

2020-06-16 23:03:29,994-04 ERROR
[org.ovirt.engine.core.bll.storage.disk.AddDiskCommandCallback]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-79)
[16c24599-0048-44eb-a410-d39b7ce98712] Failed to get volume info:
org.ovirt.engine.core.common.errors.EngineException: EngineException:
No host was found to perform the operation (Failed with error
RESOURCE_MANAGER_VDS_NOT_FOUND and code 5004)

And perhaps due to an unrelated issue, also:

2020-06-16 23:03:31,177-04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMRevertTaskVDSCommand]
(EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-43)
[16c24599-0048-44eb-a410-d39b7ce98712] Trying to revert unknown task
'6b2a7648-748c-430b-94b6-5e3f719df2ac'

I looked a bit also at:

https://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-master/1641/artifact/exported-artifacts/test_logs/he-basic-suite-master/post-he_deploy/lago-he-basic-suite-master-host-0/_var_log/vdsm/vdsm.log

and see there some relevant stuff, but nothing I can spot about the
root cause (e.g. the word "cert" does not appear there).

Can anyone please have a look? Thanks.


Build Number: 1641
Build Status:  Still Failing
Triggered By: Started by timer

-------------------------------------
Changes Since Last Success:
-------------------------------------
Changes for Build #1633
[Marcin Sobczyk] ost-images: Drop rebasing of qcows

[Ehud Yonasi] mock: fix yum repos injection.

[Ehud Yonasi] onboard ost-images to stdci.


Changes for Build #1634
[Marcin Sobczyk] ost-images: Drop rebasing of qcows


Changes for Build #1635
[Marcin Sobczyk] ost-images: Drop rebasing of qcows


Changes for Build #1636
[Marcin Sobczyk] ost-images: Drop rebasing of qcows


Changes for Build #1637
[Marcin Sobczyk] ost-images: Drop rebasing of qcows


Changes for Build #1638
[Marcin Sobczyk] ost-images: Drop rebasing of qcows

[Ehud Yonasi] stdci_runner: update templates node to ost-images.


Changes for Build #1639
[Marcin Sobczyk] ost-images: Drop rebasing of qcows


Changes for Build #1640
[Yedidyah Bar David] Allow engine 20 minutes to come up after VM restart


Changes for Build #1641
[Michal Skrivanek] test live storage migration again

[Ehud Yonasi] poll: add ost-images to nightly.




-----------------
Failed Tests:
-----------------
No tests ran.



--
Didi
_______________________________________________
Devel mailing list -- [email protected]
To unsubscribe send an email to [email protected]
Privacy Statement: https://www.ovirt.org/privacy-policy.html
oVirt Code of Conduct: 
https://www.ovirt.org/community/about/community-guidelines/
List Archives: 
https://lists.ovirt.org/archives/list/[email protected]/message/AI6KENCA35EK5RDLKR5BWU7HC6H3FIJ7/



--
Didi



--
Didi



--
Martin Perina
Manager, Software Engineering
Red Hat Czech s.r.o.
_______________________________________________
Devel mailing list -- [email protected]
To unsubscribe send an email to [email protected]
Privacy Statement: https://www.ovirt.org/privacy-policy.html
oVirt Code of Conduct: 
https://www.ovirt.org/community/about/community-guidelines/
List Archives: 
https://lists.ovirt.org/archives/list/[email protected]/message/2JUND2RQV6O7FBK3YQOSFV4XTRJ6JXUT/





_______________________________________________
Devel mailing list -- [email protected]
To unsubscribe send an email to [email protected]
Privacy Statement: https://www.ovirt.org/privacy-policy.html
oVirt Code of Conduct: 
https://www.ovirt.org/community/about/community-guidelines/
List Archives: 
https://lists.ovirt.org/archives/list/[email protected]/message/QM43OP6WPO5SAZEMNM5Y2IW67LGNDZ22/

Reply via email to