[ OST Failure Report ] [ oVirt Master (vdsmt) ] [ 12-0202018 ] [ 002_bootstrap.get_host_devices ] - Reminder

Mon Feb 12 16:05:31 UTC 2018

 On Mon, Feb 12, 2018 at 4:19 PM, Dafna Ron <dron at redhat.com> wrote:
> hi,
>
> I saw this failure on Friday and I also see it in 4.2 branch as well as
> Master.
>
> host-0 did not finish installation on misconfiguration (which I can only
> asume has to do with the block device list) but I cannot see anything in
> host-0 or engine to suggest what was the actual problem.

host-0 installation started:

2018-02-12 07:20:18,262-05 INFO
[org.ovirt.engine.core.vdsbroker.AddVdsVDSCommand] (default task-9)
[21f04b96] START, AddVdsVDSCommand(HostName =
lago-basic-suite-master-host-0,
AddVdsVDSCommandParameters:{hostId='468d8314-e2e0-416b-af9d-295f8ab5a522'}),
log id: a336fc4

But never finished. Last line from the installation is:

2018-02-12 07:20:29,266-05 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509),
Installing Host lago-basic-suite-master-host-0. Stage: Misc
configuration.

lago.log has:

2018-02-12 12:20:53,966::log_utils.py::start_log_task::655::nose::INFO::
 # verify_add_hosts:  [0m [0m
2018-02-12 12:24:19,039::log_utils.py::end_log_task::670::nose::INFO::
 # verify_add_hosts:  [32mSuccess [0m (in 0:03:25)

It seems like we verify that all hosts are up only after get_host_devices.

Probably, in this case, host-1 finished installation, host-0 did not,
and later, in get_host_devices, we happened to pick host-0 in:

    host = test_utils.hosts_in_cluster_v4(engine, CLUSTER_NAME)[0]

But failed to get a list of devices from it.

Perhaps this should fix:

https://gerrit.ovirt.org/87526

>
> The patches its reporting are not related.
>
> Link and headline of suspected patches: Not related
>
>
> Link to Job:
>
>
> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/5613/
>
> Link to all logs:
>
>
> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/5613/artifacts
>
> (Relevant) error snippet from the log:
>
> <error>
>
>
> Api error:
>
>
> Error Message
>
> Could not find block_vda1 device in host devices:
>
> Stacktrace
>
> Traceback (most recent call last):
>   File "/usr/lib64/python2.7/unittest/case.py", line 369, in run
>     testMethod()
>   File "/usr/lib/python2.7/site-packages/nose/case.py", line 197, in runTest
>     self.test(*self.arg)
>   File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 129, in
> wrapped_test
>     test()
>   File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 59, in
> wrapper
>     return func(get_test_prefix(), *args, **kwargs)
>   File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 78, in
> wrapper
>     prefix.virt_env.engine_vm().get_api(api_ver=4), *args, **kwargs
>   File
> "/home/jenkins/workspace/ovirt-master_change-queue-tester/ovirt-system-tests/basic-suite-master/test-scenarios/002_bootstrap.py",
> line 1208, in get_host_devices
>     raise RuntimeError('Could not find block_vda1 device in host devices:
> {}'.format(device_list))
> RuntimeError: Could not find block_vda1 device in host devices:
>
>
> engine log:
>
> [dron at dron post-002_bootstrap.py]$ less
> lago-basic-suite-master-engine/_var_log/ovirt-engine/engine.log |grep host-0
> 2018-02-12 07:20:17,184-05 DEBUG
> [org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
> (default task-9) [ebedf4a6-07be-45b3-9062-7996c362f747] method: getByName,
> params: [lago-basic-suite-master-host-0], timeElapsed: 18ms
> 2018-02-12 07:20:17,201-05 DEBUG
> [org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
> (default task-9) [ebedf4a6-07be-45b3-9062-7996c362f747] method:
> getAllForHostname, params: [lago-basic-suite-master-host-0], timeElapsed:
> 17ms
> 2018-02-12 07:20:17,220-05 DEBUG
> [org.ovirt.engine.core.uutils.ssh.SSHClient] (default task-9)
> [ebedf4a6-07be-45b3-9062-7996c362f747] Connecting
> 'root at lago-basic-suite-master-host-0'
> 2018-02-12 07:20:17,414-05 DEBUG
> [org.ovirt.engine.core.uutils.ssh.SSHClient] (default task-9)
> [ebedf4a6-07be-45b3-9062-7996c362f747] Connected:
> 'root at lago-basic-suite-master-host-0'
> 2018-02-12 07:20:17,427-05 DEBUG
> [org.ovirt.engine.core.uutils.ssh.SSHClient] (default task-9)
> [ebedf4a6-07be-45b3-9062-7996c362f747] Authenticating:
> 'root at lago-basic-suite-master-host-0'
> 2018-02-12 07:20:17,490-05 DEBUG
> [org.ovirt.engine.core.uutils.ssh.SSHClient] (default task-9)
> [ebedf4a6-07be-45b3-9062-7996c362f747] Authenticated:
> 'root at lago-basic-suite-master-host-0'
> 2018-02-12 07:20:18,247-05 INFO
> [org.ovirt.engine.core.vdsbroker.RemoveVdsVDSCommand] (default task-9)
> [21f04b96] START, RemoveVdsVDSCommand(HostName =
> lago-basic-suite-master-host-0,
> RemoveVdsVDSCommandParameters:{hostId='468d8314-e2e0-416b-af9d-295f8ab5a522'}),
> log id: 9f1017d
> 2018-02-12 07:20:18,262-05 INFO
> [org.ovirt.engine.core.vdsbroker.AddVdsVDSCommand] (default task-9)
> [21f04b96] START, AddVdsVDSCommand(HostName =
> lago-basic-suite-master-host-0,
> AddVdsVDSCommandParameters:{hostId='468d8314-e2e0-416b-af9d-295f8ab5a522'}),
> log id: a336fc4
> 2018-02-12 07:20:18,288-05 INFO
> [org.ovirt.engine.core.vdsbroker.VdsManager] (default task-9) [21f04b96]
> Initialize vdsBroker 'lago-basic-suite-master-host-0:54321'
> 2018-02-12 07:20:18,345-05 DEBUG
> [org.ovirt.engine.core.vdsbroker.ResourceManager] (default task-9)
> [21f04b96] subscribe called with subscription id:
> lago-basic-suite-master-host-0|*|VM_status|*
> 2018-02-12 07:20:18,346-05 DEBUG
> [org.ovirt.engine.core.vdsbroker.ResourceManager] (default task-9)
> [21f04b96] subscribe called with subscription id:
> lago-basic-suite-master-host-0|net|host_conn|no_id
> 2018-02-12 07:20:18,369-05 WARN
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (default task-9) [21f04b96] EVENT_ID:
> VDS_ALERT_FENCE_IS_NOT_CONFIGURED(9,000), Failed to verify Power Management
> configuration for Host lago-basic-suite-master-host-0.
> 2018-02-12 07:20:18,398-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (default task-9) [21f04b96] EVENT_ID: USER_ADD_VDS(42), Host
> lago-basic-suite-master-host-0 was added by admin at internal-authz.
> 2018-02-12 07:20:18,486-05 INFO
> [org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] Before Installation
> host 468d8314-e2e0-416b-af9d-295f8ab5a522, lago-basic-suite-masterhost-0
> 2018-02-12 07:20:18,549-05 INFO
> [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] START,
> SetVdsStatusVDSCommand(HostName = lago-basic-suite-master-host-0,
> SetVdsStatusVDSCommandParameters:{hostId='468d8314-e2e0-416b-af9d-295f8ab5a522',
> status='Installing', nonOperationalReason='NONE',
> stopSpmFailureLogged='false', maintenanceReason='null'}), log id: 4a95e559
> 2018-02-12 07:20:18,567-05 DEBUG
> [org.ovirt.engine.core.uutils.ssh.SSHDialog]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] connect enter
> (lago-basic-suite-master-host-0:22, 1800000, 600000)
> 2018-02-12 07:20:18,567-05 DEBUG
> [org.ovirt.engine.core.uutils.ssh.SSHClient]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] Connecting
> 'root at lago-basic-suite-master-host-0'
> 2018-02-12 07:20:18,751-05 DEBUG
> [org.ovirt.engine.core.uutils.ssh.SSHClient]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] Connected:
> 'root at lago-basic-suite-master-host-0'
> 2018-02-12 07:20:18,767-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] EVENT_ID:
> VDS_INSTALL_IN_PROGRESS(509), Installing Host
> lago-basic-suite-master-host-0. Connected to host
> lago-basic-suite-master-host-0 with SSH key fingerprint:
> SHA256:efkJTmSmltPF5S4VbnQ1avsb7whAX0dgLgxZJTxFgqo.
> 2018-02-12 07:20:18,767-05 DEBUG
> [org.ovirt.engine.core.uutils.ssh.SSHClient]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] Authenticating:
> 'root at lago-basic-suite-master-host-0'
> 2018-02-12 07:20:18,835-05 DEBUG
> [org.ovirt.engine.core.uutils.ssh.SSHClient]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] Authenticated:
> 'root at lago-basic-suite-master-host-0'
> 2018-02-12 07:20:18,835-05 INFO
> [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] Installation of
> lago-basic-suite-master-host-0. Executing command via SSH umask 0077;
> MYTMP="$(TMPDIR="${OVIRT_TMPDIR}" mktemp -d -t ovirt-XXXXXXXXXX)"; trap
> "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" >
> /dev/null 2>&1" 0; tar --warning=no-timestamp -C "${MYTMP}" -x &&
> "${MYTMP}"/ovirt-host-deploy DIALOG/dialect=str:machine
> DIALOG/customization=bool:True <
> /var/cache/ovirt-engine/ovirt-host-deploy.tar
> 2018-02-12 07:20:18,888-05 INFO
> [org.ovirt.engine.core.uutils.ssh.SSHDialog]
> (EE-ManagedThreadFactory-engine-Thread-1) [7389a3fe] SSH execute
> 'root at lago-basic-suite-master-host-0' 'umask 0077;
> MYTMP="$(TMPDIR="${OVIRT_TMPDIR}" mktemp -d -t ovirt-XXXXXXXXXX)"; trap
> "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" >
> /dev/null 2>&1" 0; tar --warning=no-timestamp -C "${MYTMP}" -x &&
> "${MYTMP}"/ovirt-host-deploy DIALOG/dialect=str:machine
> DIALOG/customization=bool:True'
> 2018-02-12 07:20:19,933-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Initializing.
> 2018-02-12 07:20:20,094-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Environment setup.
> 2018-02-12 07:20:20,112-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Environment packages setup.
> 2018-02-12 07:20:24,084-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Programs detection.
> 2018-02-12 07:20:24,199-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Environment setup.
> 2018-02-12 07:20:24,205-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Environment customization.
> 2018-02-12 07:20:24,617-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Kdump supported.
> 2018-02-12 07:20:24,775-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Logs at host located at:
> '/tmp/ovirt-host-deploy-20180212072019-56s96x.log'.
> 2018-02-12 07:20:24,890-05 INFO
> [org.ovirt.engine.core.bll.hostdeploy.VdsDeployVdsmUnit] (VdsDeploy)
> [7389a3fe] Host lago-basic-suite-master-host-0 reports unique id
> A29E23CD-AF59-423B-9FCB-D3E4A0CD6AA1
> 2018-02-12 07:20:24,908-05 INFO
> [org.ovirt.engine.core.bll.hostdeploy.VdsDeployVdsmUnit] (VdsDeploy)
> [7389a3fe] Assigning unique id A29E23CD-AF59-423B-9FCB-D3E4A0CD6AA1 to Host
> lago-basic-suite-master-host-0
> 2018-02-12 07:20:24,987-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Disabling Kdump integration.
> 2018-02-12 07:20:25,070-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Setup validation.
> 2018-02-12 07:20:25,280-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Hardware supports virtualization.
> 2018-02-12 07:20:25,383-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Transaction setup.
> 2018-02-12 07:20:25,429-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Misc configuration.
> 2018-02-12 07:20:25,433-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Package installation.
> 2018-02-12 07:20:27,065-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Yum Status: Downloading Packages.
> 2018-02-12 07:20:27,069-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Yum Download/Verify:
> tuned-2.8.0-5.el7_4.2.noarch.
> 2018-02-12 07:20:27,074-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Yum Status: Check Package Signatures.
> 2018-02-12 07:20:27,078-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Yum Status: Running Test Transaction.
> 2018-02-12 07:20:27,192-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Yum Status: Running Transaction.
> 2018-02-12 07:20:27,309-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Yum update: 1/2:
> tuned-2.8.0-5.el7_4.2.noarch.
> 2018-02-12 07:20:27,524-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Yum updated: 2/2: tuned.
> 2018-02-12 07:20:29,174-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Yum Verify: 1/2: tuned.noarch
> 0:2.8.0-5.el7_4.2 - u.
> 2018-02-12 07:20:29,182-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Yum Verify: 2/2: tuned.noarch
> 0:2.8.0-5.el7 - ud.
> 2018-02-12 07:20:29,266-05 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (VdsDeploy) [7389a3fe] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing
> Host lago-basic-suite-master-host-0. Stage: Misc configuration.
>
> </error>
>
>

-- 
Didi