Attachment 933323 Details for Bug 1135987 – engine log

engine log

engine.log (text/plain), 104.33 KB, created by Maor on 2014-09-01 12:09:10 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Maor

Created: 2014-09-01 12:09:10 UTC

Size: 104.33 KB

patch

obsolete

>2014-09-01 14:57:35,844 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Loaded file "/home/mlipchuk/ovirt-share/share/ovirt-engine/services/ovirt-engine/ovirt-engine.conf".
>2014-09-01 14:57:35,849 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) The file "/home/mlipchuk/ovirt-share/etc/ovirt-engine/engine.conf" doesn't exist or isn't readable. Will return an empty set of properties.
>2014-09-01 14:57:35,850 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Loaded file "/home/mlipchuk/ovirt-share/etc/ovirt-engine/engine.conf.d/10-setup-database.conf".
>2014-09-01 14:57:35,850 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Loaded file "/home/mlipchuk/ovirt-share/etc/ovirt-engine/engine.conf.d/10-setup-jboss.conf".
>2014-09-01 14:57:35,852 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Loaded file "/home/mlipchuk/ovirt-share/etc/ovirt-engine/engine.conf.d/10-setup-pki.conf".
>2014-09-01 14:57:35,853 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Loaded file "/home/mlipchuk/ovirt-share/etc/ovirt-engine/engine.conf.d/10-setup-protocols.conf".
>2014-09-01 14:57:35,855 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_AJP_ENABLED" is "false".
>2014-09-01 14:57:35,855 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_AJP_PORT" is "None".
>2014-09-01 14:57:35,856 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_APPS" is "engine.ear restapi.war legacy_restapi.war".
>2014-09-01 14:57:35,856 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_CACHE" is "/home/mlipchuk/ovirt-share/var/cache/ovirt-engine".
>2014-09-01 14:57:35,858 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_CHECK_INTERVAL" is "1000".
>2014-09-01 14:57:35,859 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_CONNECTION_TIMEOUT" is "300000".
>2014-09-01 14:57:35,860 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_DATABASE" is "engine".
>2014-09-01 14:57:35,861 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_DRIVER" is "org.postgresql.Driver".
>2014-09-01 14:57:35,862 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_HOST" is "localhost".
>2014-09-01 14:57:35,862 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_MAX_CONNECTIONS" is "100".
>2014-09-01 14:57:35,863 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_MIN_CONNECTIONS" is "1".
>2014-09-01 14:57:35,864 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_PASSWORD" is "***".
>2014-09-01 14:57:35,865 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_PORT" is "5432".
>2014-09-01 14:57:35,867 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_SECURED" is "False".
>2014-09-01 14:57:35,867 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_SECURED_VALIDATION" is "False".
>2014-09-01 14:57:35,868 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_URL" is "jdbc:postgresql://localhost:5432/engine?sslfactory=org.postgresql.ssl.NonValidatingFactory".
>2014-09-01 14:57:35,869 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DB_USER" is "postgres".
>2014-09-01 14:57:35,871 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DEBUG_ADDRESS" is "127.0.0.1:8787".
>2014-09-01 14:57:35,878 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_DOC" is "/home/mlipchuk/ovirt-share/share/doc/ovirt-engine".
>2014-09-01 14:57:35,879 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_ETC" is "/home/mlipchuk/ovirt-share/etc/ovirt-engine".
>2014-09-01 14:57:35,879 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_EXTENSION_PATH" is "/home/mlipchuk/ovirt-share/share/ovirt-engine/extensions.d:/home/mlipchuk/ovirt-share/etc/ovirt-engine/extensions.d".
>2014-09-01 14:57:35,880 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_FQDN" is "localhost.localdomain".
>2014-09-01 14:57:35,884 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_GROUP" is "ovirt".
>2014-09-01 14:57:35,885 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_HEAP_MAX" is "1g".
>2014-09-01 14:57:35,885 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_HEAP_MIN" is "1g".
>2014-09-01 14:57:35,885 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_HTTPS_ENABLED" is "true".
>2014-09-01 14:57:35,886 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_HTTPS_PORT" is "8443".
>2014-09-01 14:57:35,886 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_HTTPS_PROTOCOLS" is "SSLv3,TLSv1,TLSv1.1,TLSv1.2".
>2014-09-01 14:57:35,887 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_HTTP_ENABLED" is "true".
>2014-09-01 14:57:35,887 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_HTTP_PORT" is "8080".
>2014-09-01 14:57:35,888 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_JAVA_MODULEPATH" is "/home/mlipchuk/ovirt-share/share/ovirt-engine/modules".
>2014-09-01 14:57:35,888 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_JVM_ARGS" is " -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath="/home/mlipchuk/ovirt-share/var/log/ovirt-engine/dump"".
>2014-09-01 14:57:35,889 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_LOG" is "/home/mlipchuk/ovirt-share/var/log/ovirt-engine".
>2014-09-01 14:57:35,889 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_LOG_TO_CONSOLE" is "true".
>2014-09-01 14:57:35,889 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_MANUAL" is "/home/mlipchuk/ovirt-share/share/ovirt-engine/manual".
>2014-09-01 14:57:35,890 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PERM_MAX" is "256m".
>2014-09-01 14:57:35,890 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PERM_MIN" is "256m".
>2014-09-01 14:57:35,891 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI" is "/home/mlipchuk/ovirt-share/etc/pki/ovirt-engine".
>2014-09-01 14:57:35,891 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI_CA" is "/home/mlipchuk/ovirt-share/etc/pki/ovirt-engine/ca.pem".
>2014-09-01 14:57:35,892 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI_ENGINE_CERT" is "/home/mlipchuk/ovirt-share/etc/pki/ovirt-engine/certs/engine.cer".
>2014-09-01 14:57:35,893 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI_ENGINE_STORE" is "/home/mlipchuk/ovirt-share/etc/pki/ovirt-engine/keys/engine.p12".
>2014-09-01 14:57:35,894 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI_ENGINE_STORE_ALIAS" is "1".
>2014-09-01 14:57:35,894 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI_ENGINE_STORE_PASSWORD" is "***".
>2014-09-01 14:57:35,895 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI_ENGINE_STORE_TYPE" is "PKCS12".
>2014-09-01 14:57:35,895 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI_TRUST_STORE" is "/home/mlipchuk/ovirt-share/etc/pki/ovirt-engine/.truststore".
>2014-09-01 14:57:35,896 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI_TRUST_STORE_PASSWORD" is "***".
>2014-09-01 14:57:35,896 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PKI_TRUST_STORE_TYPE" is "JKS".
>2014-09-01 14:57:35,897 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PROPERTIES" is " jsse.enableSNIExtension=false "java.security.krb5.conf=/home/mlipchuk/ovirt-share/etc/ovirt-engine/krb5.conf"".
>2014-09-01 14:57:35,897 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PROXY_ENABLED" is "false".
>2014-09-01 14:57:35,898 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PROXY_HTTPS_PORT" is "443".
>2014-09-01 14:57:35,898 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_PROXY_HTTP_PORT" is "80".
>2014-09-01 14:57:35,899 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_REPORTS_UI" is "/home/mlipchuk/ovirt-share/var/lib/ovirt-engine/reports.xml".
>2014-09-01 14:57:35,901 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_STOP_INTERVAL" is "1".
>2014-09-01 14:57:35,903 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_STOP_TIME" is "10".
>2014-09-01 14:57:35,904 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_TMP" is "/home/mlipchuk/ovirt-share/var/tmp/ovirt-engine".
>2014-09-01 14:57:35,905 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_UP_MARK" is "/home/mlipchuk/ovirt-share/var/lib/ovirt-engine/engine.up".
>2014-09-01 14:57:35,906 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_URI" is "/ovirt-engine".
>2014-09-01 14:57:35,907 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_USER" is "ovirt".
>2014-09-01 14:57:35,907 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_USR" is "/home/mlipchuk/ovirt-share/share/ovirt-engine".
>2014-09-01 14:57:35,908 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_VAR" is "/home/mlipchuk/ovirt-share/var/lib/ovirt-engine".
>2014-09-01 14:57:35,908 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "ENGINE_VERBOSE_GC" is "false".
>2014-09-01 14:57:35,909 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "JBOSS_HOME" is "/usr/share/jboss-as-7.1.1.Final".
>2014-09-01 14:57:35,909 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "JBOSS_RUNTIME" is "/home/mlipchuk/ovirt-share/var/lib/ovirt-engine/jboss_runtime".
>2014-09-01 14:57:35,910 INFO  [org.ovirt.engine.core.uutils.config.ShellLikeConfd] (MSC service thread 1-7) Value of property "SENSITIVE_KEYS" is ",ENGINE_DB_PASSWORD,ENGINE_PKI_TRUST_STORE_PASSWORD,ENGINE_PKI_ENGINE_STORE_PASSWORD".
>2014-09-01 14:57:36,159 INFO  [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Start initializing Backend
>2014-09-01 14:57:36,250 ERROR [org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils] (MSC service thread 1-2) Failed to decrypt value for property AdminPassword will be used encrypted value: javax.crypto.BadPaddingException: Data must start with zero
>	at sun.security.rsa.RSAPadding.unpadV15(RSAPadding.java:325) [rt.jar:1.7.0_45]
>	at sun.security.rsa.RSAPadding.unpad(RSAPadding.java:272) [rt.jar:1.7.0_45]
>	at com.sun.crypto.provider.RSACipher.doFinal(RSACipher.java:356)
>	at com.sun.crypto.provider.RSACipher.engineDoFinal(RSACipher.java:382)
>	at javax.crypto.Cipher.doFinal(Cipher.java:1922) [jce.jar:1.7.0_45]
>	at org.ovirt.engine.core.utils.crypt.EngineEncryptionUtils.decrypt(EngineEncryptionUtils.java:163) [utils.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.getValue(DBConfigUtils.java:112) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.updateOption(DBConfigUtils.java:263) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.refreshVdcOptionCache(DBConfigUtils.java:38) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.<init>(DBConfigUtils.java:171) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.<init>(DBConfigUtils.java:157) [dal.jar:]
>	at org.ovirt.engine.core.bll.Backend.initialize(Backend.java:187) [bll.jar:]
>	at org.ovirt.engine.core.bll.Backend.create(Backend.java:138) [bll.jar:]
>	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_45]
>	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_45]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_45]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_45]
>	at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptorFactory$ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptorFactory.java:130) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.weld.injection.WeldInjectionInterceptor.processInvocation(WeldInjectionInterceptor.java:73) [jboss-as-weld-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.ManagedReferenceInterceptorFactory$ManagedReferenceInterceptor.processInvocation(ManagedReferenceInterceptorFactory.java:95) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.ManagedReferenceInterceptorFactory$ManagedReferenceInterceptor.processInvocation(ManagedReferenceInterceptorFactory.java:95) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:228) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ejb3.tx.CMTTxInterceptor.requiresNew(CMTTxInterceptor.java:333) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ejb3.tx.SingletonLifecycleCMTTxInterceptor.processInvocation(SingletonLifecycleCMTTxInterceptor.java:56) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.BasicComponent.constructComponentInstance(BasicComponent.java:161) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ee.component.BasicComponent.createInstance(BasicComponent.java:85) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ejb3.component.singleton.SingletonComponent.getComponentInstance(SingletonComponent.java:116) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ejb3.component.singleton.SingletonComponent.start(SingletonComponent.java:130) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ee.component.ComponentStartService.start(ComponentStartService.java:44) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1811)
>	at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1746)
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_45]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_45]
>	at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_45]
>
>2014-09-01 14:57:36,326 ERROR [org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils] (MSC service thread 1-2) Failed to decrypt value for property LocalAdminPassword will be used encrypted value: javax.crypto.BadPaddingException: Data must start with zero
>	at sun.security.rsa.RSAPadding.unpadV15(RSAPadding.java:325) [rt.jar:1.7.0_45]
>	at sun.security.rsa.RSAPadding.unpad(RSAPadding.java:272) [rt.jar:1.7.0_45]
>	at com.sun.crypto.provider.RSACipher.doFinal(RSACipher.java:356)
>	at com.sun.crypto.provider.RSACipher.engineDoFinal(RSACipher.java:382)
>	at javax.crypto.Cipher.doFinal(Cipher.java:1922) [jce.jar:1.7.0_45]
>	at org.ovirt.engine.core.utils.crypt.EngineEncryptionUtils.decrypt(EngineEncryptionUtils.java:163) [utils.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.getValue(DBConfigUtils.java:112) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.updateOption(DBConfigUtils.java:263) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.refreshVdcOptionCache(DBConfigUtils.java:38) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.<init>(DBConfigUtils.java:171) [dal.jar:]
>	at org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils.<init>(DBConfigUtils.java:157) [dal.jar:]
>	at org.ovirt.engine.core.bll.Backend.initialize(Backend.java:187) [bll.jar:]
>	at org.ovirt.engine.core.bll.Backend.create(Backend.java:138) [bll.jar:]
>	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_45]
>	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_45]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_45]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_45]
>	at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptorFactory$ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptorFactory.java:130) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.weld.injection.WeldInjectionInterceptor.processInvocation(WeldInjectionInterceptor.java:73) [jboss-as-weld-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.ManagedReferenceInterceptorFactory$ManagedReferenceInterceptor.processInvocation(ManagedReferenceInterceptorFactory.java:95) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.ManagedReferenceInterceptorFactory$ManagedReferenceInterceptor.processInvocation(ManagedReferenceInterceptorFactory.java:95) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:228) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ejb3.tx.CMTTxInterceptor.requiresNew(CMTTxInterceptor.java:333) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ejb3.tx.SingletonLifecycleCMTTxInterceptor.processInvocation(SingletonLifecycleCMTTxInterceptor.java:56) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.1.Final.jar:1.1.1.Final]
>	at org.jboss.as.ee.component.BasicComponent.constructComponentInstance(BasicComponent.java:161) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ee.component.BasicComponent.createInstance(BasicComponent.java:85) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ejb3.component.singleton.SingletonComponent.getComponentInstance(SingletonComponent.java:116) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ejb3.component.singleton.SingletonComponent.start(SingletonComponent.java:130) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.as.ee.component.ComponentStartService.start(ComponentStartService.java:44) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final]
>	at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1811)
>	at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1746)
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_45]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_45]
>	at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_45]
>
>2014-09-01 14:57:36,360 ERROR [org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils] (MSC service thread 1-2) Could not parse option AutoRecoveryAllowedTypes value.
>2014-09-01 14:57:36,371 INFO  [org.ovirt.engine.core.utils.osinfo.OsInfoPreferencesLoader] (MSC service thread 1-2) Loaded file /home/mlipchuk/ovirt-share/etc/ovirt-engine/osinfo.conf.d/00-defaults.properties
>2014-09-01 14:57:36,454 INFO  [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Running ovirt-engine 3.5.0.0
>2014-09-01 14:57:36,454 INFO  [org.ovirt.engine.core.bll.CpuFlagsManagerHandler] (MSC service thread 1-2) Start initializing dictionaries
>2014-09-01 14:57:36,456 INFO  [org.ovirt.engine.core.bll.CpuFlagsManagerHandler] (MSC service thread 1-2) Finished initializing dictionaries
>2014-09-01 14:57:36,457 INFO  [org.ovirt.engine.core.bll.AuditLogCleanupManager] (MSC service thread 1-2) Start initializing AuditLogCleanupManager
>2014-09-01 14:57:36,457 INFO  [org.ovirt.engine.core.bll.AuditLogCleanupManager] (MSC service thread 1-2) Setting audit cleanup manager to run at: 35 35 3 * * ?
>2014-09-01 14:57:36,473 INFO  [org.ovirt.engine.core.bll.AuditLogCleanupManager] (MSC service thread 1-2) Finished initializing AuditLogCleanupManager
>2014-09-01 14:57:36,473 INFO  [org.ovirt.engine.core.bll.AuditLogCleanupManager] (MSC service thread 1-2) Start initializing CommandEntityCleanupManager
>2014-09-01 14:57:36,474 INFO  [org.ovirt.engine.core.bll.AuditLogCleanupManager] (MSC service thread 1-2) Setting command entity cleanup manager to run at: 35 35 3 * * ?
>2014-09-01 14:57:36,475 INFO  [org.ovirt.engine.core.bll.AuditLogCleanupManager] (MSC service thread 1-2) Finished initializing CommandEntityCleanupManager
>2014-09-01 14:57:36,477 INFO  [org.ovirt.engine.core.bll.TagsDirector] (MSC service thread 1-2) Start initializing TagsDirector
>2014-09-01 14:57:36,489 INFO  [org.ovirt.engine.core.bll.TagsDirector] (MSC service thread 1-2) Tag root added to tree
>2014-09-01 14:57:36,498 INFO  [org.ovirt.engine.core.bll.TagsDirector] (MSC service thread 1-2) Finished initializing TagsDirector
>2014-09-01 14:57:36,499 INFO  [org.ovirt.engine.core.bll.IsoDomainListSyncronizer] (MSC service thread 1-2) Start initializing IsoDomainListSyncronizer
>2014-09-01 14:57:36,509 INFO  [org.ovirt.engine.core.bll.IsoDomainListSyncronizer] (MSC service thread 1-2) Finished initializing IsoDomainListSyncronizer
>2014-09-01 14:57:36,577 INFO  [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Completed initializing handlers
>2014-09-01 14:57:36,607 INFO  [org.ovirt.engine.core.utils.ErrorTranslatorImpl] (MSC service thread 1-2) Start initializing ErrorTranslatorImpl
>2014-09-01 14:57:36,618 WARN  [org.ovirt.engine.core.utils.ErrorTranslatorImpl] (MSC service thread 1-2) Code MAC_ADDRESS_IS_IN_USE appears more than once in string table.
>2014-09-01 14:57:36,622 INFO  [org.ovirt.engine.core.utils.ErrorTranslatorImpl] (MSC service thread 1-2) Finished initializing ErrorTranslatorImpl
>2014-09-01 14:57:36,623 INFO  [org.ovirt.engine.core.utils.ErrorTranslatorImpl] (MSC service thread 1-2) Start initializing ErrorTranslatorImpl
>2014-09-01 14:57:36,624 INFO  [org.ovirt.engine.core.utils.ErrorTranslatorImpl] (MSC service thread 1-2) Finished initializing ErrorTranslatorImpl
>2014-09-01 14:57:36,624 INFO  [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Mark incomplete jobs as UNKNOWN
>2014-09-01 14:57:36,662 INFO  [org.ovirt.engine.core.bll.job.JobRepositoryCleanupManager] (MSC service thread 1-2) Start initializing JobRepositoryCleanupManager
>2014-09-01 14:57:36,663 INFO  [org.ovirt.engine.core.bll.job.JobRepositoryCleanupManager] (MSC service thread 1-2) Finished initializing JobRepositoryCleanupManager
>2014-09-01 14:57:36,664 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (MSC service thread 1-2) Start initializing AutoRecoveryManager
>2014-09-01 14:57:36,665 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (MSC service thread 1-2) Finished initializing AutoRecoveryManager
>2014-09-01 14:57:36,667 INFO  [org.ovirt.engine.core.dal.job.ExecutionMessageDirector] (MSC service thread 1-2) Start initializing ExecutionMessageDirector
>2014-09-01 14:57:36,673 INFO  [org.ovirt.engine.core.dal.job.ExecutionMessageDirector] (MSC service thread 1-2) Finished initializing ExecutionMessageDirector
>2014-09-01 14:57:36,711 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Loading extension 'builtin-authn-internal'
>2014-09-01 14:57:36,715 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Extension 'builtin-authn-internal' loaded
>2014-09-01 14:57:36,717 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Loading extension 'internal'
>2014-09-01 14:57:36,718 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Extension 'internal' loaded
>2014-09-01 14:57:36,719 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Initializing extension 'builtin-authn-internal'
>2014-09-01 14:57:36,719 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Extension 'builtin-authn-internal' initialized
>2014-09-01 14:57:36,720 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Initializing extension 'internal'
>2014-09-01 14:57:36,720 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Extension 'internal' initialized
>2014-09-01 14:57:36,720 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Start of enabled extensions list
>2014-09-01 14:57:36,721 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Instance name: 'builtin-authn-internal', Extension name: 'Internal Authn (Built-in)', Version: 'N/A', Notes: '', License: 'ASL 2.0', Home: 'http://www.ovirt.org', Author 'The oVirt Project', Build interface Version: '0',  File: 'N/A', Initialized: 'true'
>2014-09-01 14:57:36,721 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) Instance name: 'internal', Extension name: 'Internal Authz (Built-in)', Version: 'N/A', Notes: '', License: 'ASL 2.0', Home: 'http://www.ovirt.org', Author 'The oVirt Project', Build interface Version: '0',  File: 'N/A', Initialized: 'true'
>2014-09-01 14:57:36,722 INFO  [org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (MSC service thread 1-2) End of enabled extensions list
>2014-09-01 14:57:36,771 INFO  [org.ovirt.engine.core.bll.aaa.DbUserCacheManager] (MSC service thread 1-4) Start initializing DbUserCacheManager
>2014-09-01 14:57:36,772 INFO  [org.ovirt.engine.core.bll.aaa.DbUserCacheManager] (MSC service thread 1-4) Finished initializing DbUserCacheManager
>2014-09-01 14:57:36,784 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (MSC service thread 1-4) Initialization of AsyncTaskManager completed successfully.
>2014-09-01 14:57:36,785 INFO  [org.ovirt.engine.core.vdsbroker.ResourceManager] (MSC service thread 1-4) Start initializing ResourceManager
>2014-09-01 14:57:36,828 INFO  [org.ovirt.engine.core.bll.aaa.SyncUsers] (DefaultQuartzScheduler_Worker-1) Principal admin::internal synchronized
>2014-09-01 14:57:36,864 INFO  [org.ovirt.engine.core.vdsbroker.VdsManager] (MSC service thread 1-4) Entered VdsManager constructor
>2014-09-01 14:57:36,877 INFO  [org.ovirt.engine.core.vdsbroker.VdsManager] (MSC service thread 1-4) Initialize vdsBroker (pluto-vdsb.eng.lab.tlv.redhat.com,54,321)
>2014-09-01 14:57:36,913 INFO  [org.ovirt.engine.core.vdsbroker.ResourceManager] (MSC service thread 1-4) VDS 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 was added to the Resource Manager
>2014-09-01 14:57:36,913 INFO  [org.ovirt.engine.core.vdsbroker.VdsManager] (MSC service thread 1-4) Entered VdsManager constructor
>2014-09-01 14:57:36,915 INFO  [org.ovirt.engine.core.vdsbroker.VdsManager] (MSC service thread 1-4) Initialize vdsBroker (venus-vdsa.tlv.redhat.com,54,321)
>2014-09-01 14:57:36,978 INFO  [org.ovirt.engine.core.vdsbroker.ResourceManager] (MSC service thread 1-4) VDS 3dc5ba65-2f7a-414c-ad2b-635cdb1afbc7 was added to the Resource Manager
>2014-09-01 14:57:36,999 INFO  [org.ovirt.engine.core.vdsbroker.ResourceManager] (MSC service thread 1-4) Finished initializing ResourceManager
>2014-09-01 14:57:37,003 INFO  [org.ovirt.engine.core.bll.OvfDataUpdater] (MSC service thread 1-4) Initialization of OvfDataUpdater completed successfully.
>2014-09-01 14:57:37,004 INFO  [org.ovirt.engine.core.bll.scheduling.SchedulingManager] (MSC service thread 1-4) Start scheduling to enable vds load balancer
>2014-09-01 14:57:37,004 INFO  [org.ovirt.engine.core.bll.scheduling.SchedulingManager] (MSC service thread 1-4) Finished scheduling to enable vds load balancer
>2014-09-01 14:57:37,005 INFO  [org.ovirt.engine.core.bll.scheduling.SchedulingManager] (MSC service thread 1-4) Start HA Reservation check
>2014-09-01 14:57:37,005 INFO  [org.ovirt.engine.core.bll.scheduling.SchedulingManager] (MSC service thread 1-4) Finished HA Reservation check
>2014-09-01 14:57:37,016 INFO  [org.ovirt.engine.core.bll.InitBackendServicesOnStartupBean] (MSC service thread 1-4) Init VM custom properties utilities
>2014-09-01 14:57:37,016 INFO  [org.ovirt.engine.core.bll.InitBackendServicesOnStartupBean] (MSC service thread 1-4) Init device custom properties utilities
>2014-09-01 14:57:37,021 INFO  [org.ovirt.engine.core.bll.scheduling.SchedulingManager] (MSC service thread 1-4) Initializing Scheduling manager
>2014-09-01 14:57:37,051 INFO  [org.ovirt.engine.core.bll.scheduling.SchedulingManager] (MSC service thread 1-4) External scheduler disabled, discovery skipped
>2014-09-01 14:57:37,052 INFO  [org.ovirt.engine.core.bll.scheduling.SchedulingManager] (MSC service thread 1-4) Initialized Scheduling manager
>2014-09-01 14:57:37,052 INFO  [org.ovirt.engine.core.bll.dwh.DwhHeartBeat] (MSC service thread 1-4) Initializing DWH Heart Beat
>2014-09-01 14:57:37,054 INFO  [org.ovirt.engine.core.bll.dwh.DwhHeartBeat] (MSC service thread 1-4) DWH Heart Beat initialized
>2014-09-01 14:57:37,066 INFO  [org.ovirt.engine.core.bll.network.macpoolmanager.MacPoolManagerRanges] (org.ovirt.thread.pool-8-thread-1) Start initializing MacPoolManagerRanges
>2014-09-01 14:57:37,069 INFO  [org.ovirt.engine.core.bll.network.macpoolmanager.MacPoolManagerRanges] (org.ovirt.thread.pool-8-thread-1) Finished initializing. Available MACs in pool: 150
>2014-09-01 14:57:37,070 INFO  [org.ovirt.engine.core.bll.network.macpoolmanager.MacPoolPerDc] (org.ovirt.thread.pool-8-thread-1) successfully initialized
>2014-09-01 14:57:40,230 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-7) START, GetHardwareInfoVDSCommand(HostName = venus-vdsa.tlv.redhat.com, HostId = 3dc5ba65-2f7a-414c-ad2b-635cdb1afbc7, vds=Host[venus-vdsa.tlv.redhat.com,3dc5ba65-2f7a-414c-ad2b-635cdb1afbc7]), log id: 3be9285
>2014-09-01 14:57:40,278 INFO  [org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (Stomp Reactor) Connecting to pluto-vdsb.eng.lab.tlv.redhat.com/10.35.16.32
>2014-09-01 14:57:40,299 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-7) FINISH, GetHardwareInfoVDSCommand, log id: 3be9285
>2014-09-01 14:57:40,394 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: VDS_HIGH_NETWORK_USE not exist in string table
>2014-09-01 14:57:40,395 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_FAILED_REMOVE_VM not exist in string table
>2014-09-01 14:57:40,396 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_RUN_UNLOCK_ENTITY_SCRIPT not exist in string table
>2014-09-01 14:57:40,397 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: VDS_NETWORK_MTU_DIFFER_FROM_LOGICAL_NETWORK not exist in string table
>2014-09-01 14:57:40,398 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: STORAGE_ACTIVATE_ASYNC not exist in string table
>2014-09-01 14:57:40,398 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_ADDED_DISK_PROFILE not exist in string table
>2014-09-01 14:57:40,399 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_FAILED_TO_ADD_DISK_PROFILE not exist in string table
>2014-09-01 14:57:40,399 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_REMOVED_DISK_PROFILE not exist in string table
>2014-09-01 14:57:40,400 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_FAILED_TO_REMOVE_DISK_PROFILE not exist in string table
>2014-09-01 14:57:40,400 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_UPDATED_DISK_PROFILE not exist in string table
>2014-09-01 14:57:40,401 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_FAILED_TO_UPDATE_DISK_PROFILE not exist in string table
>2014-09-01 14:57:40,401 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_ADDED_CPU_PROFILE not exist in string table
>2014-09-01 14:57:40,401 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_FAILED_TO_ADD_CPU_PROFILE not exist in string table
>2014-09-01 14:57:40,402 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_REMOVED_CPU_PROFILE not exist in string table
>2014-09-01 14:57:40,402 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_FAILED_TO_REMOVE_CPU_PROFILE not exist in string table
>2014-09-01 14:57:40,403 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_UPDATED_CPU_PROFILE not exist in string table
>2014-09-01 14:57:40,403 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) AuditLogType: USER_FAILED_TO_UPDATE_CPU_PROFILE not exist in string table
>2014-09-01 14:57:40,462 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Network ;vdsmdummy; is not attached to any interface on host pluto-vdsb.eng.lab.tlv.redhat.com.
>2014-09-01 14:57:40,463 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-6) START, GetHardwareInfoVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, vds=Host[pluto-vdsb.eng.lab.tlv.redhat.com,3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2]), log id: 3383ad42
>2014-09-01 14:57:40,473 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-6) FINISH, GetHardwareInfoVDSCommand, log id: 3383ad42
>2014-09-01 14:57:40,529 INFO  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-7) Initializing Host: venus-vdsa.tlv.redhat.com
>2014-09-01 14:57:40,627 INFO  [org.ovirt.engine.core.bll.HandleVdsVersionCommand] (DefaultQuartzScheduler_Worker-7) [6fb5acd] Running command: HandleVdsVersionCommand internal: true. Entities affected :  ID: 3dc5ba65-2f7a-414c-ad2b-635cdb1afbc7 Type: VDS
>2014-09-01 14:57:40,635 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Host pluto-vdsb.eng.lab.tlv.redhat.com does not enforce SELinux.
>2014-09-01 14:57:40,638 WARN  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-6) Host pluto-vdsb.eng.lab.tlv.redhat.com is running with disabled SELinux.
>2014-09-01 14:57:40,701 INFO  [org.ovirt.engine.core.bll.HandleVdsCpuFlagsOrClusterChangedCommand] (DefaultQuartzScheduler_Worker-6) [b8e2464] Running command: HandleVdsCpuFlagsOrClusterChangedCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDS
>2014-09-01 14:57:40,781 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) [b8e2464] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Network ;vdsmdummy; is not attached to any interface on host pluto-vdsb.eng.lab.tlv.redhat.com.
>2014-09-01 14:57:40,782 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-6) [b8e2464] START, GetHardwareInfoVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, vds=Host[pluto-vdsb.eng.lab.tlv.redhat.com,3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2]), log id: 3e9c3b13
>2014-09-01 14:57:40,790 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-6) [b8e2464] FINISH, GetHardwareInfoVDSCommand, log id: 3e9c3b13
>2014-09-01 14:57:40,803 WARN  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-6) [b8e2464] Host pluto-vdsb.eng.lab.tlv.redhat.com is running with disabled SELinux.
>2014-09-01 14:57:40,848 INFO  [org.ovirt.engine.core.bll.InitVdsOnUpCommand] (DefaultQuartzScheduler_Worker-6) [39e76774] Running command: InitVdsOnUpCommand internal: true. Entities affected :  ID: 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b Type: StoragePool
>2014-09-01 14:57:40,881 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-6) [39f6f419] Running command: ConnectHostToStoragePoolServersCommand internal: true. Entities affected :  ID: 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b Type: StoragePool
>2014-09-01 14:57:40,918 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-6) [39f6f419] START, ConnectStorageServerVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, storagePoolId = 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b, storageType = NFS, connectionList = [{ id: 21c2ccd2-5055-4f96-9d98-1d9314806878, connection: 10.35.16.2:/export/images/rnd/maor/data9, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: d85c7ea9-b787-4528-91ab-10b48c2d1112, connection: 10.35.16.2:/export/images/rnd/maor/data5, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 5b46dd22
>2014-09-01 14:57:40,958 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-6) [39f6f419] FINISH, ConnectStorageServerVDSCommand, return: {d85c7ea9-b787-4528-91ab-10b48c2d1112=0, 21c2ccd2-5055-4f96-9d98-1d9314806878=0}, log id: 5b46dd22
>2014-09-01 14:57:40,959 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-6) [39f6f419] Host pluto-vdsb.eng.lab.tlv.redhat.com storage connection was succeeded 
>2014-09-01 14:57:40,983 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-10) START, ConnectStoragePoolVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, vdsId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, storagePoolId = 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b, masterVersion = 2), log id: 762d6271
>2014-09-01 14:57:41,215 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-10) FINISH, ConnectStoragePoolVDSCommand, log id: 762d6271
>2014-09-01 14:57:41,215 ERROR [org.ovirt.engine.core.bll.InitVdsOnUpCommand] (org.ovirt.thread.pool-8-thread-10) Could not connect host pluto-vdsb.eng.lab.tlv.redhat.com to pool NFS with the message: Cannot connect pool, already connected to another pool: ("[u'34752335-9cd3-49e2-8593-94c877b1c037']",)
>2014-09-01 14:57:41,283 INFO  [org.ovirt.engine.core.bll.SetNonOperationalVdsCommand] (DefaultQuartzScheduler_Worker-6) [232898ed] Running command: SetNonOperationalVdsCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDS
>2014-09-01 14:57:41,298 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-6) [232898ed] START, SetVdsStatusVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, status=NonOperational, nonOperationalReason=STORAGE_DOMAIN_UNREACHABLE, stopSpmFailureLogged=false), log id: 55026259
>2014-09-01 14:57:41,311 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-6) [232898ed] FINISH, SetVdsStatusVDSCommand, log id: 55026259
>2014-09-01 14:57:41,361 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) [232898ed] Correlation ID: 232898ed, Job ID: 685366c4-f2b9-4696-95e7-c26e1c604b15, Call Stack: null, Custom Event ID: -1, Message: Host pluto-vdsb.eng.lab.tlv.redhat.com cannot access the Storage Domain(s) <UNKNOWN> attached to the Data Center NFS. Setting Host state to Non-Operational.
>2014-09-01 14:57:41,388 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) [232898ed] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Failed to verify Power Management configuration for Host pluto-vdsb.eng.lab.tlv.redhat.com.
>2014-09-01 14:57:41,401 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-6) [232898ed] Correlation ID: 39e76774, Call Stack: null, Custom Event ID: -1, Message: Failed to connect Host pluto-vdsb.eng.lab.tlv.redhat.com to Storage Pool NFS
>2014-09-01 14:57:41,423 INFO  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-6) [232898ed] Initializing Host: pluto-vdsb.eng.lab.tlv.redhat.com
>2014-09-01 14:57:41,430 INFO  [org.ovirt.engine.core.bll.HandleVdsVersionCommand] (DefaultQuartzScheduler_Worker-6) [e36e483] Running command: HandleVdsVersionCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDS
>2014-09-01 14:57:41,432 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-6) [e36e483] Host 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 : pluto-vdsb.eng.lab.tlv.redhat.com is already in NonOperational status for reason STORAGE_DOMAIN_UNREACHABLE. SetNonOperationalVds command is skipped.
>2014-09-01 14:57:47,014 INFO  [org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand] (DefaultQuartzScheduler_Worker-24) [20d5d1d3] Running command: SetStoragePoolStatusCommand internal: true. Entities affected :  ID: 3307f387-262b-4e17-a3f2-a5f0da460a62 Type: StoragePool
>2014-09-01 14:57:47,018 INFO  [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (DefaultQuartzScheduler_Worker-24) [20d5d1d3] Storage Pool 3307f387-262b-4e17-a3f2-a5f0da460a62 - Updating Storage Domain 97ce0862-80f1-486d-aad0-a8082fffbad2 status from Active to Unknown, reason : null
>2014-09-01 14:57:47,027 INFO  [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (DefaultQuartzScheduler_Worker-24) [20d5d1d3] Storage Pool 3307f387-262b-4e17-a3f2-a5f0da460a62 - Updating Storage Domain cde3916e-f6f0-414a-a336-903d869463b9 status from Active to Unknown, reason : null
>2014-09-01 14:57:47,030 INFO  [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (DefaultQuartzScheduler_Worker-24) [20d5d1d3] Storage Pool 3307f387-262b-4e17-a3f2-a5f0da460a62 - Updating Storage Domain 3934c895-31cc-477b-bdc2-2eda1dc4fafa status from Active to Unknown, reason : null
>2014-09-01 14:57:47,075 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-24) [20d5d1d3] Correlation ID: 20d5d1d3, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center DC35. Setting status to Non Responsive.
>2014-09-01 14:57:47,218 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (DefaultQuartzScheduler_Worker-24) [20d5d1d3] hostFromVds::selectedVds - venus-vdsa.tlv.redhat.com, spmStatus SPM, storage pool DC35
>2014-09-01 14:57:47,233 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (DefaultQuartzScheduler_Worker-24) [20d5d1d3] Initialize Irs proxy from vds: venus-vdsa.tlv.redhat.com
>2014-09-01 14:57:47,241 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-24) [20d5d1d3] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Storage Pool Manager runs on Host venus-vdsa.tlv.redhat.com (Address: venus-vdsa.tlv.redhat.com).
>2014-09-01 14:57:47,257 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [20d5d1d3] START, SPMGetAllTasksInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false), log id: 62c96c24
>2014-09-01 14:57:47,425 INFO  [org.ovirt.engine.core.bll.storage.SyncLunsInfoForBlockStorageDomainCommand] (org.ovirt.thread.pool-8-thread-20) [4f9e1561] Running command: SyncLunsInfoForBlockStorageDomainCommand internal: true. Entities affected :  ID: 97ce0862-80f1-486d-aad0-a8082fffbad2 Type: Storage
>2014-09-01 14:57:47,444 INFO  [org.ovirt.engine.core.bll.storage.SyncLunsInfoForBlockStorageDomainCommand] (org.ovirt.thread.pool-8-thread-21) [247ed847] Running command: SyncLunsInfoForBlockStorageDomainCommand internal: true. Entities affected :  ID: cde3916e-f6f0-414a-a336-903d869463b9 Type: Storage
>2014-09-01 14:57:47,449 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-20) [4f9e1561] START, GetVGInfoVDSCommand(HostName = venus-vdsa.tlv.redhat.com, HostId = 3dc5ba65-2f7a-414c-ad2b-635cdb1afbc7, VGID=w6uWdr-MQhn-12wb-Sp6K-OjqQ-vVSp-uXspUV), log id: 42f95621
>2014-09-01 14:57:47,452 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-21) [247ed847] START, GetVGInfoVDSCommand(HostName = venus-vdsa.tlv.redhat.com, HostId = 3dc5ba65-2f7a-414c-ad2b-635cdb1afbc7, VGID=03NEeJ-OUhx-PZhf-5gtH-pbyB-89MT-JiIYil), log id: 7fc710ea
>2014-09-01 14:57:47,481 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-24) [20d5d1d3] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Warning, Low disk space.exportDomain domain has 21 GB of free space
>2014-09-01 14:57:47,481 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [20d5d1d3] -- executeIrsBrokerCommand: Attempting on storage pool 3307f387-262b-4e17-a3f2-a5f0da460a62
>2014-09-01 14:57:47,483 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [20d5d1d3] START, HSMGetAllTasksInfoVDSCommand(HostName = venus-vdsa.tlv.redhat.com, HostId = 3dc5ba65-2f7a-414c-ad2b-635cdb1afbc7), log id: 1a5fc370
>2014-09-01 14:57:48,640 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-21) [247ed847] FINISH, GetVGInfoVDSCommand, return: [LUNs [id=3600144f09dbd050000004ddcc1cd0025, physicalVolumeId=rKHOpv-eHwH-di5i-Edos-AOLe-yhN2-uAIQib, volumeGroupId=03NEeJ-OUhx-PZhf-5gtH-pbyB-89MT-JiIYil, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=36, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.2011-05.com.redhat:mpastern-iscsi, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=20, vendorName=NEXENTA, pathsDictionary={sdg=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=cde3916e-f6f0-414a-a336-903d869463b9, storageDomainName=null]], log id: 7fc710ea
>2014-09-01 14:57:48,688 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [20d5d1d3] FINISH, HSMGetAllTasksInfoVDSCommand, return: [], log id: 1a5fc370
>2014-09-01 14:57:48,689 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [20d5d1d3] FINISH, SPMGetAllTasksInfoVDSCommand, return: [], log id: 62c96c24
>2014-09-01 14:57:48,689 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-18) [20d5d1d3] Discovered no tasks on Storage Pool DC35
>2014-09-01 14:57:49,011 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-20) [4f9e1561] FINISH, GetVGInfoVDSCommand, return: [LUNs [id=3600144f09dbd050000004e1994980004, physicalVolumeId=RwO11r-Rh4f-aAsZ-3u92-uLjY-1JJr-7FBISs, volumeGroupId=w6uWdr-MQhn-12wb-Sp6K-OjqQ-vVSp-uXspUV, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=55, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.2011-05.com.redhat:achub-iscsi, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=20, vendorName=NEXENTA, pathsDictionary={sdb=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=97ce0862-80f1-486d-aad0-a8082fffbad2, storageDomainName=null], LUNs [id=3600144f09dbd050000004e1994f10006, physicalVolumeId=2yglCk-1YYv-SHau-wpcp-08NU-aZEW-r3Raa4, volumeGroupId=w6uWdr-MQhn-12wb-Sp6K-OjqQ-vVSp-uXspUV, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=57, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.2011-05.com.redhat:achub-iscsi, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=20, vendorName=NEXENTA, pathsDictionary={sdd=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=97ce0862-80f1-486d-aad0-a8082fffbad2, storageDomainName=null]], log id: 42f95621
>2014-09-01 14:58:26,773 INFO  [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (http--0.0.0.0-8080-1) Running command: LoginUserCommand internal: false.
>2014-09-01 14:58:26,790 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-1) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin logged in.
>2014-09-01 14:58:28,146 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (http--0.0.0.0-8080-2) [2f14b65a] Running command: LogoutUserCommand internal: false.
>2014-09-01 14:58:28,150 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (http--0.0.0.0-8080-6) [193d71d4] Running command: LogoutUserCommand internal: false.
>2014-09-01 14:58:28,152 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (http--0.0.0.0-8080-4) [fee0643] Running command: LogoutUserCommand internal: false.
>2014-09-01 14:58:28,153 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (http--0.0.0.0-8080-5) [72515893] Running command: LogoutUserCommand internal: false.
>2014-09-01 14:58:28,163 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (http--0.0.0.0-8080-3) [434826bc] Running command: LogoutUserCommand internal: false.
>2014-09-01 14:58:28,165 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (http--0.0.0.0-8080-1) [59b4af6f] Running command: LogoutUserCommand internal: false.
>2014-09-01 14:58:28,183 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-6) [193d71d4] Correlation ID: 193d71d4, Call Stack: null, Custom Event ID: -1, Message: User admin logged out.
>2014-09-01 14:58:28,183 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-3) [434826bc] Correlation ID: 434826bc, Call Stack: null, Custom Event ID: -1, Message: User admin logged out.
>2014-09-01 14:58:28,185 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-4) [fee0643] Correlation ID: fee0643, Call Stack: null, Custom Event ID: -1, Message: User admin logged out.
>2014-09-01 14:58:28,186 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-5) [72515893] Correlation ID: 72515893, Call Stack: null, Custom Event ID: -1, Message: User admin logged out.
>2014-09-01 14:58:28,184 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-2) [2f14b65a] Correlation ID: 2f14b65a, Call Stack: null, Custom Event ID: -1, Message: User admin logged out.
>2014-09-01 14:58:28,190 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-1) [59b4af6f] Correlation ID: 59b4af6f, Call Stack: null, Custom Event ID: -1, Message: User admin logged out.
>2014-09-01 14:58:28,205 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (http--0.0.0.0-8080-3) [7360625a] Running command: LogoutUserCommand internal: false.
>2014-09-01 14:58:28,222 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (http--0.0.0.0-8080-4) [572105ef] Running command: LogoutUserCommand internal: false.
>2014-09-01 14:58:28,231 INFO  [org.ovirt.engine.core.bll.aaa.LogoutUserCommand] (http--0.0.0.0-8080-6) [ce0cbae] Running command: LogoutUserCommand internal: false.
>2014-09-01 14:58:28,254 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-4) [572105ef] Correlation ID: 572105ef, Call Stack: null, Custom Event ID: -1, Message: User admin logged out.
>2014-09-01 14:58:28,257 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-6) [ce0cbae] Correlation ID: ce0cbae, Call Stack: null, Custom Event ID: -1, Message: User admin logged out.
>2014-09-01 14:58:28,254 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-3) [7360625a] Correlation ID: 7360625a, Call Stack: null, Custom Event ID: -1, Message: User admin logged out.
>2014-09-01 14:58:28,319 INFO  [org.ovirt.engine.core.utils.servlet.UnsupportedLocaleHelper] (http--0.0.0.0-8080-2) Invalid locale found in configuration: 
>2014-09-01 14:58:28,320 INFO  [org.ovirt.engine.core.utils.servlet.UnsupportedLocaleHelper] (http--0.0.0.0-8080-2) Invalid locale found in configuration: 
>2014-09-01 14:59:37,003 INFO  [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-43) Attempting to update VMs/Templates Ovf.
>2014-09-01 15:00:00,020 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (DefaultQuartzScheduler_Worker-16) Autorecovering 1 hosts
>2014-09-01 15:00:00,023 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (DefaultQuartzScheduler_Worker-16) Autorecovering hosts id: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, name : pluto-vdsb.eng.lab.tlv.redhat.com
>2014-09-01 15:00:00,030 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-16) [6e1aa67d] Lock Acquired to object EngineLock [exclusiveLocks= key: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 value: VDS
>, sharedLocks= ]
>2014-09-01 15:00:00,031 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-16) [6e1aa67d] Running command: ActivateVdsCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDSAction group MANIPULATE_HOST with role type ADMIN
>2014-09-01 15:00:00,032 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-16) [6e1aa67d] Before acquiring lock in order to prevent monitoring for host pluto-vdsb.eng.lab.tlv.redhat.com from data-center NFS
>2014-09-01 15:00:00,032 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-16) [6e1aa67d] Lock acquired, from now a monitoring of host will be skipped for host pluto-vdsb.eng.lab.tlv.redhat.com from data-center NFS
>2014-09-01 15:00:00,061 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-16) [6e1aa67d] START, SetVdsStatusVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, status=Unassigned, nonOperationalReason=NONE, stopSpmFailureLogged=false), log id: 694810c
>2014-09-01 15:00:00,068 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-16) [6e1aa67d] FINISH, SetVdsStatusVDSCommand, log id: 694810c
>2014-09-01 15:00:00,112 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-16) [6e1aa67d] Activate finished. Lock released. Monitoring can run now for host pluto-vdsb.eng.lab.tlv.redhat.com from data-center NFS
>2014-09-01 15:00:00,130 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-16) [6e1aa67d] Correlation ID: 6e1aa67d, Call Stack: null, Custom Event ID: -1, Message: Host pluto-vdsb.eng.lab.tlv.redhat.com was autorecovered.
>2014-09-01 15:00:00,131 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-16) [6e1aa67d] Lock freed to object EngineLock [exclusiveLocks= key: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 value: VDS
>, sharedLocks= ]
>2014-09-01 15:00:02,787 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-25) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Network ;vdsmdummy; is not attached to any interface on host pluto-vdsb.eng.lab.tlv.redhat.com.
>2014-09-01 15:00:02,788 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-25) START, GetHardwareInfoVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, vds=Host[pluto-vdsb.eng.lab.tlv.redhat.com,3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2]), log id: 32d6664a
>2014-09-01 15:00:02,797 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-25) FINISH, GetHardwareInfoVDSCommand, log id: 32d6664a
>2014-09-01 15:00:02,800 WARN  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-25) Host pluto-vdsb.eng.lab.tlv.redhat.com is running with disabled SELinux.
>2014-09-01 15:00:02,826 INFO  [org.ovirt.engine.core.bll.HandleVdsCpuFlagsOrClusterChangedCommand] (DefaultQuartzScheduler_Worker-25) [300b48da] Running command: HandleVdsCpuFlagsOrClusterChangedCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDS
>2014-09-01 15:00:02,861 INFO  [org.ovirt.engine.core.bll.InitVdsOnUpCommand] (DefaultQuartzScheduler_Worker-25) [4535df1d] Running command: InitVdsOnUpCommand internal: true. Entities affected :  ID: 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b Type: StoragePool
>2014-09-01 15:00:02,880 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-25) [6c31fdcb] Running command: ConnectHostToStoragePoolServersCommand internal: true. Entities affected :  ID: 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b Type: StoragePool
>2014-09-01 15:00:02,896 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-25) [6c31fdcb] START, ConnectStorageServerVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, storagePoolId = 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b, storageType = NFS, connectionList = [{ id: 21c2ccd2-5055-4f96-9d98-1d9314806878, connection: 10.35.16.2:/export/images/rnd/maor/data9, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: d85c7ea9-b787-4528-91ab-10b48c2d1112, connection: 10.35.16.2:/export/images/rnd/maor/data5, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 674e932a
>2014-09-01 15:00:02,924 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-25) [6c31fdcb] FINISH, ConnectStorageServerVDSCommand, return: {d85c7ea9-b787-4528-91ab-10b48c2d1112=0, 21c2ccd2-5055-4f96-9d98-1d9314806878=0}, log id: 674e932a
>2014-09-01 15:00:02,925 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-25) [6c31fdcb] Host pluto-vdsb.eng.lab.tlv.redhat.com storage connection was succeeded 
>2014-09-01 15:00:02,929 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-19) START, ConnectStoragePoolVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, vdsId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, storagePoolId = 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b, masterVersion = 2), log id: 2db906ff
>2014-09-01 15:00:02,942 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-19) FINISH, ConnectStoragePoolVDSCommand, log id: 2db906ff
>2014-09-01 15:00:02,942 ERROR [org.ovirt.engine.core.bll.InitVdsOnUpCommand] (org.ovirt.thread.pool-8-thread-19) Could not connect host pluto-vdsb.eng.lab.tlv.redhat.com to pool NFS with the message: Cannot connect pool, already connected to another pool: ("[u'34752335-9cd3-49e2-8593-94c877b1c037']",)
>2014-09-01 15:00:02,986 INFO  [org.ovirt.engine.core.bll.SetNonOperationalVdsCommand] (DefaultQuartzScheduler_Worker-25) [2720e497] Running command: SetNonOperationalVdsCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDS
>2014-09-01 15:00:02,989 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-25) [2720e497] START, SetVdsStatusVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, status=NonOperational, nonOperationalReason=STORAGE_DOMAIN_UNREACHABLE, stopSpmFailureLogged=false), log id: 282ba699
>2014-09-01 15:00:03,000 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-25) [2720e497] FINISH, SetVdsStatusVDSCommand, log id: 282ba699
>2014-09-01 15:00:03,014 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-25) [2720e497] Correlation ID: 2720e497, Job ID: 5cc198df-bb60-41aa-8a77-011b9f404db8, Call Stack: null, Custom Event ID: -1, Message: Host pluto-vdsb.eng.lab.tlv.redhat.com cannot access the Storage Domain(s) <UNKNOWN> attached to the Data Center NFS. Setting Host state to Non-Operational.
>2014-09-01 15:00:03,025 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-25) [2720e497] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Failed to verify Power Management configuration for Host pluto-vdsb.eng.lab.tlv.redhat.com.
>2014-09-01 15:00:03,034 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-25) [2720e497] Correlation ID: 4535df1d, Call Stack: null, Custom Event ID: -1, Message: Failed to connect Host pluto-vdsb.eng.lab.tlv.redhat.com to Storage Pool NFS
>2014-09-01 15:00:03,064 INFO  [org.ovirt.engine.core.bll.HandleVdsVersionCommand] (DefaultQuartzScheduler_Worker-25) [73f427c9] Running command: HandleVdsVersionCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDS
>2014-09-01 15:00:03,066 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-25) [73f427c9] Host 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 : pluto-vdsb.eng.lab.tlv.redhat.com is already in NonOperational status for reason STORAGE_DOMAIN_UNREACHABLE. SetNonOperationalVds command is skipped.
>2014-09-01 15:00:05,224 INFO  [org.ovirt.engine.core.bll.aaa.LoginAdminUserCommand] (http--0.0.0.0-8080-1) Running command: LoginAdminUserCommand internal: false.
>2014-09-01 15:00:05,230 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (http--0.0.0.0-8080-1) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin logged in.
>2014-09-01 15:00:14,915 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: 2460ea58
>2014-09-01 15:00:14,974 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) FINISH, GetVmsInfoVDSCommand, log id: 2460ea58
>2014-09-01 15:00:17,732 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: 285f038b
>2014-09-01 15:00:17,750 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) FINISH, GetVmsInfoVDSCommand, log id: 285f038b
>2014-09-01 15:00:17,952 INFO  [org.ovirt.engine.core.bll.ExportVmCommand] (http--0.0.0.0-8080-1) [9f85cb0] Lock Acquired to object EngineLock [exclusiveLocks= key: a84e791a-6446-4ee7-83e8-930007947ee7 value: VM
>, sharedLocks= ]
>2014-09-01 15:00:18,010 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) [9f85cb0] START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: 372a041a
>2014-09-01 15:00:18,094 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) [9f85cb0] FINISH, GetVmsInfoVDSCommand, log id: 372a041a
>2014-09-01 15:00:18,376 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) [9f85cb0] START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: 21d7c682
>2014-09-01 15:00:18,391 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) [9f85cb0] FINISH, GetVmsInfoVDSCommand, log id: 21d7c682
>2014-09-01 15:00:18,561 INFO  [org.ovirt.engine.core.bll.ExportVmCommand] (org.ovirt.thread.pool-8-thread-41) [9f85cb0] Running command: ExportVmCommand internal: false. Entities affected :  ID: 3934c895-31cc-477b-bdc2-2eda1dc4fafa Type: StorageAction group IMPORT_EXPORT_VM with role type ADMIN
>2014-09-01 15:00:18,602 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-8-thread-41) [9f85cb0] START, SetVmStatusVDSCommand( vmId = a84e791a-6446-4ee7-83e8-930007947ee7, status = ImageLocked, exit status = Normal), log id: 4405b8e
>2014-09-01 15:00:18,616 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-8-thread-41) [9f85cb0] FINISH, SetVmStatusVDSCommand, log id: 4405b8e
>2014-09-01 15:00:18,636 INFO  [org.ovirt.engine.core.bll.ExportVmCommand] (org.ovirt.thread.pool-8-thread-41) [9f85cb0] Lock freed to object EngineLock [exclusiveLocks= key: a84e791a-6446-4ee7-83e8-930007947ee7 value: VM
>, sharedLocks= ]
>2014-09-01 15:00:18,663 INFO  [org.ovirt.engine.core.bll.CopyImageGroupCommand] (org.ovirt.thread.pool-8-thread-41) [7d64bf7e] Running command: CopyImageGroupCommand internal: true. Entities affected :  ID: 3934c895-31cc-477b-bdc2-2eda1dc4fafa Type: Storage
>2014-09-01 15:00:18,741 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.MoveImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-41) [7d64bf7e] START, MoveImageGroupVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 97ce0862-80f1-486d-aad0-a8082fffbad2, imageGroupId = 728c6008-6870-4cb3-858d-b3ca7e4bdb70, dstDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmId = a84e791a-6446-4ee7-83e8-930007947ee7, op = Copy, postZero = false, force = true), log id: 5f47b7b
>2014-09-01 15:00:19,093 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.MoveImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-41) [7d64bf7e] FINISH, MoveImageGroupVDSCommand, log id: 5f47b7b
>2014-09-01 15:00:19,174 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-41) [7d64bf7e] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command c272c7e7-10c2-4916-af89-02d2a3db34f6
>2014-09-01 15:00:19,175 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-41) [7d64bf7e] CommandMultiAsyncTasks::AttachTask: Attaching task a7bcfc7c-fb57-48f9-830a-3914bea405ae to command c272c7e7-10c2-4916-af89-02d2a3db34f6.
>2014-09-01 15:00:19,201 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-41) [7d64bf7e] Adding task a7bcfc7c-fb57-48f9-830a-3914bea405ae (Parent Command ExportVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-01 15:00:19,279 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-41) [7d64bf7e] Correlation ID: 9f85cb0, Job ID: ff5cb3a3-6abf-4dc3-966b-86c94a4c5499, Call Stack: null, Custom Event ID: -1, Message: Starting export Vm VmBasedOnTemplate to exportDomain
>2014-09-01 15:00:19,280 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-41) [7d64bf7e] BaseAsyncTask::startPollingTask: Starting to poll task a7bcfc7c-fb57-48f9-830a-3914bea405ae.
>2014-09-01 15:00:26,775 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-90) Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now
>2014-09-01 15:00:26,837 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-90) SPMAsyncTask::PollTask: Polling task a7bcfc7c-fb57-48f9-830a-3914bea405ae (Parent Command ExportVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'cleanFailure'.
>2014-09-01 15:00:26,851 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-90) BaseAsyncTask::logEndTaskFailure: Task a7bcfc7c-fb57-48f9-830a-3914bea405ae (Parent Command ExportVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended with failure:
>-- Result: cleanFailure
>-- Message: VDSGenericException: VDSErrorException: Failed in vdscommand to HSMGetAllTasksStatusesVDS, error = Cannot get parent volume,
>-- Exception: VDSGenericException: VDSErrorException: Failed in vdscommand to HSMGetAllTasksStatusesVDS, error = Cannot get parent volume
>2014-09-01 15:00:26,853 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-90) CommandAsyncTask::endActionIfNecessary: All tasks of command c272c7e7-10c2-4916-af89-02d2a3db34f6 has ended -> executing endAction
>2014-09-01 15:00:26,853 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-90) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: c272c7e7-10c2-4916-af89-02d2a3db34f6): calling endAction .
>2014-09-01 15:00:26,854 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction ExportVm, executionIndex: 0
>2014-09-01 15:00:26,873 ERROR [org.ovirt.engine.core.bll.ExportVmCommand] (org.ovirt.thread.pool-8-thread-2) Ending command with failure: org.ovirt.engine.core.bll.ExportVmCommand
>2014-09-01 15:00:26,881 ERROR [org.ovirt.engine.core.bll.CopyImageGroupCommand] (org.ovirt.thread.pool-8-thread-2) [7d64bf7e] Ending command with failure: org.ovirt.engine.core.bll.CopyImageGroupCommand
>2014-09-01 15:00:26,910 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-8-thread-2) START, SetVmStatusVDSCommand( vmId = a84e791a-6446-4ee7-83e8-930007947ee7, status = Down, exit status = Normal), log id: 5e2f3f9f
>2014-09-01 15:00:26,914 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-8-thread-2) FINISH, SetVmStatusVDSCommand, log id: 5e2f3f9f
>2014-09-01 15:00:26,936 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-2) Correlation ID: 9f85cb0, Call Stack: null, Custom Event ID: -1, Message: Failed to export Vm VmBasedOnTemplate to exportDomain
>2014-09-01 15:00:26,937 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type ExportVm completed, handling the result.
>2014-09-01 15:00:26,937 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type ExportVm succeeded, clearing tasks.
>2014-09-01 15:00:26,942 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-2) SPMAsyncTask::ClearAsyncTask: Attempting to clear task a7bcfc7c-fb57-48f9-830a-3914bea405ae
>2014-09-01 15:00:26,944 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) START, SPMClearTaskVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, taskId = a7bcfc7c-fb57-48f9-830a-3914bea405ae), log id: 4adc0e26
>2014-09-01 15:00:26,946 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) START, HSMClearTaskVDSCommand(HostName = venus-vdsa.tlv.redhat.com, HostId = 3dc5ba65-2f7a-414c-ad2b-635cdb1afbc7, taskId=a7bcfc7c-fb57-48f9-830a-3914bea405ae), log id: 759133b
>2014-09-01 15:00:27,067 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) FINISH, HSMClearTaskVDSCommand, log id: 759133b
>2014-09-01 15:00:27,069 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) FINISH, SPMClearTaskVDSCommand, log id: 4adc0e26
>2014-09-01 15:00:27,121 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-2) BaseAsyncTask::removeTaskFromDB: Removed task a7bcfc7c-fb57-48f9-830a-3914bea405ae from DataBase
>2014-09-01 15:00:27,121 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity c272c7e7-10c2-4916-af89-02d2a3db34f6
>2014-09-01 15:00:35,499 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-2) START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: 22b7bb40
>2014-09-01 15:00:35,524 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-2) FINISH, GetVmsInfoVDSCommand, log id: 22b7bb40
>2014-09-01 15:00:38,219 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-2) START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: bcb986c
>2014-09-01 15:00:38,240 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-2) FINISH, GetVmsInfoVDSCommand, log id: bcb986c
>2014-09-01 15:00:38,385 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateFromImportExportCommand] (org.ovirt.thread.pool-8-thread-23) [58543c0] Running command: RemoveVmTemplateFromImportExportCommand internal: false. Entities affected :  ID: 3934c895-31cc-477b-bdc2-2eda1dc4fafa Type: StorageAction group DELETE_TEMPLATE with role type USER
>2014-09-01 15:00:38,387 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.RemoveVMVDSCommand] (org.ovirt.thread.pool-8-thread-23) [58543c0] START, RemoveVMVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmGuid = db9fcfaa-d7d0-4a5a-b2e2-f846e4f03285), log id: 5ac4fcd4
>2014-09-01 15:00:38,441 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.RemoveVMVDSCommand] (org.ovirt.thread.pool-8-thread-23) [58543c0] FINISH, RemoveVMVDSCommand, log id: 5ac4fcd4
>2014-09-01 15:00:38,471 INFO  [org.ovirt.engine.core.bll.RemoveAllVmImagesCommand] (org.ovirt.thread.pool-8-thread-23) [4db3d783] Running command: RemoveAllVmImagesCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: VM
>2014-09-01 15:00:38,532 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (org.ovirt.thread.pool-8-thread-23) [6c246f27] Running command: RemoveImageCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2014-09-01 15:00:38,566 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-23) [6c246f27] START, DeleteImageGroupVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, imageGroupId = 021f20cd-9b19-4f30-b1d9-4b151f221d10, postZeros = false, forceDelete = true), log id: 477df5c8
>2014-09-01 15:00:38,809 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-23) [6c246f27] FINISH, DeleteImageGroupVDSCommand, log id: 477df5c8
>2014-09-01 15:00:38,884 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-23) [6c246f27] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command aa7b3bf6-2dfc-475c-b46c-97b93e8b0fd1
>2014-09-01 15:00:38,886 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-23) [6c246f27] CommandMultiAsyncTasks::AttachTask: Attaching task 2b376287-45ac-457d-86ea-9e7d17383f55 to command aa7b3bf6-2dfc-475c-b46c-97b93e8b0fd1.
>2014-09-01 15:00:38,901 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-23) [6c246f27] Adding task 2b376287-45ac-457d-86ea-9e7d17383f55 (Parent Command RemoveVmTemplateFromImportExport, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-01 15:00:38,942 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-23) [6c246f27] Correlation ID: 58543c0, Job ID: b97c5257-2917-4c1f-9505-7730ddb8c0c1, Call Stack: null, Custom Event ID: -1, Message: Template template1 was removed from exportDomain
>2014-09-01 15:00:38,943 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-23) [6c246f27] BaseAsyncTask::startPollingTask: Starting to poll task 2b376287-45ac-457d-86ea-9e7d17383f55.
>2014-09-01 15:00:44,920 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-2) START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: 7273101f
>2014-09-01 15:00:44,942 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-2) FINISH, GetVmsInfoVDSCommand, log id: 7273101f
>2014-09-01 15:00:46,855 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-52) Polling and updating Async Tasks: 2 tasks, 1 tasks to poll now
>2014-09-01 15:00:46,865 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-52) SPMAsyncTask::PollTask: Polling task 2b376287-45ac-457d-86ea-9e7d17383f55 (Parent Command RemoveVmTemplateFromImportExport, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-01 15:00:46,878 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-52) BaseAsyncTask::onTaskEndSuccess: Task 2b376287-45ac-457d-86ea-9e7d17383f55 (Parent Command RemoveVmTemplateFromImportExport, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-01 15:00:46,879 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-52) CommandAsyncTask::endActionIfNecessary: All tasks of command aa7b3bf6-2dfc-475c-b46c-97b93e8b0fd1 has ended -> executing endAction
>2014-09-01 15:00:46,880 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-52) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: aa7b3bf6-2dfc-475c-b46c-97b93e8b0fd1): calling endAction .
>2014-09-01 15:00:46,880 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-33) CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction RemoveVmTemplateFromImportExport, executionIndex: 0
>2014-09-01 15:00:46,886 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (org.ovirt.thread.pool-8-thread-33) START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: 49e072b0
>2014-09-01 15:00:46,902 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (org.ovirt.thread.pool-8-thread-33) FINISH, GetVmsInfoVDSCommand, log id: 49e072b0
>2014-09-01 15:00:46,911 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateFromImportExportCommand] (org.ovirt.thread.pool-8-thread-33) Ending command successfully: org.ovirt.engine.core.bll.RemoveVmTemplateFromImportExportCommand
>2014-09-01 15:00:46,913 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-33) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type RemoveVmTemplateFromImportExport completed, handling the result.
>2014-09-01 15:00:46,914 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-33) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type RemoveVmTemplateFromImportExport succeeded, clearing tasks.
>2014-09-01 15:00:46,925 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-33) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 2b376287-45ac-457d-86ea-9e7d17383f55
>2014-09-01 15:00:46,926 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-33) START, SPMClearTaskVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, taskId = 2b376287-45ac-457d-86ea-9e7d17383f55), log id: 41308870
>2014-09-01 15:00:46,929 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-33) START, HSMClearTaskVDSCommand(HostName = venus-vdsa.tlv.redhat.com, HostId = 3dc5ba65-2f7a-414c-ad2b-635cdb1afbc7, taskId=2b376287-45ac-457d-86ea-9e7d17383f55), log id: 73ccfda6
>2014-09-01 15:00:46,998 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-33) FINISH, HSMClearTaskVDSCommand, log id: 73ccfda6
>2014-09-01 15:00:46,999 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-33) FINISH, SPMClearTaskVDSCommand, log id: 41308870
>2014-09-01 15:00:47,010 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-33) BaseAsyncTask::removeTaskFromDB: Removed task 2b376287-45ac-457d-86ea-9e7d17383f55 from DataBase
>2014-09-01 15:00:47,012 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-33) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity aa7b3bf6-2dfc-475c-b46c-97b93e8b0fd1
>2014-09-01 15:00:50,841 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: 17e25c90
>2014-09-01 15:00:50,931 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) FINISH, GetVmsInfoVDSCommand, log id: 17e25c90
>2014-09-01 15:00:52,030 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: ac5fabf
>2014-09-01 15:00:52,243 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) FINISH, GetVmsInfoVDSCommand, log id: ac5fabf
>2014-09-01 15:00:53,720 INFO  [org.ovirt.engine.core.bll.ExportVmCommand] (http--0.0.0.0-8080-1) [7c8d19b8] Lock Acquired to object EngineLock [exclusiveLocks= key: a84e791a-6446-4ee7-83e8-930007947ee7 value: VM
>, sharedLocks= ]
>2014-09-01 15:00:53,766 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) [7c8d19b8] START, GetVmsInfoVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmIdList = null), log id: 4e22f3ea
>2014-09-01 15:00:53,782 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (http--0.0.0.0-8080-1) [7c8d19b8] FINISH, GetVmsInfoVDSCommand, log id: 4e22f3ea
>2014-09-01 15:00:53,902 INFO  [org.ovirt.engine.core.bll.ExportVmCommand] (org.ovirt.thread.pool-8-thread-46) [7c8d19b8] Running command: ExportVmCommand internal: false. Entities affected :  ID: 3934c895-31cc-477b-bdc2-2eda1dc4fafa Type: StorageAction group IMPORT_EXPORT_VM with role type ADMIN
>2014-09-01 15:00:53,903 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-8-thread-46) [7c8d19b8] START, SetVmStatusVDSCommand( vmId = a84e791a-6446-4ee7-83e8-930007947ee7, status = ImageLocked, exit status = Normal), log id: 5a698b5f
>2014-09-01 15:00:53,907 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-8-thread-46) [7c8d19b8] FINISH, SetVmStatusVDSCommand, log id: 5a698b5f
>2014-09-01 15:00:53,911 INFO  [org.ovirt.engine.core.bll.ExportVmCommand] (org.ovirt.thread.pool-8-thread-46) [7c8d19b8] Lock freed to object EngineLock [exclusiveLocks= key: a84e791a-6446-4ee7-83e8-930007947ee7 value: VM
>, sharedLocks= ]
>2014-09-01 15:00:53,917 INFO  [org.ovirt.engine.core.bll.CopyImageGroupCommand] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] Running command: CopyImageGroupCommand internal: true. Entities affected :  ID: 3934c895-31cc-477b-bdc2-2eda1dc4fafa Type: Storage
>2014-09-01 15:00:53,945 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.MoveImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] START, MoveImageGroupVDSCommand( storagePoolId = 3307f387-262b-4e17-a3f2-a5f0da460a62, ignoreFailoverLimit = false, storageDomainId = 97ce0862-80f1-486d-aad0-a8082fffbad2, imageGroupId = 728c6008-6870-4cb3-858d-b3ca7e4bdb70, dstDomainId = 3934c895-31cc-477b-bdc2-2eda1dc4fafa, vmId = a84e791a-6446-4ee7-83e8-930007947ee7, op = Copy, postZero = false, force = false), log id: 37dc73ad
>2014-09-01 15:00:54,349 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.MoveImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] Failed in MoveImageGroupVDS method
>2014-09-01 15:00:54,374 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] IrsBroker::Failed::MoveImageGroupVDS due to: IRSErrorException: IRSGenericException: IRSErrorException: Failed to MoveImageGroupVDS, error = Error moving image: ('spUUID=3307f387-262b-4e17-a3f2-a5f0da460a62, srcDomUUID=97ce0862-80f1-486d-aad0-a8082fffbad2, dstDomUUID=3934c895-31cc-477b-bdc2-2eda1dc4fafa, imgUUID=728c6008-6870-4cb3-858d-b3ca7e4bdb70, vmUUID=, op=1, force=false, postZero=false force=false',), code = 253
>2014-09-01 15:00:54,379 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.MoveImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] FINISH, MoveImageGroupVDSCommand, log id: 37dc73ad
>2014-09-01 15:00:54,379 ERROR [org.ovirt.engine.core.bll.CopyImageGroupCommand] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] Command org.ovirt.engine.core.bll.CopyImageGroupCommand throw Vdc Bll exception. With error message VdcBLLException: org.ovirt.engine.core.vdsbroker.irsbroker.IRSErrorException: IRSGenericException: IRSErrorException: Failed to MoveImageGroupVDS, error = Error moving image: ('spUUID=3307f387-262b-4e17-a3f2-a5f0da460a62, srcDomUUID=97ce0862-80f1-486d-aad0-a8082fffbad2, dstDomUUID=3934c895-31cc-477b-bdc2-2eda1dc4fafa, imgUUID=728c6008-6870-4cb3-858d-b3ca7e4bdb70, vmUUID=, op=1, force=false, postZero=false force=false',), code = 253 (Failed with error MoveImageError and code 253)
>2014-09-01 15:00:54,395 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] Removed task c9c84078-0502-4076-bcd8-f766734695e8 from DataBase
>2014-09-01 15:00:54,407 ERROR [org.ovirt.engine.core.bll.CopyImageGroupCommand] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] Transaction rolled-back for command: org.ovirt.engine.core.bll.CopyImageGroupCommand.
>2014-09-01 15:00:54,408 INFO  [org.ovirt.engine.core.utils.transaction.TransactionSupport] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] transaction rolled back
>2014-09-01 15:00:54,408 ERROR [org.ovirt.engine.core.bll.ExportVmCommand] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] Command org.ovirt.engine.core.bll.ExportVmCommand throw Vdc Bll exception. With error message VdcBLLException: Failed during ExportVmCommand (Failed with error MoveImageError and code 253)
>2014-09-01 15:00:54,413 INFO  [org.ovirt.engine.core.bll.ExportVmCommand] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] Command [id=c02bbb5d-a010-498b-ad6d-b92d54a2822b]: Compensating CHANGED_STATUS_ONLY of org.ovirt.engine.core.common.businessentities.VmDynamic; snapshot: EntityStatusSnapshot [id=a84e791a-6446-4ee7-83e8-930007947ee7, status=Down].
>2014-09-01 15:00:54,431 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-46) [2d4a0b0] Correlation ID: 7c8d19b8, Job ID: ce10ff32-2404-4891-9d8c-3a9884f0955a, Call Stack: null, Custom Event ID: -1, Message: Failed to export Vm VmBasedOnTemplate to exportDomain
>2014-09-01 15:01:36,776 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-99) Setting new tasks map. The map contains now 1 tasks
>2014-09-01 15:01:37,041 INFO  [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-7) [6fb5acd] Attempting to update VMs/Templates Ovf.
>2014-09-01 15:02:06,776 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-86) Setting new tasks map. The map contains now 0 tasks
>2014-09-01 15:02:06,777 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-86) Cleared all tasks of pool 3307f387-262b-4e17-a3f2-a5f0da460a62.
>2014-09-01 15:03:37,051 INFO  [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-69) Attempting to update VMs/Templates Ovf.
>2014-09-01 15:05:00,010 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (DefaultQuartzScheduler_Worker-15) Autorecovering 1 hosts
>2014-09-01 15:05:00,011 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (DefaultQuartzScheduler_Worker-15) Autorecovering hosts id: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, name : pluto-vdsb.eng.lab.tlv.redhat.com
>2014-09-01 15:05:00,013 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-15) [4952e960] Lock Acquired to object EngineLock [exclusiveLocks= key: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 value: VDS
>, sharedLocks= ]
>2014-09-01 15:05:00,014 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-15) [4952e960] Running command: ActivateVdsCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDSAction group MANIPULATE_HOST with role type ADMIN
>2014-09-01 15:05:00,014 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-15) [4952e960] Before acquiring lock in order to prevent monitoring for host pluto-vdsb.eng.lab.tlv.redhat.com from data-center NFS
>2014-09-01 15:05:00,015 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-15) [4952e960] Lock acquired, from now a monitoring of host will be skipped for host pluto-vdsb.eng.lab.tlv.redhat.com from data-center NFS
>2014-09-01 15:05:00,017 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-15) [4952e960] START, SetVdsStatusVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, status=Unassigned, nonOperationalReason=NONE, stopSpmFailureLogged=false), log id: 328e5aa1
>2014-09-01 15:05:00,031 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-15) [4952e960] FINISH, SetVdsStatusVDSCommand, log id: 328e5aa1
>2014-09-01 15:05:00,055 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-15) [4952e960] Activate finished. Lock released. Monitoring can run now for host pluto-vdsb.eng.lab.tlv.redhat.com from data-center NFS
>2014-09-01 15:05:00,057 INFO  [org.ovirt.engine.core.bll.ActivateVdsCommand] (DefaultQuartzScheduler_Worker-15) [4952e960] Lock freed to object EngineLock [exclusiveLocks= key: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 value: VDS
>, sharedLocks= ]
>2014-09-01 15:05:00,375 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-17) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Network ;vdsmdummy; is not attached to any interface on host pluto-vdsb.eng.lab.tlv.redhat.com.
>2014-09-01 15:05:00,375 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-17) START, GetHardwareInfoVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, vds=Host[pluto-vdsb.eng.lab.tlv.redhat.com,3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2]), log id: 27bd39e1
>2014-09-01 15:05:00,384 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-17) FINISH, GetHardwareInfoVDSCommand, log id: 27bd39e1
>2014-09-01 15:05:00,390 WARN  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-17) Host pluto-vdsb.eng.lab.tlv.redhat.com is running with disabled SELinux.
>2014-09-01 15:05:00,431 INFO  [org.ovirt.engine.core.bll.HandleVdsCpuFlagsOrClusterChangedCommand] (DefaultQuartzScheduler_Worker-17) [215fb887] Running command: HandleVdsCpuFlagsOrClusterChangedCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDS
>2014-09-01 15:05:00,443 INFO  [org.ovirt.engine.core.bll.InitVdsOnUpCommand] (DefaultQuartzScheduler_Worker-17) [736dc00b] Running command: InitVdsOnUpCommand internal: true. Entities affected :  ID: 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b Type: StoragePool
>2014-09-01 15:05:00,450 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-17) [96f9d85] Running command: ConnectHostToStoragePoolServersCommand internal: true. Entities affected :  ID: 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b Type: StoragePool
>2014-09-01 15:05:00,458 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-17) [96f9d85] START, ConnectStorageServerVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, storagePoolId = 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b, storageType = NFS, connectionList = [{ id: 21c2ccd2-5055-4f96-9d98-1d9314806878, connection: 10.35.16.2:/export/images/rnd/maor/data9, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: d85c7ea9-b787-4528-91ab-10b48c2d1112, connection: 10.35.16.2:/export/images/rnd/maor/data5, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 4d0effec
>2014-09-01 15:05:00,480 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-17) [96f9d85] FINISH, ConnectStorageServerVDSCommand, return: {d85c7ea9-b787-4528-91ab-10b48c2d1112=0, 21c2ccd2-5055-4f96-9d98-1d9314806878=0}, log id: 4d0effec
>2014-09-01 15:05:00,481 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-17) [96f9d85] Host pluto-vdsb.eng.lab.tlv.redhat.com storage connection was succeeded 
>2014-09-01 15:05:00,487 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-7) START, ConnectStoragePoolVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, vdsId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, storagePoolId = 2a848bc8-4c22-481d-b5e7-7057e0d5bb8b, masterVersion = 2), log id: 74f213b6
>2014-09-01 15:05:00,500 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-7) FINISH, ConnectStoragePoolVDSCommand, log id: 74f213b6
>2014-09-01 15:05:00,500 ERROR [org.ovirt.engine.core.bll.InitVdsOnUpCommand] (org.ovirt.thread.pool-8-thread-7) Could not connect host pluto-vdsb.eng.lab.tlv.redhat.com to pool NFS with the message: Cannot connect pool, already connected to another pool: ("[u'34752335-9cd3-49e2-8593-94c877b1c037']",)
>2014-09-01 15:05:00,555 INFO  [org.ovirt.engine.core.bll.SetNonOperationalVdsCommand] (DefaultQuartzScheduler_Worker-17) [69f4de37] Running command: SetNonOperationalVdsCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDS
>2014-09-01 15:05:00,558 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-17) [69f4de37] START, SetVdsStatusVDSCommand(HostName = pluto-vdsb.eng.lab.tlv.redhat.com, HostId = 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2, status=NonOperational, nonOperationalReason=STORAGE_DOMAIN_UNREACHABLE, stopSpmFailureLogged=false), log id: 2485824d
>2014-09-01 15:05:00,574 INFO  [org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand] (DefaultQuartzScheduler_Worker-17) [69f4de37] FINISH, SetVdsStatusVDSCommand, log id: 2485824d
>2014-09-01 15:05:00,581 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-17) [69f4de37] Correlation ID: 69f4de37, Job ID: 36a9a0e5-78bd-47e1-82f8-953895cc1fa4, Call Stack: null, Custom Event ID: -1, Message: Host pluto-vdsb.eng.lab.tlv.redhat.com cannot access the Storage Domain(s) <UNKNOWN> attached to the Data Center NFS. Setting Host state to Non-Operational.
>2014-09-01 15:05:00,607 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-17) [69f4de37] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Failed to verify Power Management configuration for Host pluto-vdsb.eng.lab.tlv.redhat.com.
>2014-09-01 15:05:00,613 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-17) [69f4de37] Correlation ID: 736dc00b, Call Stack: null, Custom Event ID: -1, Message: Failed to connect Host pluto-vdsb.eng.lab.tlv.redhat.com to Storage Pool NFS
>2014-09-01 15:05:00,631 INFO  [org.ovirt.engine.core.bll.HandleVdsVersionCommand] (DefaultQuartzScheduler_Worker-17) [6bdd7e6e] Running command: HandleVdsVersionCommand internal: true. Entities affected :  ID: 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 Type: VDS
>2014-09-01 15:05:00,633 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-17) [6bdd7e6e] Host 3c48e0ff-c569-41a8-bcb2-c573a7fcf2b2 : pluto-vdsb.eng.lab.tlv.redhat.com is already in NonOperational status for reason STORAGE_DOMAIN_UNREACHABLE. SetNonOperationalVds command is skipped.
>2014-09-01 15:05:37,060 INFO  [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-29) Attempting to update VMs/Templates Ovf.
>2014-09-01 15:07:37,073 INFO  [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-87) Attempting to update VMs/Templates Ovf.

Actions: View

Attachments on bug 1135987: 933322 | 933323