Bug 1589045

Summary:

[RHHI] Brick profile feature in RHV-M doesn't seems to be working

Product:

[oVirt] ovirt-engine

Reporter:

bipin <bshetty>

Component:

Frontend.WebAdmin

Assignee:

Kaustav Majumder <kmajumde>

Status:

CLOSED CURRENTRELEASE

QA Contact:

SATHEESARAN <sasundar>

Severity:

high

Docs Contact:

Priority:

medium

Version:

future

CC:

bshetty, bugs, godas, kmajumde, lsvaty, rhs-bugs, sabose, sasundar

Target Milestone:

ovirt-4.4.0

Flags:

pm-rhel: ovirt-4.4+

Target Release:

---

Hardware:

x86_64

OS:

Linux

Whiteboard:

Fixed In Version:

Doc Type:

Known Issue

Doc Text:

Story Points:

---

Clone Of:

1589041

Environment:

Last Closed:

2019-11-22 11:04:42 UTC

Type:

Bug

Regression:

---

Mount Type:

---

Documentation:

---

CRM:

Verified Versions:

Category:

---

oVirt Team:

Gluster

RHEL 7.3 requirements from Atomic Host:

Cloudforms Team:

---

Target Upstream Version:

Embargoed:

Bug Depends On:

Bug Blocks:

1589041

Attachments:

Description	Flags
VDSM log	none
Engine.log	none
engine.log	none
Engine.log	none
RHV-M_UI	none

Description bipin 2018-06-08 09:27:38 UTC

Created attachment 1449036 [details]
Exception.txt

+++ This bug was initially created as a clone of Bug #1589041 +++

Description of problem:
While fetching the brick profile stats in RHV-M UI,the details button display's error suggesting it couldn't fetch the stats for the bricks. This seems to be a regression, also seen in older builds.


Version-Release number of selected component (if applicable):
rhvm-4.2.4.2-0.1.el7_3.noarch

How reproducible:
100%

Steps to Reproduce:
1. Login to the RHV-M -> Storage ->Volumes
2. Select any brick in the volume
3. Select the Profiling button then -> start
4. Select the details button

Actual results:
Error displaying no brick profiling stats 

Expected results:
Should provide the brick profile stats

Additional info:

--- Additional comment from Red Hat Bugzilla Rules Engine on 2018-06-08 05:20:50 EDT ---

This bug is automatically being proposed for the current release of Red Hat Hyperconverged Infrastructure (RHHI) under active development, by setting the release flag 'rhhi‑2.0' to '?'. 

If this bug should be proposed for a different release, please manually change the proposed release flag.

--- Additional comment from bipin on 2018-06-08 05:22:42 EDT ---

Error log:

2018-06-08 12:48:18,248+05 INFO  [org.ovirt.engine.core.bll.gluster.StartGlusterVolumeProfileCommand] (EE-ManagedThreadFactory-engine-Thread-3062) [59218944-b746-447f-94bd-97ea4fa07fd4] Running command: StartGlu
sterVolumeProfileCommand internal: false. Entities affected :  ID: c39c7d4f-881a-4572-b1f7-8824fe79864e Type: GlusterVolumeAction group MANIPULATE_GLUSTER_VOLUME with role type ADMIN
2018-06-08 12:48:18,251+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.StartGlusterVolumeProfileVDSCommand] (EE-ManagedThreadFactory-engine-Thread-3062) [59218944-b746-447f-94bd-97ea4fa07fd4] START, StartGlus
terVolumeProfileVDSCommand(HostName = 10.70.36.243, GlusterVolumeVDSParameters:{hostId='4b10cf9f-5610-421d-8f46-73eef63ebc56', volumeName='VDO'}), log id: 5adb803f
2018-06-08 12:48:18,495+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.StartGlusterVolumeProfileVDSCommand] (EE-ManagedThreadFactory-engine-Thread-3062) [59218944-b746-447f-94bd-97ea4fa07fd4] FINISH, StartGlu
sterVolumeProfileVDSCommand, log id: 5adb803f
2018-06-08 12:48:18,529+05 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-3062) [59218944-b746-447f-94bd-97ea4fa07fd4] EVENT_ID: GLUSTER_VOLUM
E_PROFILE_START(4,022), Gluster Volume VDO profiling started on cluster Default.
2018-06-08 12:48:22,450+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GetGlusterVolumeProfileInfoVDSCommand] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] START, GetGlusterVolumeProfileInfoVDSComma
nd(HostName = 10.70.36.243, GlusterVolumeProfileInfoVDSParameters:{hostId='4b10cf9f-5610-421d-8f46-73eef63ebc56', volumeName='VDO'}), log id: 51e085dc
2018-06-08 12:48:22,625+05 WARN  [org.ovirt.engine.core.vdsbroker.gluster.GetGlusterVolumeProfileInfoVDSCommand] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] Unexpected return value: Status [code=-32603, message=Internal JSON-RPC error: {'reason': "Attempt to call function: <bound method GlusterVolume.profileInfo of <vdsm.gluster.apiwrapper.GlusterVolume object at 0x7f39c412bed0>> with arguments: (u'VDO', True) error: sequence item 0: expected string, NoneType found"}]
2018-06-08 12:48:22,625+05 WARN  [org.ovirt.engine.core.vdsbroker.gluster.GetGlusterVolumeProfileInfoVDSCommand] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] Unexpected return value: Status [code=-32603, message=Internal JSON-RPC error: {'reason': "Attempt to call function: <bound method GlusterVolume.profileInfo of <vdsm.gluster.apiwrapper.GlusterVolume object at 0x7f39c412bed0>> with arguments: (u'VDO', True) error: sequence item 0: expected string, NoneType found"}]
2018-06-08 12:48:22,625+05 ERROR [org.ovirt.engine.core.vdsbroker.gluster.GetGlusterVolumeProfileInfoVDSCommand] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] Failed in 'GetGlusterVolumeProfileInfoVDS' method
2018-06-08 12:48:22,625+05 WARN  [org.ovirt.engine.core.vdsbroker.gluster.GetGlusterVolumeProfileInfoVDSCommand] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] Unexpected return value: Status [code=-32603, message=Internal JSON-RPC error: {'reason': "Attempt to call function: <bound method GlusterVolume.profileInfo of <vdsm.gluster.apiwrapper.GlusterVolume object at 0x7f39c412bed0>> with arguments: (u'VDO', True) error: sequence item 0: expected string, NoneType found"}]
2018-06-08 12:48:22,656+05 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM 10.70.36.243 command GetGlusterVolumeProfileInfoVDS failed: Internal JSON-RPC error: {'reason': "Attempt to call function: <bound method GlusterVolume.profileInfo of <vdsm.gluster.apiwrapper.GlusterVolume object at 0x7f39c412bed0>> with arguments: (u'VDO', True) error: sequence item 0: expected string, NoneType found"}
2018-06-08 12:48:22,656+05 ERROR [org.ovirt.engine.core.vdsbroker.gluster.GetGlusterVolumeProfileInfoVDSCommand] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] Command 'GetGlusterVolumeProfileInfoVDSCommand(HostName = 10.70.36.243, GlusterVolumeProfileInfoVDSParameters:{hostId='4b10cf9f-5610-421d-8f46-73eef63ebc56', volumeName='VDO'})' execution failed: VDSGenericException: VDSErrorException: Failed to GetGlusterVolumeProfileInfoVDS, error = Internal JSON-RPC error: {'reason': "Attempt to call function: <bound method GlusterVolume.profileInfo of <vdsm.gluster.apiwrapper.GlusterVolume object at 0x7f39c412bed0>> with arguments: (u'VDO', True) error: sequence item 0: expected string, NoneType found"}, code = -32603
2018-06-08 12:48:22,656+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GetGlusterVolumeProfileInfoVDSCommand] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] FINISH, GetGlusterVolumeProfileInfoVDSCommand, log id: 51e085dc
2018-06-08 12:48:22,657+05 ERROR [org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] Query 'GetGlusterVolumeProfileInfoQuery' failed: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to GetGlusterVolumeProfileInfoVDS, error = Internal JSON-RPC error: {'reason': "Attempt to call function: <bound method GlusterVolume.profileInfo of <vdsm.gluster.apiwrapper.GlusterVolume object at 0x7f39c412bed0>> with arguments: (u'VDO', True) error: sequence item 0: expected string, NoneType found"}, code = -32603 (Failed with error unexpected and code 16)
2018-06-08 12:48:22,657+05 ERROR [org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery] (default task-5) [ca01436a-1bc9-4577-b584-d5fae19e710a] Exception: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to GetGlusterVolumeProfileInfoVDS, error = Internal JSON-RPC error: {'reason': "Attempt to call function: <bound method GlusterVolume.profileInfo of <vdsm.gluster.apiwrapper.GlusterVolume object at 0x7f39c412bed0>> with arguments: (u'VDO', True) error: sequence item 0: expected string, NoneType found"}, code = -32603 (Failed with error unexpected and code 16)

--- Additional comment from bipin on 2018-06-08 05:24 EDT ---



--- Additional comment from bipin on 2018-06-08 05:25 EDT ---

Comment 2 Gobinda Das 2018-07-10 06:58:57 UTC

Kaustav as discussed,
VDSM is giving error when request is going with nfs=true

2018-07-02 14:53:24,515+05 ERROR [org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery] (default task-34) [c6473179-84c5-4afd-a09a-6d2d5afc4d6a] Query 'GetGlusterVolumeProfileInfoQuery' failed: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to GetGlusterVolumeProfileInfoVDS, error = Internal JSON-RPC error: {'reason': "Attempt to call function: <bound method GlusterVolume.profileInfo of <vdsm.gluster.apiwrapper.GlusterVolume object at 0x7f7694eacd50>> with arguments: (u'dist-vol', True) error: sequence item 0: expected string, NoneType found"}, code = -32603 (Failed with error unexpected and code 16)
2018-07-02 14:53:24,515+05 ERROR [org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery] (default task-34) [c6473179-84c5-4afd-a09a-6d2d5afc4d6a] Exception: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to GetGlusterVolumeProfileInfoVDS, error = Internal JSON-RPC error: {'reason': "Attempt to call function: <bound method GlusterVolume.profileInfo of <vdsm.gluster.apiwrapper.GlusterVolume object at 0x7f7694eacd50>> with arguments: (u'dist-vol', True) error: sequence item 0: expected string, NoneType found"}, code = -32603 (Failed with error unexpected and code 16)
	at org.ovirt.engine.core.bll.VdsHandler.handleVdsResult(VdsHandler.java:118) [bll.jar:]
	at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFrontendImpl.java:33) [bll.jar:]
	at org.ovirt.engine.core.bll.QueriesCommandBase.runVdsCommand(QueriesCommandBase.java:238) [bll.jar:]
	at org.ovirt.engine.core.bll.gluster.GlusterQueriesCommandBase.runVdsCommand(GlusterQueriesCommandBase.java:88) [bll.jar:]
	at org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery.executeQueryCommand(GetGlusterVolumeProfileInfoQuery.java:25) [bll.jar:]
	at org.ovirt.engine.core.bll.QueriesCommandBase.executeCommand(QueriesCommandBase.java:106) [bll.jar:]
	at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:31) [dal.jar:]
	at org.ovirt.engine.core.bll.executor.DefaultBackendQueryExecutor.execute(DefaultBackendQueryExecutor.java:14) [bll.jar:]
	at org.ovirt.engine.core.bll.Backend.runQueryImpl(Backend.java:520) [bll.jar:]
	at org.ovirt.engine.core.bll.Backend.runQuery(Backend.java:489) [bll.jar:]
	at sun.reflect.GeneratedMethodAccessor73.invoke(Unknown Source) [:1.8.0_171]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_171]
	at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_171]
	at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
	at org.jboss.as.weld.ejb.DelegatingInterceptorInvocationContext.proceed(DelegatingInterceptorInvocationContext.java:92) [wildfly-weld-ejb-11.0.0.Final.jar:11.0.0.Final]
	at org.jboss.weld.interceptor.proxy.WeldInvocationContext.interceptorChainCompleted(WeldInvocationContext.java:98) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
	at org.jboss.weld.interceptor.proxy.WeldInvocationContext.proceed(WeldInvocationContext.java:117) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
	at org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(LoggingInterceptor.java:12) [common.jar:]
	at sun.reflect.GeneratedMethodAccessor68.invoke(Unknown Source) [:1.8.0_171]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_171]
	at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_171]
	at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
	at org.jboss.weld.interceptor.proxy.WeldInvocationContext.invokeNext(WeldInvocationContext.java:83) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
	at org.jboss.weld.interceptor.proxy.WeldInvocationContext.proceed(WeldInvocationContext.java:115) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
	at org.jboss.weld.bean.InterceptorImpl.intercept(InterceptorImpl.java:108) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
	at org.jboss.as.weld.ejb.DelegatingInterceptorInvocationContext.proceed(DelegatingInterceptorInvocationContext.java:82) [wildfly-weld-ejb-11.0.0.Final.jar:11.0.0.Final]
	at org.jboss.as.weld.interceptors.EjbComponentInterceptorSupport.delegateInterception(EjbComponentInterceptorSupport.java:60)
	at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:76)
	at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:88)
	at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:101)
	at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
	at org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerInterceptor.aroundInvoke(CorrelationIdTrackerInterceptor.java:13) [bll.jar:]
	at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source) [:1.8.0_171]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_171]
	at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_171]
	at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptor.java:89)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [wildfly-ejb3-11.0.0.Final.jar:11.0.0.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45) [wildfly-ee-11.0.0.Final.jar:11.0.0.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
	at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationIntercep


Can you please check?

Comment 3 Kaustav Majumder 2018-07-19 09:42:24 UTC

I have checked the same but it is giving proper status for the volumes although when I am refreshing the status 2-3 times it is giving the above error. This might be due to network contention.

Comment 4 Kaustav Majumder 2018-07-19 09:43:21 UTC

Need  info regarding your setup

Comment 5 bipin 2018-07-19 11:11:23 UTC

As discussed offline provided the setup where the error still persists

Comment 6 SATHEESARAN 2018-09-04 08:53:43 UTC

Tested with RHV 4.2.6-4 and glusterfs-3.8.4
Unable to get the brick profile details.

Comment 7 Red Hat Bugzilla Rules Engine 2018-09-04 08:53:50 UTC

Target release should be placed once a package build is known to fix a issue. Since this bug is not modified, the target version has been reset. Please use target milestone to plan a fix for a oVirt release.

Comment 8 Kaustav Majumder 2018-09-06 05:51:05 UTC

Unable to reproduce the bug in my dev evironment. I am able to view brick profile status. Kindly help me with reproducing the bug

Comment 9 Sahina Bose 2018-09-19 11:03:19 UTC

Please provide the engine logs as well as vdsm logs for the failure

Comment 10 bipin 2018-09-20 12:07:12 UTC

Again tested with RHV 4.2.6-4 + glusterfs-3.12.2-18 (3.4.1) could see the issue persisting.


Snippet from Engine.log:
=======================
2018-09-20 17:14:34,694+05 INFO  [org.ovirt.engine.core.bll.gluster.StartGlusterVolumeProfileCommand] (EE-ManagedThreadFactory-engine-Thread-7418) [051f2c88-03ce-48f1-8267-823d1fe6aae0] Running command: StartGlu
sterVolumeProfileCommand internal: false. Entities affected :  ID: 7b95b7c7-bd5e-432e-89eb-7880e18d2840 Type: GlusterVolumeAction group MANIPULATE_GLUSTER_VOLUME with role type ADMIN
2018-09-20 17:14:34,697+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.StartGlusterVolumeProfileVDSCommand] (EE-ManagedThreadFactory-engine-Thread-7418) [051f2c88-03ce-48f1-8267-823d1fe6aae0] START, StartGlusterVolumeProfileVDSCommand(HostName = rhsqa-grafton7-nic2.lab.eng.blr.redhat.com, GlusterVolumeVDSParameters:{hostId='b77c9cd5-7275-4689-8359-94ae2acbe527', volumeName='vmstore'}), log id: 167e075e
2018-09-20 17:14:34,897+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand] (DefaultQuartzScheduler1) [3d301f4] START, GlusterServersListVDSCommand(HostName = rhsqa-grafton9-nic2.lab.eng.blr.redhat.com, VdsIdVDSCommandParametersBase:{hostId='4a41fbff-b10e-4413-be29-a36aa69b3a1c'}), log id: 4f175a63
2018-09-20 17:14:34,944+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.StartGlusterVolumeProfileVDSCommand] (EE-ManagedThreadFactory-engine-Thread-7418) [051f2c88-03ce-48f1-8267-823d1fe6aae0] FINISH, StartGlusterVolumeProfileVDSCommand, log id: 167e075e
2018-09-20 17:14:34,950+05 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-7418) [051f2c88-03ce-48f1-8267-823d1fe6aae0] EVENT_ID: GLUSTER_VOLUME_PROFILE_START(4,022), Gluster Volume vmstore profiling started on cluster Default.
2018-09-20 17:14:35,216+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand] (DefaultQuartzScheduler1) [3d301f4] FINISH, GlusterServersListVDSCommand, return: [10.70.45.31/22:CONNECTED, rhsqa-grafton7.lab.eng.blr.redhat.com:CONNECTED, rhsqa-grafton8.lab.eng.blr.redhat.com:CONNECTED], log id: 4f175a63
2018-09-20 17:14:35,222+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler1) [3d301f4] START, GlusterVolumesListVDSCommand(HostName = rhsqa-grafton9-nic2.lab.eng.blr.redhat.com, GlusterVolumesListVDSParameters:{hostId='4a41fbff-b10e-4413-be29-a36aa69b3a1c'}), log id: 7a1645c8
2018-09-20 17:14:35,421+05 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler1) [3d301f4] EVENT_ID: GLUSTER_VOLUME_OPTION_SET_FROM_CLI(4,028), Detected new option diagnostics.count-fop-hits=on on volume vmstore of cluster Default, and added it to engine DB.
2018-09-20 17:14:35,421+05 INFO  [org.ovirt.engine.core.bll.gluster.GlusterSyncJob] (DefaultQuartzScheduler1) [3d301f4] New option 'diagnostics.count-fop-hits'='on' set on volume 'vmstore' from gluster CLI. Updating engine DB accordingly.
2018-09-20 17:14:35,426+05 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler1) [3d301f4] EVENT_ID: GLUSTER_VOLUME_OPTION_SET_FROM_CLI(4,028), Detected new option diagnostics.latency-measurement=on on volume vmstore of cluster Default, and added it to engine DB.
2018-09-20 17:14:35,426+05 INFO  [org.ovirt.engine.core.bll.gluster.GlusterSyncJob] (DefaultQuartzScheduler1) [3d301f4] New option 'diagnostics.latency-measurement'='on' set on volume 'vmstore' from gluster CLI. Updating engine DB accordingly.
2018-09-20 17:14:39,365+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GetGlusterVolumeProfileInfoVDSCommand] (default task-28) [2031ad93-f64b-4e54-bc9b-0ce5e21e4ec5] START, GetGlusterVolumeProfileInfoVDSCommand(HostName = rhsqa-grafton9-nic2.lab.eng.blr.redhat.com, GlusterVolumeProfileInfoVDSParameters:{hostId='4a41fbff-b10e-4413-be29-a36aa69b3a1c', volumeName='vmstore'}), log id: 68b100b5
2018-09-20 17:14:39,552+05 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GetGlusterVolumeProfileInfoVDSCommand] (default task-28) [2031ad93-f64b-4e54-bc9b-0ce5e21e4ec5] FINISH, GetGlusterVolumeProfileInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeProfileInfo@9fde9785, log id: 68b100b5
2018-09-20 17:14:39,553+05 ERROR [org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery] (default task-28) [2031ad93-f64b-4e54-bc9b-0ce5e21e4ec5] Query 'GetGlusterVolumeProfileInfoQuery' failed: null
2018-09-20 17:14:39,553+05 ERROR [org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery] (default task-28) [2031ad93-f64b-4e54-bc9b-0ce5e21e4ec5] Exception: java.lang.NullPointerException
        at org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery.populateBrickNames(GetGlusterVolumeProfileInfoQuery.java:44) [bll.jar:]
        at org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery.executeQueryCommand(GetGlusterVolumeProfileInfoQuery.java:36) [bll.jar:]
        at org.ovirt.engine.core.bll.QueriesCommandBase.executeCommand(QueriesCommandBase.java:106) [bll.jar:]
        at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33) [dal.jar:]
        at org.ovirt.engine.core.bll.executor.DefaultBackendQueryExecutor.execute(DefaultBackendQueryExecutor.java:14) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runQueryImpl(Backend.java:538) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runQuery(Backend.java:507) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor101.invoke(Unknown Source) [:1.8.0_181]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_181]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_181]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
        at org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerInterceptor.aroundInvoke(CorrelationIdTrackerInterceptor.java:13) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor97.invoke(Unknown Source) [:1.8.0_181]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_181]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_181]
        at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptor.java:89)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45) [wildfly-ee-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
        at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:264) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:379) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:244) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
        at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73) [weld-core-impl.jar:2.4.7.Final-redhat-1]
        at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) [wildfly-ejb3-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
        at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:609)
        at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)




Snippet from vdsm log:
======================
2018-09-20 17:14:34,942+0530 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call GlusterVolume.profileStart succeeded in 0.24 seconds (__init__:573)
2018-09-20 17:14:36,873+0530 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call Host.ping2 succeeded in 0.00 seconds (__init__:573)
2018-09-20 17:14:36,937+0530 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call Host.ping2 succeeded in 0.00 seconds (__init__:573)
2018-09-20 17:14:36,940+0530 INFO  (jsonrpc/2) [vdsm.api] START repoStats(domains=[u'49210550-6128-4c1a-978c-b52a0ae18960']) from=::1,59914, task_id=764325af-efd9-446f-a4f1-bf789a8d3065 (api:46)
2018-09-20 17:14:36,940+0530 INFO  (jsonrpc/2) [vdsm.api] FINISH repoStats return={u'49210550-6128-4c1a-978c-b52a0ae18960': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000772269', 'lastCheck': '4.3', 'valid': True}} from=::1,59914, task_id=764325af-efd9-446f-a4f1-bf789a8d3065 (api:52)
2018-09-20 17:14:36,941+0530 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call Host.getStorageRepoStats succeeded in 0.00 seconds (__init__:573)
2018-09-20 17:14:36,945+0530 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call Host.ping2 succeeded in 0.00 seconds (__init__:573)
2018-09-20 17:14:37,616+0530 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call Host.ping2 succeeded in 0.00 seconds (__init__:573)
2018-09-20 17:14:37,620+0530 INFO  (jsonrpc/6) [api.host] START getStats() from=::1,59914 (api:46)
2018-09-20 17:14:37,621+0530 INFO  (jsonrpc/6) [vdsm.api] START repoStats(domains=()) from=::1,59914, task_id=167fd692-ebe9-4d41-9e11-f1866541f310 (api:46)
2018-09-20 17:14:37,621+0530 INFO  (jsonrpc/6) [vdsm.api] FINISH repoStats return={u'08e2f0ee-d5e2-409a-8fd2-29d4968964fd': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00061482', 'lastCheck': '3.7', 'valid': True}, u'49210550-6128-4c1a-978c-b52a0ae18960': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000772269', 'lastCheck': '5.0', 'valid': True}, u'05fefed6-58e7-432b-8fdc-c1952b1c2237': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000747418', 'lastCheck': '7.1', 'valid': True}} from=::1,59914, task_id=167fd692-ebe9-4d41-9e11-f1866541f310 (api:52)
2018-09-20 17:14:37,621+0530 INFO  (jsonrpc/6) [vdsm.api] START multipath_health() from=::1,59914, task_id=c7c66258-a39c-4d29-b293-19216f6d9874 (api:46)




Attaching the detailed vdsm and engine log

Comment 11 bipin 2018-09-20 12:16:59 UTC

Created attachment 1485115 [details]
VDSM log

Comment 12 bipin 2018-09-20 12:18:09 UTC

Created attachment 1485116 [details]
Engine.log

Comment 13 SATHEESARAN 2018-09-25 10:43:09 UTC

Created attachment 1486710 [details]
engine.log

Comment 14 bipin 2018-10-08 10:46:40 UTC

Tested with rhv-4.2.7.2-0.1.el7ev.noarch and could see the below issue.

2018-10-08 15:58:36,029+05 ERROR [org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery] (default task-34) [8f355838-c434-4cb6-a434-af1ddfbdbb37] Query 'GetGlusterVolumeProfileInfoQuery' failed: nul
l
2018-10-08 15:58:36,029+05 ERROR [org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery] (default task-34) [8f355838-c434-4cb6-a434-af1ddfbdbb37] Exception: java.lang.NullPointerException
        at org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery.populateBrickNames(GetGlusterVolumeProfileInfoQuery.java:44) [bll.jar:]
        at org.ovirt.engine.core.bll.gluster.GetGlusterVolumeProfileInfoQuery.executeQueryCommand(GetGlusterVolumeProfileInfoQuery.java:36) [bll.jar:]
        at org.ovirt.engine.core.bll.QueriesCommandBase.executeCommand(QueriesCommandBase.java:106) [bll.jar:]
        at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33) [dal.jar:]
        at org.ovirt.engine.core.bll.executor.DefaultBackendQueryExecutor.execute(DefaultBackendQueryExecutor.java:14) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runQueryImpl(Backend.java:538) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runQuery(Backend.java:507) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor185.invoke(Unknown Source) [:1.8.0_181]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_181]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_181]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
        at org.jboss.as.weld.ejb.DelegatingInterceptorInvocationContext.proceed(DelegatingInterceptorInvocationContext.java:92) [wildfly-weld-ejb-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.weld.interceptor.proxy.WeldInvocationContextImpl.interceptorChainCompleted(WeldInvocationContextImpl.java:124) [weld-core-impl.jar:2.4.7.Final-redhat-1]
        at org.jboss.weld.interceptor.proxy.WeldInvocationContextImpl.proceed(WeldInvocationContextImpl.java:143) [weld-core-impl.jar:2.4.7.Final-redhat-1]
        at org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(LoggingInterceptor.java:12) [common.jar:]
        at sun.reflect.GeneratedMethodAccessor66.invoke(Unknown Source) [:1.8.0_181]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_181]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_181]
        at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73) [weld-core-impl.jar:2.4.7.Final-redhat-1]
        at org.jboss.weld.interceptor.proxy.WeldInvocationContextImpl.invokeNext(WeldInvocationContextImpl.java:109) [weld-core-impl.jar:2.4.7.Final-redhat-1]
        at org.jboss.weld.interceptor.proxy.WeldInvocationContextImpl.proceed(WeldInvocationContextImpl.java:141) [weld-core-impl.jar:2.4.7.Final-redhat-1]
        at org.jboss.weld.bean.InterceptorImpl.intercept(InterceptorImpl.java:113) [weld-core-impl.jar:2.4.7.Final-redhat-1]
        at org.jboss.as.weld.ejb.DelegatingInterceptorInvocationContext.proceed(DelegatingInterceptorInvocationContext.java:82) [wildfly-weld-ejb-7.1.4.GA-redhat-1.jar:7.1.4.GA-redhat-1]
        at org.jboss.as.weld.interceptors.EjbComponentInterceptorSupport.delegateInterception(EjbComponentInterceptorSupport.java:60)
        at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:76)
        at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:88)
        at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:101)
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
        at org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerInterceptor.aroundInvoke(CorrelationIdTrackerInterceptor.java:13) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor139.invoke(Unknown Source) [:1.8.0_181]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_181]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_181]

Comment 15 bipin 2018-10-08 11:14:07 UTC

Created attachment 1491620 [details]
Engine.log

Comment 16 SATHEESARAN 2018-10-15 08:50:29 UTC

This issue is still seen with RHV 4.2.7-2

Comment 17 SATHEESARAN 2018-11-05 17:00:07 UTC

As this bug is re-opened, removing the doc_text related to the bug_fix and marking it for known_issue

Comment 18 Sandro Bonazzola 2019-01-28 09:43:37 UTC

This bug has not been marked as blocker for oVirt 4.3.0.
Since we are releasing it tomorrow, January 29th, this bug has been re-targeted to 4.3.1.

Comment 19 Gobinda Das 2019-11-12 12:22:48 UTC

kaustav, any update on this?

Comment 20 RHEL Program Management 2019-11-12 12:22:58 UTC

The documentation text flag should only be set after 'doc text' field is provided. Please provide the documentation text and set the flag to '?' again.

Comment 21 bipin 2019-11-22 10:26:48 UTC

This works in rhv 4.3.7. So closing the bug accordingly.
Attaching the screenshot

Comment 22 bipin 2019-11-22 10:27:35 UTC

Created attachment 1638663 [details]
RHV-M_UI