On Tue, Jan 24, 2017 at 11:09 AM, Piotr Kliczewski <piotr.kliczewski@gmail.com> wrote:The above log entry is a result of the engine closing connection dueOn Tue, Jan 24, 2017 at 9:38 AM, Fred Rolland <frolland@redhat.com> wrote:
> Hi,
>
> I see some issues in the communication between host0 and the the engine.
> Vdsm returned the answer to call getSpmStatus and then got an SSL error. [1]
>
> After that, the engine tried to send to the same host0 connectStorageServer
> requests that failed.
> The process of attaching the storage domain failed because the host was not
> connected to the NFS server.
> I think the engine should not have tried to attach the storage domain if
> connectStorageServer request failed.
> Can you open a bug on this ?
>
> Regardless, the SSL error and communication issue should be investigated
> further by infra team.
>
> Regards,
>
> Fred
>
> [1]
> jsonrpc.Executor/5::DEBUG::2017-01-19
> 12:13:48,711::__init__::555::jsonrpc.JsonRpcServer::(_handle _request) Return
> 'StoragePool.getSpmStatus' in bridge with {'spmId': 1, 'spmStatus': 'SPM',
> 'spmLver': 2L}
> jsonrpc.Executor/5::INFO::2017-01-19
> 12:13:48,711::__init__::513::jsonrpc.JsonRpcServer::(_serveR equest) RPC call
> StoragePool.getSpmStatus succeeded in 0.00 seconds
> JsonRpc (StompReactor)::ERROR::2017-01-19
> 12:13:49,449::betterAsyncore::113::vds.dispatcher::(recv) SSL error during
> reading data: unexpected eof
to higher level
timeout occurring
>
> [2]
> 2017-01-19 12:13:49,455 ERROR
> [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageSer Above log entry tells us that a command timeout. In order toverVDSCommand]
> (org.ovirt.thread.pool-6-thread-5) [4a2c0e44] Command
> 'ConnectStorageServerVDSCommand(HostName = lago-basic-suite-4-0-host0,
> StorageServerConnectionManagementVDSParameters:{runAsync='tr ue',
> hostId='4c4d9ad9-32a1-406a-93da-1710e069c690',
> storagePoolId='00000000-0000-0000-0000-000000000000', storageType='NFS',
> connectionList='[StorageServerConnections:{id='da9131c8- 1cd9-46bb-b7ea-f83228e04d3f',
> connection='192.168.201.4:/exports/nfs/iso', iqn='null', vfsType='null',
> mountOptions='null', nfsVersion='V3', nfsRetrans='null', nfsTimeo='null',
> iface='null', netIfaceName='null'}]'})' execution failed:
> VDSGenericException: VDSNetworkException: Message timeout which can be
> caused by communication issues
>
understand what happened
I would check this command why it did not get a response. Usually it
is send 300 secs
prior above message.
It is desired approach when we see higher timeout to close the
connection and attempt to
reconnect.Is there a reason not to close gracefully?Y.
>
>
> On Mon, Jan 23, 2017 at 4:35 PM, Shlomo Ben David <sbendavi@redhat.com>
> wrote:
>>
>> Hi,
>>
>> Job [1] failed with the following errors (logs [2]):
>>
>> {"jsonrpc": "2.0", "id": "669e1306-3206-4a64-a33f-d18176531ff8", "error":
>> {"message": "Storage domain does not exist:
>> (u'ab6c9588-d957-4be3-9862-d2596db463d9',)", "code": 358}}�
>> 2017-01-19 12:13:51,619 DEBUG
>> [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker)
>> [3a116b94] Message received: {"jsonrpc": "2.0", "id":
>> "669e1306-3206-4a64-a33f-d18176531ff8", "error": {"message": "Storage domain
>> does not exist: (u'ab6c9588-d957-4be3-9862-d2596db463d9',)", "code": 358}}
>> 2017-01-19 12:13:51,620 ERROR
>> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDoma inVDSCommand]
>> (default task-27) [6a6480a4] Failed in 'AttachStorageDomainVDS' method
>> 2017-01-19 12:13:51,624 ERROR
>> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo gDirector]
>> (default task-27) [6a6480a4] Correlation ID: null, Call Stack: null, Custom
>> Event ID: -1, Message: VDSM command failed: Storage domain does not exist:
>> (u'ab6c9588-d957-4be3-9862-d2596db463d9',)
>> 2017-01-19 12:13:51,624 ERROR
>> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDoma inVDSCommand]
>> (default task-27) [6a6480a4] Command 'AttachStorageDomainVDSCommand(
>> AttachStorageDomainVDSCommandParameters:{runAsync='true',
>> storagePoolId='fc33da6d-5da7-4005-a693-f170437c176c',
>> ignoreFailoverLimit='false',
>> storageDomainId='ab6c9588-d957-4be3-9862-d2596db463d9'})' execution failed:
>> IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS,
>> error = Storage domain does not exist:
>> (u'ab6c9588-d957-4be3-9862-d2596db463d9',), code = 358
>> 2017-01-19 12:13:51,632 DEBUG
>> [org.ovirt.engine.core.utils.timer.FixedDelayJobListener]
>> (DefaultQuartzScheduler10) [] Rescheduling
>> DEFAULT.org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyDa ta.hostsStorageConnectionsAndP oolMetadataRefresh#-9223372036 854775793
>> as there is no unfired trigger.
>> 2017-01-19 12:13:51,624 DEBUG
>> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDoma inVDSCommand]
>> (default task-27) [6a6480a4] Exception:
>> org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailed NoFailoverException:
>> IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS,
>> error = Storage domain does not exist:
>> (u'ab6c9588-d957-4be3-9862-d2596db463d9',), code = 358
>> at
>> org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomai nVDSCommand.createDefaultConcr eteException(AttachStorageDoma inVDSCommand.java:25)
>> [vdsbroker.jar:]
>> at
>> org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase. createException(BrokerCommandB ase.java:222)
>> [vdsbroker.jar:]
>> at
>> org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase. proceedProxyReturnValue(Broker CommandBase.java:192)
>> [vdsbroker.jar:]
>> at
>> org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomai nVDSCommand.executeIrsBrokerCo mmand(AttachStorageDomainVDSCo mmand.java:18)
>> [vdsbroker.jar:]
>> at
>> org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand. lambda$executeVDSCommand$0(Irs BrokerCommand.java:161)
>> [vdsbroker.jar:]
>> at
>> org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData.runIn ControlledConcurrency(IrsProxy Data.java:248)
>> [vdsbroker.jar:]
>> at
>> org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand.e xecuteVDSCommand(IrsBrokerComm and.java:158)
>> [vdsbroker.jar:]
>> at
>> org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeComman d(VDSCommandBase.java:73)
>> [vdsbroker.jar:]
>> at
>> org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandB ase.java:33)
>> [dal.jar:]
>> at
>> org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsComman d(ResourceManager.java:451)
>> [vdsbroker.jar:]
>> at
>> org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsComman d(VDSBrokerFrontendImpl.java: 33)
>> [bll.jar:]
>> at
>> org.ovirt.engine.core.bll.CommandBase.runVdsCommand(CommandB ase.java:2171)
>> [bll.jar:]
>> at
>> org.ovirt.engine.core.bll.storage.StorageHandlingCommandBase .runVdsCommand(StorageHandling CommandBase.java:657)
>> [bll.jar:]
>> at
>> org.ovirt.engine.core.bll.storage.domain.AttachStorageDomain ToPoolCommand.executeCommand(A ttachStorageDomainToPoolComman d.java:152)
>> [bll.jar:]
>> at
>> org.ovirt.engine.core.bll.CommandBase.executeWithoutTransact ion(CommandBase.java:1305)
>> [bll.jar:]
>> at
>> org.ovirt.engine.core.bll.CommandBase.executeActionInTransac tionScope(CommandBase.java: 1447)
>> [bll.jar:]
>> at
>> org.ovirt.engine.core.bll.CommandBase.runInTransaction(Comma ndBase.java:2075)
>> [bll.jar:]
>> at
>> org.ovirt.engine.core.utils.transaction.TransactionSupport.e xecuteInSuppressed(Transaction Support.java:166)
>> [utils.jar:]
>> at
>> org.ovirt.engine.core.utils.transaction.TransactionSupport.e xecuteInScope(TransactionSuppo rt.java:105)
>> [utils.jar:]
>> at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase. java:1490)
>> [bll.jar:]
>> at
>> org.ovirt.engine.core.bll.CommandBase.executeAction(CommandB ase.java:398)
>> [bll.jar:]
>> at org.ovirt.engine.core.bll.Backend.runAction(Backend.java: 493)
>> [bll.jar:]
>> at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java :475)
>> [bll.jar:]
>> at org.ovirt.engine.core.bll.Backend.runAction(Backend.java: 428)
>> [bll.jar:]
>> at sun.reflect.GeneratedMethodAccessor217.invoke(Unknown Source)
>> [:1.8.0_111]
>> at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe thodAccessorImpl.java:43)
>> [rt.jar:1.8.0_111]
>> at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_111]
>> at
>> org.jboss.as.ee.component.ManagedReferenceMethodInterceptor. processInvocation(ManagedRefer enceMethodInterceptor.java:52)
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.invocation.InterceptorContext$Invocation.proceed( InterceptorContext.java:437)
>> at
>> org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.delegateInte rception(Jsr299BindingsInterce ptor.java:70)
>> [wildfly-weld-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInte rception(Jsr299BindingsInterce ptor.java:80)
>> [wildfly-weld-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvoc ation(Jsr299BindingsIntercepto r.java:93)
>> [wildfly-weld-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.as.ee.component.interceptors.UserInterceptorFactor y$1.processInvocation(UserInte rceptorFactory.java:63)
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.invocation.InterceptorContext$Invocation.proceed( InterceptorContext.java:437)
>> at
>> org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerI nterceptor.aroundInvoke(Correl ationIdTrackerInterceptor. java:13)
>> [bll.jar:]
>> at sun.reflect.GeneratedMethodAccessor63.invoke(Unknown Source)
>> [:1.8.0_111]
>> at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe thodAccessorImpl.java:43)
>> [rt.jar:1.8.0_111]
>> at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_111]
>> at
>> org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInt erceptor.processInvocation(Man agedReferenceLifecycleMethodIn terceptor.java:89)
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeI nterceptor.processInvocation(E xecutionTimeInterceptor.java:4 3)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.invocation.InterceptorContext$Invocation.proceed( InterceptorContext.java:437)
>> at
>> org.jboss.weld.ejb.AbstractEJBRequestScopeActivationIntercep tor.aroundInvoke(AbstractEJBRe questScopeActivationIntercepto r.java:73)
>> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
>> at
>> org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor. processInvocation(EjbRequestSc opeActivationInterceptor.java: 83)
>> [wildfly-weld-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.proc essInvocation(ConcurrentContex tInterceptor.java:45)
>> [wildfly-ee-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.invocation.InitialInterceptor.processInvocation(In itialInterceptor.java:21)
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.invocation.ChainedInterceptor.processInvocation(Ch ainedInterceptor.java:61)
>> at
>> org.jboss.as.ee.component.interceptors.ComponentDispatcherIn terceptor.processInvocation(Co mponentDispatcherInterceptor. java:52)
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ejb3.component.singleton.SingletonComponentInst anceAssociationInterceptor.pro cessInvocation(SingletonCompon entInstanceAssociationIntercep tor.java:53)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInte rceptor.java:263)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxIntercep tor.java:374)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTT xInterceptor.java:243)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ejb3.component.interceptors.CurrentInvocationCo ntextInterceptor. processInvocation(CurrentInvoc ationContextInterceptor.java: 41)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterc eptor.processInvocation(WaitTi meInterceptor.java:47)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ejb3.security.SecurityContextInterceptor.proces sInvocation(SecurityContextInt erceptor.java:100)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ejb3.deployment.processors.StartupAwaitIntercep tor.processInvocation(StartupA waitInterceptor.java:22)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ejb3.component.interceptors.ShutDownInterceptor Factory$1.processInvocation(Sh utDownInterceptorFactory.java: 64)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ejb3.component.interceptors.LoggingInterceptor. processInvocation(LoggingInter ceptor.java:67)
>> [wildfly-ejb3-10.1.0.Final.jar:10.1.0.Final]
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.as.ee.component.NamespaceContextInterceptor.proces sInvocation(NamespaceContextIn terceptor.java:50)
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.invocation.ContextClassLoaderInterceptor.processIn vocation(ContextClassLoaderInt erceptor.java:64)
>> at
>> org.jboss.invocation.InterceptorContext.proceed(InterceptorC ontext.java:340)
>> at
>> org.jboss.invocation.InterceptorContext.run(InterceptorConte