Re: [ovirt-users] [ovirt-devel] vdsm vds.dispatcher [Solved]

[Gary Pedretty]

The latest release 4.1 solved this issue.

gary



Gary Pedrettyg...@ravnalaska.net
Systems Manager  www.flyravn.com
Ravn Alaska   /\907-450-7251
5245 Airport Industrial Road /  \/\ 907-450-7238 fax
Fairbanks, Alaska  99709/\  /\ \ Second greatest commandment
Serving Alaska's Interior  /  \/  /\  \ \/\   "Love your neighbor as
White white everywhere, must be winter  yourself” Matt 22:39






> On Aug 30, 2017, at 11:34 AM, Gary Pedretty  wrote:
> 
> The bug I assumed this was related to is.
> 
> Bug 1417708 - ovirt-ha-agent should reuse json-rpc connections  
> 
> 
> This is a glusterized 4 host self hosted engine setup.  All storage domains 
> are glusterfs replica 3 volumes on 3 of the 4 hosts that are part of the 
> cluster.
> 
> Centos 3.10.0-514.26.2.el7.x86_64
> 
> vdsm-4.18.21-1.el7.centos.x86_64
> libvirt-2.0.0-10.el7_3.9.x86_64
> glusterfs-3.7.20-1.el7.x86_64
> qemu-kvm-tools-ev-2.6.0-28.el7_3.3.1.x86_64
> 
> Host and engine are all updated to the latest versions
> 
> Here are sample of messages log, vdsm,log, supervdsm.log and mom.log
> 
> messages
> 
> Aug 28 01:20:11 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:16 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:16 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:19 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:22 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:24 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:37 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:41 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:41 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:44 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:47 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> Aug 28 01:20:49 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
> reading data: unexpected eof
> 
> vdsm.log
> 
> Thread-316519::DEBUG::2017-08-28 
> 01:21:13,242::bindingxmlrpc::319::vds::(wrapper) client [::1]
> Thread-316519::DEBUG::2017-08-28 
> 01:21:13,242::task::597::Storage.TaskManager.Task::(_updateState) 
> Task=`7c850537-b9e2-4e4b-b346-5fc8ba40f2d1`::moving from state
> init -> state preparing
> Thread-316519::INFO::2017-08-28 
> 01:21:13,242::logUtils::49::dispatcher::(wrapper) Run and protect: 
> repoStats(options=None)
> Thread-316519::INFO::2017-08-28 
> 01:21:13,243::logUtils::52::dispatcher::(wrapper) Run and protect: repoStats, 
> Return
> response: {u'5e39db25-561f-490a-81b6-46a7225f02b6': {'code': 0, 'actual': 
> True, 'version': 0, 'acquired': True, 'delay': '0.000833501', 'lastCheck': 
> '1.1', 'valid': True}, u'403df7fb-6cff-46e1-8e04-41213fbc0e6e': {'code': 0, 
> 'actual': True, 'version': 3, 'acquired': False, 'delay': '0.000893509', 
> 'lastCheck': '1.1', 'valid': True}, u'cf2f4c75-966b-4f69-90a2-d8e7d21fc052': 
> {'code': 0, 'actual': True, 'version':
> 3, 'acquired': True, 'delay': '0.000776587', 'lastCheck': '1.0', 'valid': 
> True}, u'6654cb0c-3e57-42ca-b996-3660a3d32a43': {'code': 0, 'actual': True, 
> 'version': 3, 'acquired': True, 'delay': '0.000513211', 'lastCheck': '1.1', 
> 'valid': True}, u'2bf8f623-1d82-444e-ae16-d32e5fe4dc9e': {'code': 0, 
> 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000493711', 
> 'lastCheck': '1.3', 'valid':
> True}, u'feaebec7-aae3-45b5-9684-1feedede7bec': {'code': 0, 'actual': True, 
> 'version': 0, 'acquired': True, 'delay':
> '0.000512272', 'lastCheck': '1.1', 'valid': True}}
> Thread-316519::DEBUG::2017-08-28 
> 01:21:13,243::task::1193::Storage.TaskManager.Task::(prepare) 
> Task=`7c850537-b9e2-4e4b-b346-5fc8ba40f2d1`::finished: 
> {u'5e39db25-561f-490a-81b6-46a7225f02b6': {'code':
> 0, 'actual': True, 'version': 0,
> 'acquired': True, 'delay': '0.000833501', 'lastCheck': '1.1', 'valid': True}, 
> u'403df7fb-6cff-46e1-8e04-41213fbc0e6e': {'code': 0, 'actual': True, 
> 'version': 3, 'acquired': False, 'delay': '0.000893509', 'lastCheck': '1.1', 
> 'valid': True}, u'cf2f4c75-966b-4f69-90a2-d8e7d21fc052': {'code': 0, 
> 'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000776587', 
> 'lastCheck': '1.0', 

Re: [ovirt-users] [ovirt-devel] vdsm vds.dispatcher

[Gary Pedretty]

By someone, I assume you mean some other process running on the host, or 
possibly the engine?

Gary



Gary Pedrettyg...@ravnalaska.net 

Systems Manager  www.flyravn.com 

Ravn Alaska   /\907-450-7251
5245 Airport Industrial Road /  \/\ 907-450-7238 fax
Fairbanks, Alaska  99709/\  /\ \ Second greatest commandment
Serving All of Alaska  /  \/  /\  \ \/\   “Love your neighbor as
Green, green as far as the eyes can see yourself” Matt 22:39





> On Aug 31, 2017, at 6:17 AM, Martin Sivak  > wrote:
> 
> One more thing:
> 
> MOM's getStatistics is actually called by VDSM stats reporting code,
> so my guess here is that someone queries VDSM for stats pretty hard,
> VDSM then asks MOM for details.
> 
> Martin
> 
> On Thu, Aug 31, 2017 at 4:14 PM, Martin Sivak  > wrote:
>> Hi,
>> 
>>> 2017-08-27 23:15:41,199 - mom.RPCServer - INFO - ping()
>>> 2017-08-27 23:15:41,200 - mom.RPCServer - INFO - getStatistics()
>>> 2017-08-27 23:15:43,946 - mom.RPCServer - INFO - ping()
>>> 2017-08-27 23:15:43,947 - mom.RPCServer - INFO - getStatistics()
>> 
>> These are logs from mom's RPC server, someone is calling MOM way too
>> often. Well about 25 times per minute if my math is right.
>> 
>> The only client I know about is actually VDSM.
>> 
>> Martin
>> 
>> 
>> On Mon, Aug 28, 2017 at 9:17 AM, Gary Pedretty > > wrote:
>>> Be glad to provide logs to help diagnose this.  I see nothing unusual in the
>>> vdsm.log
>>> 
>>> mom.log shows the following almost as frequently as the messages log entries
>>> 
>>> 2017-08-27 23:15:41,199 - mom.RPCServer - INFO - ping()
>>> 2017-08-27 23:15:41,200 - mom.RPCServer - INFO - getStatistics()
>>> 2017-08-27 23:15:43,946 - mom.RPCServer - INFO - ping()
>>> 2017-08-27 23:15:43,947 - mom.RPCServer - INFO - getStatistics()
>>> 
>>> 

___
Devel mailing list
de...@ovirt.org 
http://lists.ovirt.org/mailman/listinfo/devel 
___
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users

Re: [ovirt-users] [ovirt-devel] vdsm vds.dispatcher

[Gary Pedretty]

The bug I assumed this was related to is.

Bug 1417708 - ovirt-ha-agent should reuse json-rpc connections  


This is a glusterized 4 host self hosted engine setup.  All storage domains are 
glusterfs replica 3 volumes on 3 of the 4 hosts that are part of the cluster.

Centos 3.10.0-514.26.2.el7.x86_64

vdsm-4.18.21-1.el7.centos.x86_64
libvirt-2.0.0-10.el7_3.9.x86_64
glusterfs-3.7.20-1.el7.x86_64
qemu-kvm-tools-ev-2.6.0-28.el7_3.3.1.x86_64

Host and engine are all updated to the latest versions

Here are sample of messages log, vdsm,log, supervdsm.log and mom.log

messages

Aug 28 01:20:11 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:16 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:16 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:19 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:22 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:24 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:37 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:41 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:41 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:44 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:47 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof
Aug 28 01:20:49 fai-kvm-1 journal: vdsm vds.dispatcher ERROR SSL error during 
reading data: unexpected eof

vdsm.log

Thread-316519::DEBUG::2017-08-28 
01:21:13,242::bindingxmlrpc::319::vds::(wrapper) client [::1]
Thread-316519::DEBUG::2017-08-28 
01:21:13,242::task::597::Storage.TaskManager.Task::(_updateState) 
Task=`7c850537-b9e2-4e4b-b346-5fc8ba40f2d1`::moving from state
init -> state preparing
Thread-316519::INFO::2017-08-28 
01:21:13,242::logUtils::49::dispatcher::(wrapper) Run and protect: 
repoStats(options=None)
Thread-316519::INFO::2017-08-28 
01:21:13,243::logUtils::52::dispatcher::(wrapper) Run and protect: repoStats, 
Return
response: {u'5e39db25-561f-490a-81b6-46a7225f02b6': {'code': 0, 'actual': True, 
'version': 0, 'acquired': True, 'delay': '0.000833501', 'lastCheck': '1.1', 
'valid': True}, u'403df7fb-6cff-46e1-8e04-41213fbc0e6e': {'code': 0, 'actual': 
True, 'version': 3, 'acquired': False, 'delay': '0.000893509', 'lastCheck': 
'1.1', 'valid': True}, u'cf2f4c75-966b-4f69-90a2-d8e7d21fc052': {'code': 0, 
'actual': True, 'version':
3, 'acquired': True, 'delay': '0.000776587', 'lastCheck': '1.0', 'valid': 
True}, u'6654cb0c-3e57-42ca-b996-3660a3d32a43': {'code': 0, 'actual': True, 
'version': 3, 'acquired': True, 'delay': '0.000513211', 'lastCheck': '1.1', 
'valid': True}, u'2bf8f623-1d82-444e-ae16-d32e5fe4dc9e': {'code': 0, 'actual': 
True, 'version': 3, 'acquired': True, 'delay': '0.000493711', 'lastCheck': 
'1.3', 'valid':
True}, u'feaebec7-aae3-45b5-9684-1feedede7bec': {'code': 0, 'actual': True, 
'version': 0, 'acquired': True, 'delay':
'0.000512272', 'lastCheck': '1.1', 'valid': True}}
Thread-316519::DEBUG::2017-08-28 
01:21:13,243::task::1193::Storage.TaskManager.Task::(prepare) 
Task=`7c850537-b9e2-4e4b-b346-5fc8ba40f2d1`::finished: 
{u'5e39db25-561f-490a-81b6-46a7225f02b6': {'code':
0, 'actual': True, 'version': 0,
'acquired': True, 'delay': '0.000833501', 'lastCheck': '1.1', 'valid': True}, 
u'403df7fb-6cff-46e1-8e04-41213fbc0e6e': {'code': 0, 'actual': True, 'version': 
3, 'acquired': False, 'delay': '0.000893509', 'lastCheck': '1.1', 'valid': 
True}, u'cf2f4c75-966b-4f69-90a2-d8e7d21fc052': {'code': 0, 'actual': True, 
'version': 3, 'acquired': True, 'delay': '0.000776587', 'lastCheck': '1.0', 
'valid': True}, u'6654cb0c-3e57-42ca-b996-3660a3d32a43': {'code': 0, 'actual': 
True, 'version': 3, 'acquired': True, 'delay': '0.000513211', 'lastCheck': 
'1.1', 'valid': True}, u'2bf8f623-1d82-444e-ae16-d32e5fe4dc9e':
{'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay': 
'0.000493711', 'lastCheck': '1.3', 'valid': True}, 
u'feaebec7-aae3-45b5-9684-1feedede7bec':
{'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': 
'0.000512272', 'lastCheck': '1.1', 'valid': True}}
Thread-316519::DEBUG::2017-08-28 
01:21:13,243::task::597::Storage.TaskManager.Task::(_updateState) 
Task=`7c850537-b9e2-4e4b-b346-5fc8ba40f2d1`::moving from state
preparing -> state finished
Thread-316519::DEBUG::2017-08-28 
01:21:13,243::resourceManager::952::Storage.ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-316519::DEBUG::2017-08-28 
01:21:13,243::resourceManager::989::Storage.ResourceManager.Owner::(cancelAll)