Description of problem: there's something strange going on with host-deploy and rhel6 hosts in _3.5_ cluster level because host-deploy initiated by host-update-manager checks for dnf. --->%--- Oct 7, 2015 11:38:00 AM Failed to check for available updates on host host.example.com with message 'Command returned failure code 1 during SSH session 'root.com ---<%--- --->%--- 2015-10-07 11:50:06 DEBUG otopi.context context._executeMethod:142 Stage boot METHOD otopi.plugins.otopi.packagers.yumpackager.Plugin._boot Loaded plugins: product-id 2015-10-07 11:50:07 DEBUG otopi.context context.dumpEnvironment:500 ENVIRONMENT DUMP - BEGIN 2015-10-07 11:50:07 DEBUG otopi.context context.dumpEnvironment:510 ENV PACKAGER/keepAliveInterval=int:'30' 2015-10-07 11:50:07 DEBUG otopi.context context.dumpEnvironment:510 ENV PACKAGER/yumDisabledPlugins=list:'[]' 2015-10-07 11:50:07 DEBUG otopi.context context.dumpEnvironment:510 ENV PACKAGER/yumEnabledPlugins=list:'[]' 2015-10-07 11:50:07 DEBUG otopi.context context.dumpEnvironment:510 ENV PACKAGER/yumExpireCache=bool:'True' 2015-10-07 11:50:07 DEBUG otopi.context context.dumpEnvironment:510 ENV PACKAGER/yumRollback=bool:'True' 2015-10-07 11:50:07 DEBUG otopi.context context.dumpEnvironment:510 ENV PACKAGER/yumpackagerEnabled=bool:'True' 2015-10-07 11:50:07 DEBUG otopi.context context.dumpEnvironment:514 ENVIRONMENT DUMP - END 2015-10-07 11:50:07 DEBUG otopi.context context._executeMethod:142 Stage boot METHOD otopi.plugins.otopi.system.info.Plugin._init 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.system.info info._init:51 SYSTEM INFORMATION - BEGIN 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.system.info info._init:52 executable /usr/bin/python 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.system.info info._init:53 python /usr/bin/python 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.system.info info._init:54 platform linux2 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.system.info info._init:55 distribution ('Red Hat Enterprise Linux Server', '6.7', 'Santiago') 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.system.info info._init:56 host 'host.example.com 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.system.info info._init:62 uid 0 euid 0 gid 0 egid 0 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.system.info info._init:64 SYSTEM INFORMATION - END 2015-10-07 11:50:07 DEBUG otopi.context context._executeMethod:142 Stage boot METHOD otopi.plugins.otopi.packagers.dnfpackager.Plugin._boot 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.packagers.dnfpackager dnfpackager._boot:178 Cannot initialize minidnf Traceback (most recent call last): File "/tmp/ovirt-rSbhnv7AO1/otopi-plugins/otopi/packagers/dnfpackager.py", line 165, in _boot constants.PackEnv.DNF_DISABLED_PLUGINS File "/tmp/ovirt-rSbhnv7AO1/otopi-plugins/otopi/packagers/dnfpackager.py", line 75, in _getMiniDNF from otopi import minidnf File "/tmp/ovirt-rSbhnv7AO1/pythonlib/otopi/minidnf.py", line 9, in <module> import dnf ImportError: No module named dnf ---<%--- Version-Release number of selected component (if applicable): ovirt-host-deploy-1.4.0-0.0.5.master.el6ev.noarch How reproducible: 100% Steps to Reproduce: 1. 3.6 engine + 3.5 clstr + rhel6.7 host in 3.5 clstr 2. wait for host-update-manager to fire host-deploy to check for available updates (engine-config -s HostPackagesUpdateTimeInHours=0.1 if you are not patient) 3. wait and see what appears in Events and host-deploy log for your host Actual results: failed event (see above) and failure to import dnf on rhel6 host (causing failed event?) Expected results: silenzio or show available packages Additional info:
*** Bug 1269425 has been marked as a duplicate of this bug. ***
yum is being registered: --- 2015-10-07 11:50:07 DEBUG otopi.plugins.otopi.packagers.yumpackager yumpackager._init:209 Registering yum packager --- no errors of operation: --- 2015-10-07 11:50:10 DEBUG otopi.context context.dumpEnvironment:510 ENV BASE/aborted=bool:'False' 2015-10-07 11:50:10 DEBUG otopi.context context.dumpEnvironment:510 ENV BASE/error=bool:'False' 2015-10-07 11:50:10 DEBUG otopi.context context.dumpEnvironment:510 ENV ODEPLOY/installIncomplete=bool:'False' --- please provide engine log of this session.
seems like PEBKAC, another yum copy running. if i am right, please close as not bug (i can't reproduce anymore, so i guess there was some yum "hanged"). 2015-10-07 11:37:59,382 INFO [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase] (DefaultQuartzScheduler_Worker-51) [1535a78c] Installation of srv-02.rhev.lab.eng.brq.redhat.com. 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-mgmt DIALOG/dialect=str:machine DIALOG/customization=bool:True < /var/cache/ovirt-engine/ovirt-host-deploy.tar 2015-10-07 11:37:59,382 INFO [org.ovirt.engine.core.utils.archivers.tar.CachedTar] (DefaultQuartzScheduler_Worker-51) [1535a78c] Tarball '/var/cache/ovirt-engine/ovirt-host-deploy.tar' refresh 2015-10-07 11:37:59,444 INFO [org.ovirt.engine.core.uutils.ssh.SSHDialog] (DefaultQuartzScheduler_Worker-51) [1535a78c] SSH execute 'root.lab.eng.brq.redhat.com' '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-mgmt D IALOG/dialect=str:machine DIALOG/customization=bool:True' 2015-10-07 11:38:00,633 INFO [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase] (VdsDeploy) [1535a78c] Stage: Initializing 2015-10-07 11:38:00,648 INFO [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase] (VdsDeploy) [1535a78c] Stage: Environment setup 2015-10-07 11:38:00,668 ERROR [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase] (VdsDeploy) [1535a78c] Failed to execute stage 'Environment setup': Existing lock /var/run/yum.pid: another copy is running as pi d 11570. 2015-10-07 11:38:00,669 INFO [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase] (VdsDeploy) [1535a78c] Stage: Pre-termination 2015-10-07 11:38:00,692 INFO [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase] (VdsDeploy) [1535a78c] Retrieving installation logs to: '/var/log/ovirt-engine/host-deploy/ovirt-host-mgmt-20151007113800-srv-02. rhev.lab.eng.brq.redhat.com-1535a78c.log' 2015-10-07 11:38:00,784 INFO [org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase] (VdsDeploy) [1535a78c] Stage: Termination 2015-10-07 11:38:00,854 ERROR [org.ovirt.engine.core.uutils.ssh.SSHDialog] (DefaultQuartzScheduler_Worker-51) [1535a78c] SSH error running command root.lab.eng.brq.redhat.com:'umask 0077; MYTMP="$(TMP DIR="${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-mgmt DIALOG/dialect=str:machine DIALOG/customization=bool:True': Command returned failure code 1 during SSH session 'root.lab.eng.brq.redhat.com' 2015-10-07 11:38:00,854 ERROR [org.ovirt.engine.core.uutils.ssh.SSHDialog] (DefaultQuartzScheduler_Worker-51) [1535a78c] Exception: java.io.IOException: Command returned failure code 1 during SSH session 'root@sr v-02.rhev.lab.eng.brq.redhat.com' at org.ovirt.engine.core.uutils.ssh.SSHClient.executeCommand(SSHClient.java:527) [uutils.jar:] at org.ovirt.engine.core.uutils.ssh.SSHDialog.executeCommand(SSHDialog.java:312) [uutils.jar:] at org.ovirt.engine.core.bll.hostdeploy.VdsDeployBase.execute(VdsDeployBase.java:567) [bll.jar:] at org.ovirt.engine.core.bll.host.HostUpgradeManager.isUpdateAvailable(HostUpgradeManager.java:38) [bll.jar:] at org.ovirt.engine.core.bll.host.AvailableUpdatesFinder.isUpdateAvailable(AvailableUpdatesFinder.java:24) [bll.jar:] at org.ovirt.engine.core.bll.VdsEventListener.isUpdateAvailable(VdsEventListener.java:548) [bll.jar:] at org.ovirt.engine.core.vdsbroker.ResourceManager.isUpdateAvailable(ResourceManager.java:526) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.VdsManager.availableUpdates(VdsManager.java:295) [vdsbroker.jar:] at sun.reflect.GeneratedMethodAccessor142.invoke(Unknown Source) [:1.8.0_51] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_51] at java.lang.reflect.Method.invoke(Method.java:497) [rt.jar:1.8.0_51] at org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81) [scheduler.jar:] at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52) [scheduler.jar:] at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz.jar:] at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz.jar:]