Bug 889856

Summary: host-deploy: improve of deploy events and logs
Product: Red Hat Enterprise Virtualization Manager Reporter: Dafna Ron <dron>
Component: ovirt-engineAssignee: Alon Bar-Lev <alonbl>
Status: CLOSED NOTABUG QA Contact: Haim <hateya>
Severity: high Docs Contact:
Priority: unspecified    
Version: 3.2.0CC: bazulay, dougsland, dyasny, iheim, lpeer, Rhev-m-bugs, sgrinber, yeylon, ykaul
Target Milestone: ---Keywords: Improvement
Target Release: 3.2.0   
Hardware: x86_64   
OS: Linux   
Whiteboard: infra
Fixed In Version: Doc Type: Enhancement
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-01-01 10:19:44 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
log none

Description Dafna Ron 2012-12-23 16:42:09 UTC
Created attachment 668065 [details]
log

Description of problem:

we are getting a long error in engine log with java.io.IOException when host fails install due to dependencies. 

Version-Release number of selected component (if applicable):

sf1

How reproducible:

100%

Steps to Reproduce:
1. upgrade a host from rhel6.3 to 6.4 after removing qemu
2. install the host in rhevm  
3.
  
Actual results:

we get java.io.IOException in engine log

Expected results:

it would be helpful to clean the log and create user friendly error messages for failure of install. 

Additional info: full log attached 

2012-12-23 17:50:48,582 INFO  [org.ovirt.engine.core.bll.InstallerMessages] (VdsDeploy) Installation gold-vdsc.qa.lab.tlv.redhat.com: Stage: Termination
2012-12-23 17:50:48,700 ERROR [org.ovirt.engine.core.utils.ssh.SSHDialog] (pool-3-thread-8) SSH error running command root.lab.tlv.redhat.com:'umask 0077; MYTMP="$(mktemp -t ovirt-XXXXXXXXXX)"; trap "chmod -R u+rwX \"${MYTMP}\" > /dev/null 2>&1; rm -fr \"${MYTMP}\" > /dev/null 2>&1" 0; rm -fr "${MYTMP}" && mkdir "${MYTMP}" && python -c "import sys, tarfile; tarfile.open(fileobj=sys.stdin, mode='r|').extractall(path='${MYTMP}')" &&  "${MYTMP}"/setup DIALOG/dialect=str:machine DIALOG/customization=bool:True': java.io.IOException: Command returned failure code 1 during SSH session 'root.lab.tlv.redhat.com'
        at org.ovirt.engine.core.utils.ssh.SSHClient.executeCommand(SSHClient.java:506) [engine-utils.jar:]
        at org.ovirt.engine.core.utils.ssh.SSHDialog.executeCommand(SSHDialog.java:308) [engine-utils.jar:]
        at org.ovirt.engine.core.bll.VdsDeploy.execute(VdsDeploy.java:908) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.InstallVdsCommand.executeCommand(InstallVdsCommand.java:162) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:990) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1075) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1456) [engine-bll.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:166) [engine-utils.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:108) [engine-utils.jar:]
        at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1093) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:295) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:350) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runInternalAction(Backend.java:555) [engine-bll.jar:]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_09-icedtea]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_09-icedtea]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_09-icedtea]
        at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_09-icedtea]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:36) [jboss-as-ee.jar:7.1.3.Final-redhat-4]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [jboss-as-ejb3.jar:7.1.3.Final-redhat-4]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java

Comment 1 Yaniv Kaul 2012-12-23 16:50:03 UTC
Should probably also catch the exception.

Comment 2 Alon Bar-Lev 2012-12-23 17:01:22 UTC
First, lets agree that this is the same behavior of 3.1.
Please try and see what happens if there is invalid dependency in yum.

After we agree, and set this as Improvement we can discuss how to improve.

Some facts...

1. The error printed in comment#0 will be issue if there is *ANY* error, as script exists with non zero exit code. This is printed in engine log just like any other exception.

2. The error logs from the deployment is printed in:

a. event log (user visible).

b. engine.log (GSS/QE visible).

c. ovirt-host-deploy*.log (GSS/QE visible).

3. The engine.log was never meant to be used as logs for users, there is too much noise there, so the log usage of the deploy process is no exception.

What we can improve:

1. Keep deploy error logs in memory during deploy process, reprint them when deploy ends for both event log and engine.log.

2. Issue a new engine.log that targets users, and use it project wide, removing all exceptions etc from this log.

Comment 10 Barak 2013-01-01 10:19:44 UTC
This is no different than general way we handle the engine log, therefore host deploy is no different.

moving this BZ to CLOSE NOTABUG till we get proper general requirements for logging in the engine side.