Bug 886605

Summary: [rhevm-upgrade] cannot add host to RHEVM after upgrade -> Failure details: SSH could not receive file
Product: Red Hat Enterprise Virtualization Manager Reporter: Martin Pavlik <mpavlik>
Component: ovirt-engineAssignee: Eli Mesika <emesika>
Status: CLOSED CURRENTRELEASE QA Contact: Martin Pavlik <mpavlik>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 3.1.0CC: acathrow, alonbl, alourie, amureini, bazulay, cpelland, dyasny, iheim, lpeer, mgoldboi, Rhev-m-bugs, sgrinber, yeylon, ykaul
Target Milestone: ---Keywords: Regression, ZStream
Target Release: 3.1.1   
Hardware: x86_64   
OS: Linux   
Whiteboard: infra
Fixed In Version: si25.2 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-02-24 13:36:17 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:
Bug Depends On:    
Bug Blocks: 880665, 884640    
Attachments:
Description Flags
logs from host tmp dir
none
logs from host /var/log dir
none
log_collector none

Description Martin Pavlik 2012-12-12 16:32:06 UTC
Created attachment 662451 [details]
logs from host tmp dir

Description of problem:
It is not possible to add host to rhevm setup after management upgrade. Installation of the host fails with following error in logs

2012-12-12 17:15:22,488 ERROR [org.ovirt.engine.core.bll.VdsInstaller] (pool-3-thread-9) [3bd6432d] Installation of 10.34.66.81 has failed. Failure details: SSH could not receive file 10.34.66.81:'/tmp/cert_56ca073b-351d-4813-8fee-1b41cab63914.req': '/etc/pki/rhevm/requests/cert_56ca073b-351d-4813-8fee-1b41cab63914.req'. (Stage: Downloading certificate request from Host)



Problem appears for RHEL and for RHEVH

Version-Release number of selected component (if applicable):
Red Hat Enterprise Virtualization Manager Version: 3.1.0-33.el6ev 

host:
libvirt-0.9.10-21.el6_3.6.x86_64
qemu-img-rhev-0.12.1.2-2.295.el6_3.8.x86_64
vdsm-4.9.6-44.2.el6_3.x86_64


How reproducible:
100%

Steps to Reproduce:
1. upgrade rhevm from ic158.2 to si 25.1
2. add host into setup

  
Actual results:
host installation fails

Expected results:
successful host installation

Additional info:

File exists on host
-rw-------. 1 root root 911 Dec 12 17:15 /tmp/cert_56ca073b-351d-4813-8fee-1b41cab63914.req


engine.log
2012-12-12 17:15:22,487 ERROR [org.ovirt.engine.core.utils.hostinstall.VdsInstallerSSH] (pool-3-thread-9) SSH could not receive file 10.34.66.81:'/tmp/cert_56ca073b-351d-4813-8fee-1b41cab63914.req': '/etc/pki/rhevm/requests/cert_56ca073b-351d-4813-8fee-1b41cab63914.req': java.io.FileNotFoundException: /etc/pki/rhevm/requests/cert_56ca073b-351d-4813-8fee-1b41cab63914.req (No such file or directory)
	at java.io.FileOutputStream.open(Native Method) [rt.jar:1.7.0_09-icedtea]
	at java.io.FileOutputStream.<init>(FileOutputStream.java:212) [rt.jar:1.7.0_09-icedtea]
	at java.io.FileOutputStream.<init>(FileOutputStream.java:104) [rt.jar:1.7.0_09-icedtea]
	at org.ovirt.engine.core.utils.ssh.SSHClient.receiveFile(SSHClient.java:609) [engine-utils.jar:]
	at org.ovirt.engine.core.utils.hostinstall.VdsInstallerSSH.receiveFile(VdsInstallerSSH.java:436) [engine-utils.jar:]
	at org.ovirt.engine.core.bll.VdsInstaller.RunStage(VdsInstaller.java:347) [engine-bll.jar:]
	at org.ovirt.engine.core.bll.VdsInstaller.Install(VdsInstaller.java:280) [engine-bll.jar:]
	at org.ovirt.engine.core.bll.InstallVdsCommand.executeCommand(InstallVdsCommand.java:110) [engine-bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:876) [engine-bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:973) [engine-bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1372) [engine-bll.jar:]
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:168) [engine-utils.jar:]
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:107) [engine-utils.jar:]
	at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:991) [engine-bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:291) [engine-bll.jar:]
	at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:351) [engine-bll.jar:]
	at org.ovirt.engine.core.bll.Backend.runInternalAction(Backend.java:597) [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-3]
	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-3]
	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-3]
	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:53) [jboss-as-ee.jar:7.1.3.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
	at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53) [jboss-as-ejb3.jar:7.1.3.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:209) [jboss-as-ejb3.jar:7.1.3.Final-redhat-3]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:361) [jboss-as-ejb3.jar:7.1.3.Final-redhat-3]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:192) [jboss-as-ejb3.jar:7.1.3.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3.jar:7.1.3.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
	at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:42) [jboss-as-ejb3.jar:7.1.3.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
	at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3.jar:7.1.3.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee.jar:7.1.3.Final-redhat-3]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
	at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee.jar:7.1.3.Final-redhat-3]
	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.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee.jar:7.1.3.Final-redhat-3]
	at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:181) [jboss-as-ee.jar:7.1.3.Final-redhat-3]
	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.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee.jar:7.1.3.Final-redhat-3]
	at org.ovirt.engine.core.bll.interfaces.BackendInternal$$$view9.runInternalAction(Unknown Source) [engine-bll.jar:]
	at org.ovirt.engine.core.bll.AddVdsCommand$3.run(AddVdsCommand.java:156) [engine-bll.jar:]
	at org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil$InternalWrapperRunnable.run(ThreadPoolUtil.java:64) [engine-utils.jar:]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_09-icedtea]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.7.0_09-icedtea]
	at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.7.0_09-icedtea]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) [rt.jar:1.7.0_09-icedtea]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [rt.jar:1.7.0_09-icedtea]
	at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_09-icedtea]

Comment 1 Martin Pavlik 2012-12-12 16:34:47 UTC
Created attachment 662452 [details]
logs from host /var/log dir

Comment 2 Martin Pavlik 2012-12-12 16:35:13 UTC
Created attachment 662453 [details]
log_collector

Comment 5 Alon Bar-Lev 2012-12-12 22:18:06 UTC
Engine runs as non root, so it cannot write over this file because of its ownership.
Please remove the file and try again.

Question is how we got this file owned by root?

Comment 6 Alon Bar-Lev 2012-12-12 22:20:08 UTC
Oh... sorry!
I was confused by the "Host" term.

Can you please attach the output of:
# ls -lR /etc/pki/ovirt-engine

Comment 8 Martin Pavlik 2012-12-13 06:13:40 UTC
(In reply to comment #6)
> Oh... sorry!
> I was confused by the "Host" term.
> 
> Can you please attach the output of:
> # ls -lR /etc/pki/ovirt-engine

[root@mp-rhevm30 ~]# ls -lR /etc/pki/ovirt-engine
/etc/pki/ovirt-engine:
total 84
-rw-r--r--. 1 ovirt ovirt  482 Dec 10 18:35 cacert.template
-rwxr-x---. 1 ovirt ovirt 3524 Oct 26 09:16 ca.pem
drwxr-xr-x. 2 ovirt ovirt 4096 Dec 12 16:19 certs
-rw-r--r--. 1 ovirt ovirt  534 Dec 10 18:35 cert.template
-rwxr-xr-x. 1 ovirt ovirt 1037 Dec 10 18:35 CreateCA.sh
-rwxr-xr-x. 1 ovirt ovirt  928 Dec 10 18:35 CreateKStore.sh
-rwxr-xr-x. 1 ovirt ovirt 1020 Dec 10 18:35 CreatePem.sh
-rwxr-xr-x. 1 ovirt ovirt 1106 Dec 10 18:35 CreateReq.sh
-rw-r--r--. 1 ovirt ovirt    0 Dec 10 18:35 database.txt
-rwxr-xr-x. 1 ovirt ovirt 1080 Dec 10 18:35 encryptpasswd.sh
-rwxr-xr-x. 1 ovirt ovirt  708 Dec 10 18:35 exportK2SSH.sh
-rwxr-xr-x. 1 ovirt ovirt 1965 Dec 10 18:35 generate-ssh-keys
-rwxr-xr-x. 1 ovirt ovirt  665 Dec 10 18:35 importToKeyStore.sh
-rwxr-xr-x. 1 root  root  3036 Dec 10 18:35 installCA_dev.sh
-rwxr-xr-x. 1 ovirt ovirt 2405 Dec 10 18:35 installCA.sh
drwxr-xr-x. 2 ovirt ovirt 4096 Dec 12 16:19 keys
-rw-r--r--. 1 ovirt ovirt  637 Dec 10 18:35 openssl.conf
drwxr-x---. 2 ovirt ovirt 4096 Oct 26 09:16 private
drwxr-xr-x. 2 ovirt ovirt 4096 Dec 12 16:19 requests
-rw-r--r--. 1 ovirt ovirt    3 Oct 26 09:16 serial.txt
-rwxr-xr-x. 1 ovirt ovirt 2543 Dec 10 18:35 SignReq.sh
-rwxr-xr-x. 1 ovirt ovirt 3259 Dec 10 18:35 store-utils.sh

/etc/pki/ovirt-engine/certs:
total 20
-rw-r--r--. 1 root  root  3524 Oct 26 09:16 01.pem
-rw-r--r--. 1 root  root  3666 Oct 26 09:16 02.pem
-rw-r--r--. 1 root  root   833 Oct 26 09:16 ca.der
-rwxr-xr-x. 1 ovirt ovirt    0 Oct 24 22:02 emptyfile.txt
-rw-r--r--. 1 root  root  3666 Oct 26 09:16 engine.cer
-rw-r--r--. 1 root  root   852 Oct 26 09:16 engine.der

/etc/pki/ovirt-engine/keys:
total 8
-rwxr-xr-x. 1 ovirt ovirt   0 Oct 24 22:02 emptyfile.txt
-rw-------. 1 root  root  916 Oct 26 09:16 engine_id_rsa
-rw-r--r--. 1 root  root  219 Oct 26 09:16 engine.ssh.key.txt

/etc/pki/ovirt-engine/private:
total 4
-rwxr-x---. 1 ovirt ovirt 887 Oct 26 09:16 ca.pem
-rwxr-xr-x. 1 ovirt ovirt   0 Oct 24 22:02 emptyfile.txt

/etc/pki/ovirt-engine/requests:
total 8
-rw-r--r--. 1 root  root  623 Oct 26 09:16 ca.csr
-rwxr-xr-x. 1 ovirt ovirt   0 Oct 24 22:02 emptyfile.txt
-rw-r--r--. 1 root  root  617 Oct 26 09:16 engine.req

Comment 9 Alon Bar-Lev 2012-12-13 10:35:15 UTC
OK, thanks!

I guess the output of:
# engine-config --get CABaseDirectory 

Is /etc/pki/rhevm and not /etc/pki/ovirt-engine.

Moran,

1. The permissions of the /etc/pki/ovirt-engine do not match these of vanilla 3.1 installation, in this case it was not the problem, but please consider to sync.

2. The CABaseDirectory configuration should be modified.

I suggest to simply diff 'ls -laR' of upgraded machine and vanilla machine to find issues.

I also suggest to diff exported database of upgraded machine and vanilla machine to find issues.

Comment 10 Moran Goldboim 2012-12-13 11:49:42 UTC
(In reply to comment #9)
> OK, thanks!
> 
> I guess the output of:
> # engine-config --get CABaseDirectory 
> 
> Is /etc/pki/rhevm and not /etc/pki/ovirt-engine.
> 
> Moran,
> 
> 1. The permissions of the /etc/pki/ovirt-engine do not match these of
> vanilla 3.1 installation, in this case it was not the problem, but please
> consider to sync.
> 
> 2. The CABaseDirectory configuration should be modified.
> 
> I suggest to simply diff 'ls -laR' of upgraded machine and vanilla machine
> to find issues.
> 
> I also suggest to diff exported database of upgraded machine and vanilla
> machine to find issues.

we'll check your comments about directory permissions, but the root cause of the bug is that we can't configure CABaseDirectory any more, and this should be addressed as as part of https://gerrit.eng.lab.tlv.redhat.com/#/c/3550/

Comment 17 Eli Mesika 2012-12-15 19:53:41 UTC
https://gerrit.eng.lab.tlv.redhat.com/#/c/3757/

Comment 23 Martin Pavlik 2012-12-20 15:51:15 UTC
works on si25.2 with RHEV Hypervisor - 6.3 - 20121212.0.el6_3