Re: [ovirt-devel] [vdsm] Connection refused when talking to jsonrpc
Adding Piotr On Tue, Nov 8, 2016 at 5:52 PM, Martin Sivak <msivak@redhat.com> wrote:
Hi,
mom-vdsm.service contains:
Requires=vdsmd.service After=vdsmd.service
So when Shira restarted vdsm, mom was also restarted.
[journalctl --unit vdsmd] Nov 08 18:25:27 RHEL7.2Server systemd[1]: Stopping Virtual Desktop Server Manager... Nov 08 18:25:27 RHEL7.2Server vdsmd_init_common.sh[3053]: vdsm: Running run_final_hooks Nov 08 18:25:27 RHEL7.2Server systemd[1]: Starting Virtual Desktop Server Manager...
[journalctl --unit mom-vdsm] Nov 08 18:17:23 RHEL7.2Server systemd[1]: Starting MOM instance configured for VDSM purposes... Nov 08 18:25:16 RHEL7.2Server systemd[1]: Stopping MOM instance configured for VDSM purposes... Nov 08 18:25:29 RHEL7.2Server systemd[1]: Started MOM instance configured for VDSM purposes.
But mom then immediately failed with:
2016-11-08 18:25:08,008 - mom.RPCServer - INFO - ping() 2016-11-08 18:25:08,010 - mom.RPCServer - INFO - getStatistics() 2016-11-08 18:25:17,028 - mom.RPCServer - INFO - RPC Server ending 2016-11-08 18:25:24,705 - mom.GuestManager - INFO - Guest Manager ending 2016-11-08 18:25:26,575 - mom.HostMonitor - INFO - Host Monitor ending
2016-11-08 18:25:29,869 - mom - INFO - MOM starting 2016-11-08 18:25:29,905 - mom.HostMonitor - INFO - Host Monitor starting 2016-11-08 18:25:29,905 - mom - INFO - hypervisor interface vdsmjsonrpcbulk 2016-11-08 18:25:30,029 - mom.vdsmInterface - ERROR - Cannot connect to VDSM! [Errno 111] Connection refused 2016-11-08 18:25:30,030 - mom - ERROR - Failed to initialize MOM threads Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 29, in run hypervisor_iface = self.get_hypervisor_interface() File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 217, in get_hypervisor_interface return module.instance(self.config) File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/ vdsmjsonrpcbulkInterface.py", line 47, in instance return JsonRpcVdsmBulkInterface() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/ vdsmjsonrpcbulkInterface.py", line 29, in __init__ super(JsonRpcVdsmBulkInterface, self).__init__() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/ vdsmjsonrpcInterface.py", line 43, in __init__ .orRaise(RuntimeError, 'No connection to VDSM.') File "/usr/lib/python2.7/site-packages/mom/optional.py", line 28, in orRaise raise exception(*args, **kwargs) RuntimeError: No connection to VDSM.
The question here is, how much time does VDSM need to allow jsonrpc to connect and request a ping and list of VMs?
Martin _______________________________________________ vdsm-devel mailing list -- vdsm-devel@lists.fedorahosted.org To unsubscribe send an email to vdsm-devel-leave@lists.fedorahosted.org
On Tue, Nov 8, 2016 at 8:51 PM, Martin Perina <mperina@redhat.com> wrote:
Adding Piotr
On Tue, Nov 8, 2016 at 5:52 PM, Martin Sivak <msivak@redhat.com> wrote:
Hi,
mom-vdsm.service contains:
Requires=vdsmd.service After=vdsmd.service
So when Shira restarted vdsm, mom was also restarted.
[journalctl --unit vdsmd] Nov 08 18:25:27 RHEL7.2Server systemd[1]: Stopping Virtual Desktop Server Manager... Nov 08 18:25:27 RHEL7.2Server vdsmd_init_common.sh[3053]: vdsm: Running run_final_hooks Nov 08 18:25:27 RHEL7.2Server systemd[1]: Starting Virtual Desktop Server Manager...
[journalctl --unit mom-vdsm] Nov 08 18:17:23 RHEL7.2Server systemd[1]: Starting MOM instance configured for VDSM purposes... Nov 08 18:25:16 RHEL7.2Server systemd[1]: Stopping MOM instance configured for VDSM purposes... Nov 08 18:25:29 RHEL7.2Server systemd[1]: Started MOM instance configured for VDSM purposes.
But mom then immediately failed with:
2016-11-08 18:25:08,008 - mom.RPCServer - INFO - ping() 2016-11-08 18:25:08,010 - mom.RPCServer - INFO - getStatistics() 2016-11-08 18:25:17,028 - mom.RPCServer - INFO - RPC Server ending 2016-11-08 18:25:24,705 - mom.GuestManager - INFO - Guest Manager ending 2016-11-08 18:25:26,575 - mom.HostMonitor - INFO - Host Monitor ending
2016-11-08 18:25:29,869 - mom - INFO - MOM starting 2016-11-08 18:25:29,905 - mom.HostMonitor - INFO - Host Monitor starting 2016-11-08 18:25:29,905 - mom - INFO - hypervisor interface vdsmjsonrpcbulk 2016-11-08 18:25:30,029 - mom.vdsmInterface - ERROR - Cannot connect to VDSM! [Errno 111] Connection refused 2016-11-08 18:25:30,030 - mom - ERROR - Failed to initialize MOM threads Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 29, in run hypervisor_iface = self.get_hypervisor_interface() File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 217, in get_hypervisor_interface return module.instance(self.config) File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 47, in instance return JsonRpcVdsmBulkInterface() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 29, in __init__ super(JsonRpcVdsmBulkInterface, self).__init__() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcInterface.py", line 43, in __init__ .orRaise(RuntimeError, 'No connection to VDSM.') File "/usr/lib/python2.7/site-packages/mom/optional.py", line 28, in orRaise raise exception(*args, **kwargs) RuntimeError: No connection to VDSM.
The question here is, how much time does VDSM need to allow jsonrpc to connect and request a ping and list of VMs?
It depends on recovery logic in vdsm and it can take quite some time.
Please share vdsm logs so I could take a look?
Martin _______________________________________________ vdsm-devel mailing list -- vdsm-devel@lists.fedorahosted.org To unsubscribe send an email to vdsm-devel-leave@lists.fedorahosted.org
On Tue, Nov 8, 2016 at 10:31 PM, Piotr Kliczewski <pkliczew@redhat.com> wrote:
On Tue, Nov 8, 2016 at 8:51 PM, Martin Perina <mperina@redhat.com> wrote:
Adding Piotr
On Tue, Nov 8, 2016 at 5:52 PM, Martin Sivak <msivak@redhat.com> wrote:
Hi,
mom-vdsm.service contains:
Requires=vdsmd.service After=vdsmd.service
So when Shira restarted vdsm, mom was also restarted.
[journalctl --unit vdsmd] Nov 08 18:25:27 RHEL7.2Server systemd[1]: Stopping Virtual Desktop Server Manager... Nov 08 18:25:27 RHEL7.2Server vdsmd_init_common.sh[3053]: vdsm: Running run_final_hooks Nov 08 18:25:27 RHEL7.2Server systemd[1]: Starting Virtual Desktop Server Manager...
[journalctl --unit mom-vdsm] Nov 08 18:17:23 RHEL7.2Server systemd[1]: Starting MOM instance configured for VDSM purposes... Nov 08 18:25:16 RHEL7.2Server systemd[1]: Stopping MOM instance configured for VDSM purposes... Nov 08 18:25:29 RHEL7.2Server systemd[1]: Started MOM instance configured for VDSM purposes.
But mom then immediately failed with:
2016-11-08 18:25:08,008 - mom.RPCServer - INFO - ping() 2016-11-08 18:25:08,010 - mom.RPCServer - INFO - getStatistics() 2016-11-08 18:25:17,028 - mom.RPCServer - INFO - RPC Server ending 2016-11-08 18:25:24,705 - mom.GuestManager - INFO - Guest Manager ending 2016-11-08 18:25:26,575 - mom.HostMonitor - INFO - Host Monitor ending
2016-11-08 18:25:29,869 - mom - INFO - MOM starting 2016-11-08 18:25:29,905 - mom.HostMonitor - INFO - Host Monitor starting 2016-11-08 18:25:29,905 - mom - INFO - hypervisor interface vdsmjsonrpcbulk 2016-11-08 18:25:30,029 - mom.vdsmInterface - ERROR - Cannot connect to VDSM! [Errno 111] Connection refused 2016-11-08 18:25:30,030 - mom - ERROR - Failed to initialize MOM threads Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 29, in run hypervisor_iface = self.get_hypervisor_interface() File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 217, in get_hypervisor_interface return module.instance(self.config) File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/vdsmjsonrpcbulkInterface.py", line 47, in instance return JsonRpcVdsmBulkInterface() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/vdsmjsonrpcbulkInterface.py", line 29, in __init__ super(JsonRpcVdsmBulkInterface, self).__init__() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/vdsmjsonrpcInterface.py", line 43, in __init__ .orRaise(RuntimeError, 'No connection to VDSM.') File "/usr/lib/python2.7/site-packages/mom/optional.py", line 28, in orRaise raise exception(*args, **kwargs) RuntimeError: No connection to VDSM.
The question here is, how much time does VDSM need to allow jsonrpc to connect and request a ping and list of VMs?
It depends on recovery logic in vdsm and it can take quite some time.
Recovery is done in another thread and does not delay startup in any way. Same for storage init thread. We can minimize the delay for clients by opening the acceptor first thing during startup, so clients can connect immediately. The code is already sending error 99 (recovering or initializing) until both vm recovery and storage init is done. Nir
----- Original Message -----
From: "Piotr Kliczewski" <pkliczew@redhat.com> To: "Martin Perina" <mperina@redhat.com> Cc: "Francesco Romani" <fromani@redhat.com>, "Shira Maximov" <mshira@redhat.com>, "devel" <devel@ovirt.org> Sent: Tuesday, November 8, 2016 9:31:43 PM Subject: Re: [vdsm] Connection refused when talking to jsonrpc
2016-11-08 18:25:30,030 - mom - ERROR - Failed to initialize MOM threads Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 29, in run hypervisor_iface = self.get_hypervisor_interface() File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 217, in get_hypervisor_interface return module.instance(self.config) File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 47, in instance return JsonRpcVdsmBulkInterface() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 29, in __init__ super(JsonRpcVdsmBulkInterface, self).__init__() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcInterface.py", line 43, in __init__ .orRaise(RuntimeError, 'No connection to VDSM.') File "/usr/lib/python2.7/site-packages/mom/optional.py", line 28, in orRaise raise exception(*args, **kwargs) RuntimeError: No connection to VDSM.
The question here is, how much time does VDSM need to allow jsonrpc to connect and request a ping and list of VMs?
It depends on recovery logic in vdsm and it can take quite some time.
Please share vdsm logs so I could take a look?
+1 the most likely cause is the recovery still in progress, however I was expecting a different error, so worth looking at the logs. Bests, -- Francesco Romani Red Hat Engineering Virtualization R & D Phone: 8261328 IRC: fromani
On 9 Nov 2016, at 08:55, Francesco Romani <fromani@redhat.com> wrote:
----- Original Message -----
From: "Piotr Kliczewski" <pkliczew@redhat.com> To: "Martin Perina" <mperina@redhat.com> Cc: "Francesco Romani" <fromani@redhat.com>, "Shira Maximov" <mshira@redhat.com>, "devel" <devel@ovirt.org> Sent: Tuesday, November 8, 2016 9:31:43 PM Subject: Re: [vdsm] Connection refused when talking to jsonrpc
2016-11-08 18:25:30,030 - mom - ERROR - Failed to initialize MOM threads Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 29, in run hypervisor_iface = self.get_hypervisor_interface() File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 217, in get_hypervisor_interface return module.instance(self.config) File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 47, in instance return JsonRpcVdsmBulkInterface() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 29, in __init__ super(JsonRpcVdsmBulkInterface, self).__init__() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcInterface.py", line 43, in __init__ .orRaise(RuntimeError, 'No connection to VDSM.') File "/usr/lib/python2.7/site-packages/mom/optional.py", line 28, in orRaise raise exception(*args, **kwargs) RuntimeError: No connection to VDSM.
The question here is, how much time does VDSM need to allow jsonrpc to connect and request a ping and list of VMs?
It depends on recovery logic in vdsm and it can take quite some time.
Please share vdsm logs so I could take a look?
+1
the most likely cause is the recovery still in progress, however I was expecting a different error, so worth looking at the logs.
Isn’t the most likely cause by far a simple startup delay? We do open the listener “soon” and responds with code 99, but it’s still not instant of course
Bests,
-- Francesco Romani Red Hat Engineering Virtualization R & D Phone: 8261328 IRC: fromani _______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
Isn’t the most likely cause by far a simple startup delay? We do open the listener “soon” and responds with code 99, but it’s still not instant of course
That is possible of course and we handle those "errors" just fine. But connection refused never happened with xmlrpc. It might have been luck, but it always worked there :) Martin On Wed, Nov 9, 2016 at 9:11 AM, Michal Skrivanek <michal.skrivanek@redhat.com> wrote:
On 9 Nov 2016, at 08:55, Francesco Romani <fromani@redhat.com> wrote:
----- Original Message -----
From: "Piotr Kliczewski" <pkliczew@redhat.com> To: "Martin Perina" <mperina@redhat.com> Cc: "Francesco Romani" <fromani@redhat.com>, "Shira Maximov" <mshira@redhat.com>, "devel" <devel@ovirt.org> Sent: Tuesday, November 8, 2016 9:31:43 PM Subject: Re: [vdsm] Connection refused when talking to jsonrpc
2016-11-08 18:25:30,030 - mom - ERROR - Failed to initialize MOM threads Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 29, in run hypervisor_iface = self.get_hypervisor_interface() File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 217, in get_hypervisor_interface return module.instance(self.config) File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 47, in instance return JsonRpcVdsmBulkInterface() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 29, in __init__ super(JsonRpcVdsmBulkInterface, self).__init__() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcInterface.py", line 43, in __init__ .orRaise(RuntimeError, 'No connection to VDSM.') File "/usr/lib/python2.7/site-packages/mom/optional.py", line 28, in orRaise raise exception(*args, **kwargs) RuntimeError: No connection to VDSM.
The question here is, how much time does VDSM need to allow jsonrpc to connect and request a ping and list of VMs?
It depends on recovery logic in vdsm and it can take quite some time.
Please share vdsm logs so I could take a look?
+1
the most likely cause is the recovery still in progress, however I was expecting a different error, so worth looking at the logs.
Isn’t the most likely cause by far a simple startup delay? We do open the listener “soon” and responds with code 99, but it’s still not instant of course
Bests,
-- Francesco Romani Red Hat Engineering Virtualization R & D Phone: 8261328 IRC: fromani _______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
On Wed, Nov 9, 2016 at 9:48 AM, Martin Sivak <msivak@redhat.com> wrote:
Isn’t the most likely cause by far a simple startup delay? We do open the listener “soon” and responds with code 99, but it’s still not instant of course
That is possible of course and we handle those "errors" just fine. But connection refused never happened with xmlrpc. It might have been luck, but it always worked there :)
There is no difference how we open listening socket (it is used by both protocols) and I have seen the engine attempting to connect using both protocols before the socket was open. What is the time difference that you see?
Martin
On Wed, Nov 9, 2016 at 9:11 AM, Michal Skrivanek <michal.skrivanek@redhat.com> wrote:
On 9 Nov 2016, at 08:55, Francesco Romani <fromani@redhat.com> wrote:
----- Original Message -----
From: "Piotr Kliczewski" <pkliczew@redhat.com> To: "Martin Perina" <mperina@redhat.com> Cc: "Francesco Romani" <fromani@redhat.com>, "Shira Maximov" <
Sent: Tuesday, November 8, 2016 9:31:43 PM Subject: Re: [vdsm] Connection refused when talking to jsonrpc
2016-11-08 18:25:30,030 - mom - ERROR - Failed to initialize MOM
Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 29, in run hypervisor_iface = self.get_hypervisor_interface() File "/usr/lib/python2.7/site-packages/mom/__init__.py", line 217, in get_hypervisor_interface return module.instance(self.config) File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 47, in instance return JsonRpcVdsmBulkInterface() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcbulkInterface.py", line 29, in __init__ super(JsonRpcVdsmBulkInterface, self).__init__() File "/usr/lib/python2.7/site-packages/mom/HypervisorInterfaces/v dsmjsonrpcInterface.py", line 43, in __init__ .orRaise(RuntimeError, 'No connection to VDSM.') File "/usr/lib/python2.7/site-packages/mom/optional.py", line 28, in orRaise raise exception(*args, **kwargs) RuntimeError: No connection to VDSM.
The question here is, how much time does VDSM need to allow jsonrpc to connect and request a ping and list of VMs?
It depends on recovery logic in vdsm and it can take quite some time.
Please share vdsm logs so I could take a look?
+1
the most likely cause is the recovery still in progress, however I was expecting a different error, so worth looking at the logs.
Isn’t the most likely cause by far a simple startup delay? We do open
mshira@redhat.com>, "devel" <devel@ovirt.org> threads the listener “soon” and responds with code 99, but it’s still not instant of course
Bests,
-- Francesco Romani Red Hat Engineering Virtualization R & D Phone: 8261328 IRC: fromani _______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
----- Original Message -----
From: "Piotr Kliczewski" <pkliczew@redhat.com> To: "Martin Sivak" <msivak@redhat.com> Cc: "Michal Skrivanek" <michal.skrivanek@redhat.com>, "Francesco Romani" <fromani@redhat.com>, "Shira Maximov" <mshira@redhat.com>, "devel" <devel@ovirt.org> Sent: Wednesday, November 9, 2016 9:54:02 AM Subject: Re: [ovirt-devel] [vdsm] Connection refused when talking to jsonrpc
On Wed, Nov 9, 2016 at 9:48 AM, Martin Sivak <msivak@redhat.com> wrote:
Isn’t the most likely cause by far a simple startup delay? We do open the listener “soon” and responds with code 99, but it’s still not instant of course
That is possible of course and we handle those "errors" just fine. But connection refused never happened with xmlrpc. It might have been luck, but it always worked there :)
There is no difference how we open listening socket (it is used by both protocols) and I have seen the engine attempting to connect using both protocols before the socket was open. What is the time difference that you see?
Not sure I reproduced correctly, but it seems a race on startup. I got the same error on my box, and here it happens if mom tries to connect to the unix socket /var/run/vdsm/mom-vdsm.sock *before* that Vdsm creates it. Once vdsmd succesfully starts, a restart of mom-vdsm seems to fix all the issues. I'm not sure yet if that's all of it and how to handle with systemd dependencies. Perhaps Nir's suggestion past in the thread to notify systemd is a good first step in the right direction. HTH, -- Francesco Romani Red Hat Engineering Virtualization R & D Phone: 8261328 IRC: fromani
On 9 Nov 2016, at 09:57, Francesco Romani <fromani@redhat.com> wrote:
----- Original Message -----
From: "Piotr Kliczewski" <pkliczew@redhat.com> To: "Martin Sivak" <msivak@redhat.com> Cc: "Michal Skrivanek" <michal.skrivanek@redhat.com>, "Francesco Romani" <fromani@redhat.com>, "Shira Maximov" <mshira@redhat.com>, "devel" <devel@ovirt.org> Sent: Wednesday, November 9, 2016 9:54:02 AM Subject: Re: [ovirt-devel] [vdsm] Connection refused when talking to jsonrpc
On Wed, Nov 9, 2016 at 9:48 AM, Martin Sivak <msivak@redhat.com> wrote:
Isn’t the most likely cause by far a simple startup delay? We do open the listener “soon” and responds with code 99, but it’s still not instant of course
That is possible of course and we handle those "errors" just fine. But connection refused never happened with xmlrpc. It might have been luck, but it always worked there :)
There is no difference how we open listening socket (it is used by both protocols) and I have seen the engine attempting to connect using both protocols before the socket was open. What is the time difference that you see?
Not sure I reproduced correctly, but it seems a race on startup. I got the same error on my box, and here it happens if mom tries to connect to the unix socket /var/run/vdsm/mom-vdsm.sock *before* that Vdsm creates it. Once vdsmd succesfully starts, a restart of mom-vdsm seems to fix all the issues.
I'm not sure yet if that's all of it and how to handle with systemd dependencies. Perhaps Nir's suggestion past in the thread to notify systemd is a good first step in the right direction.
not sure we would need to wait for recovery to finish if you want to be really nice to “dumb” clients that would take too long though I think mom needs a fix in addition anyway
HTH,
-- Francesco Romani Red Hat Engineering Virtualization R & D Phone: 8261328 IRC: fromani
participants (6)
-
Francesco Romani -
Martin Perina -
Martin Sivak -
Michal Skrivanek -
Nir Soffer -
Piotr Kliczewski