Bug 1215236

Summary: "vds.MultiProtocolAcceptor ERROR Unhandled exception" and "SSLError: unexpected eof"
Product: Red Hat Enterprise Virtualization Manager Reporter: Robert McSwain <rmcswain>
Component: vdsmAssignee: Piotr Kliczewski <pkliczew>
Status: CLOSED ERRATA QA Contact: Petr Kubica <pkubica>
Severity: high Docs Contact:
Priority: unspecified    
Version: 3.5.0CC: ahoness, bazulay, colin.stuck, ecohen, lpeer, lsurette, mzheng, oourfali, pkliczew, pstehlik, pzhukov, rmcswain, sherold, s.kieske, yeylon
Target Milestone: ---Keywords: ZStream
Target Release: 3.5.4   
Hardware: x86_64   
OS: Linux   
Whiteboard: infra
Fixed In Version: vdsm-4.16.21-1.el6ev Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-09-03 18:12:37 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1229859    
Bug Blocks:    

Description Robert McSwain 2015-04-24 17:17:14 UTC 
Description of problem: 
Host went non-operational, /var/log/messages log shows "vds.MultiProtocolAcceptor ERROR Unhandled exception"

and vdsm.log shows Unexpected EOF:

Detector thread::ERROR::2015-04-15 23:58:27,051::protocoldetector::90::vds.MultiProtocolAcceptor::(serve_forever) Unhandled exception
Traceback (most recent call last):
  File "/usr/share/vdsm/protocoldetector.py", line 86, in serve_forever
    self._process_events()
  File "/usr/share/vdsm/protocoldetector.py", line 105, in _process_events
    self._handle_connection_read(fd)
  File "/usr/share/vdsm/protocoldetector.py", line 225, in _handle_connection_read
    data = client_socket.recv(self._required_size, socket.MSG_PEEK)
  File "/usr/lib/python2.6/site-packages/vdsm/sslutils.py", line 58, in read
    self._data = self.connection.read(size)
  File "/usr/lib64/python2.6/site-packages/M2Crypto/SSL/Connection.py", line 229, in read
    return self._read_nbio(size)
  File "/usr/lib64/python2.6/site-packages/M2Crypto/SSL/Connection.py", line 218, in _read_nbio
    return m2.ssl_read_nbio(self.ssl, size)
SSLError: unexpected eof
Detector thread::ERROR::2015-04-15 23:58:27,052::protocoldetector::90::vds.MultiProtocolAcceptor::(serve_forever) Unhandled exception
Traceback (most recent call last):
  File "/usr/share/vdsm/protocoldetector.py", line 86, in serve_forever
    self._process_events()
  File "/usr/share/vdsm/protocoldetector.py", line 105, in _process_events
    self._handle_connection_read(fd)
  File "/usr/share/vdsm/protocoldetector.py", line 225, in _handle_connection_read
    data = client_socket.recv(self._required_size, socket.MSG_PEEK)
  File "/usr/lib/python2.6/site-packages/vdsm/sslutils.py", line 58, in read
    self._data = self.connection.read(size)
  File "/usr/lib64/python2.6/site-packages/M2Crypto/SSL/Connection.py", line 229, in read
    return self._read_nbio(size)
  File "/usr/lib64/python2.6/site-packages/M2Crypto/SSL/Connection.py", line 218, in _read_nbio
    return m2.ssl_read_nbio(self.ssl, size)
SSLError: unexpected eof
Detector thread::ERROR::2015-04-15 23:58:27,052::protocoldetector::90::vds.MultiProtocolAcceptor::(serve_forever) Unhandled exception
Traceback (most recent call last):
  File "/usr/share/vdsm/protocoldetector.py", line 86, in serve_forever
    self._process_events()
  File "/usr/share/vdsm/protocoldetector.py", line 105, in _process_events
    self._handle_connection_read(fd)
  File "/usr/share/vdsm/protocoldetector.py", line 225, in _handle_connection_read
    data = client_socket.recv(self._required_size, socket.MSG_PEEK)
  File "/usr/lib/python2.6/site-packages/vdsm/sslutils.py", line 58, in read
    self._data = self.connection.read(size)
  File "/usr/lib64/python2.6/site-packages/M2Crypto/SSL/Connection.py", line 229, in read
    return self._read_nbio(size)
  File "/usr/lib64/python2.6/site-packages/M2Crypto/SSL/Connection.py", line 218, in _read_nbio
    return m2.ssl_read_nbio(self.ssl, size)
SSLError: unexpected eof

Version-Release number of selected component (if applicable):
RHEL 6.6 host
vdsm-4.16.8.1-6.el6ev.x86_64                                Tue Feb 17 12:56:06 2015
vdsm-cli-4.16.8.1-6.el6ev.noarch                            Tue Feb 17 12:56:05 2015
vdsm-jsonrpc-4.16.8.1-6.el6ev.noarch                        Tue Feb 17 12:56:05 2015
vdsm-python-4.16.8.1-6.el6ev.noarch                         Tue Feb 17 12:56:05 2015
vdsm-python-zombiereaper-4.16.8.1-6.el6ev.noarch            Tue Feb 17 12:56:05 2015
vdsm-xmlrpc-4.16.8.1-6.el6ev.noarch                         Tue Feb 17 12:56:05 2015
vdsm-yajsonrpc-4.16.8.1-6.el6ev.noarch                      Tue Feb 17 12:56:05 2015


How reproducible:
Unknown

Steps to Reproduce:
Unknown

Actual results:
Host goes non-responsive, resolvable by restarting vdsmd.

Expected results:
vdsm doesn't receive an eof 

Additional info:
Logs to be added in a private comment
Comment 2 Piotr Kliczewski 2015-04-27 06:20:42 UTC 
Please provide steps how to reproduce it.
Comment 3 Robert McSwain 2015-04-28 16:44:53 UTC 
Piotr,

Unfortunately the customer doesn't know how this happened or what resolved it. They noticed that without restarting vdsmd the host came back into function on its own. I'll see what else they can provide us but it doesn't look like they know why it happened or why it resolved.
Comment 8 Colin Stuck 2015-06-09 16:11:14 UTC 
My server is showing the same problem again.

From the Hypervisor's '/var/log/messages':
Jun  9 03:40:17 [vdsm.err] vds.MultiProtocolAcceptor ERROR Unhandled exception
Jun  9 03:40:17 [vdsm.err] vds.MultiProtocolAcceptor ERROR Unhandled exception
Jun  9 03:40:17 [vdsm.err] vds.MultiProtocolAcceptor ERROR Unhandled exception
Jun  9 03:40:17 [vdsm.err] vds.MultiProtocolAcceptor ERROR Unhandled exception
Jun  9 03:40:17 [vdsm.err] vds.MultiProtocolAcceptor ERROR Unhandled exception
Jun  9 03:40:17 [vdsm.err] vds.MultiProtocolAcceptor ERROR Unhandled exception
Jun  9 03:40:17 [vdsm.err] vds.MultiProtocolAcceptor ERROR Unhandled exception


From the hypervisor's '/var/log/vdsm/vdsm.log':
Detector thread::ERROR::2015-06-09 12:01:02,132::protocoldetector::90::vds.MultiProtocolAcceptor::(serve_forever) Unhandled exception
Traceback (most recent call last):
  File "/usr/share/vdsm/protocoldetector.py", line 86, in serve_forever
    self._process_events()
  File "/usr/share/vdsm/protocoldetector.py", line 105, in _process_events
    self._handle_connection_read(fd)
  File "/usr/share/vdsm/protocoldetector.py", line 225, in _handle_connection_read
    data = client_socket.recv(self._required_size, socket.MSG_PEEK)
  File "/usr/lib/python2.6/site-packages/vdsm/sslutils.py", line 58, in read
    self._data = self.connection.read(size)
  File "/usr/lib64/python2.6/site-packages/M2Crypto/SSL/Connection.py", line 229, in read
    return self._read_nbio(size)
  File "/usr/lib64/python2.6/site-packages/M2Crypto/SSL/Connection.py", line 218, in _read_nbio
    return m2.ssl_read_nbio(self.ssl, size)
SSLError: unexpected eof

[root@~]# cat /etc/redhat-release
Red Hat Enterprise Linux Server release 6.6 (Santiago)

[root@~]# rpm -qa|grep -i vdsm
vdsm-python-zombiereaper-4.16.8.1-6.el6ev.noarch
vdsm-xmlrpc-4.16.8.1-6.el6ev.noarch
vdsm-yajsonrpc-4.16.8.1-6.el6ev.noarch
vdsm-python-4.16.8.1-6.el6ev.noarch
vdsm-4.16.8.1-6.el6ev.x86_64
vdsm-cli-4.16.8.1-6.el6ev.noarch
vdsm-jsonrpc-4.16.8.1-6.el6ev.noarch
Comment 9 Piotr Kliczewski 2015-06-10 07:38:37 UTC 
Please provide engine.log when the failure occurred.
Comment 10 Piotr Kliczewski 2015-06-11 10:01:06 UTC 
Issue reproduced and a fix posted.
Comment 11 Petr Kubica 2015-07-23 08:00:15 UTC 
Hi, could you provide steps to reproduce ?

Only what I found is in https://gerrit.ovirt.org/#/c/42351/
command vdsClient 0 getVdsCaps

it causes an exception on stdout:
Traceback (most recent call last):
  File "/usr/share/vdsm/vdsClient.py", line 2683, in <module>
    code, message = commands[command][0](commandArgs)
  File "/usr/share/vdsm/vdsClient.py", line 446, in do_getCap
    return self.ExecAndExit(self.s.getVdsCapabilities())
  File "/usr/lib64/python2.7/xmlrpclib.py", line 1224, in __call__
    return self.__send(self.__name, args)
  File "/usr/lib64/python2.7/xmlrpclib.py", line 1578, in __request
    verbose=self.__verbose
  File "/usr/lib64/python2.7/xmlrpclib.py", line 1264, in request
    return self.single_request(host, handler, request_body, verbose)
  File "/usr/lib64/python2.7/xmlrpclib.py", line 1294, in single_request
    response = h.getresponse(buffering=True)
  File "/usr/lib64/python2.7/httplib.py", line 1045, in getresponse
    response.begin()
  File "/usr/lib64/python2.7/httplib.py", line 409, in begin
    version, status, reason = self._read_status()
  File "/usr/lib64/python2.7/httplib.py", line 365, in _read_status
    line = self.fp.readline(_MAXLINE + 1)
  File "/usr/lib64/python2.7/socket.py", line 476, in readline
    data = self._sock.recv(self._rbufsize)
error: [Errno 104] Connection reset by peer

in vdsm log I didn't found any exception:
Detector thread::DEBUG::2015-07-23 09:55:07,056::protocoldetector::207::vds.MultiProtocolAcceptor::(_process_handshake) Error during handshake: http request
Detector thread::DEBUG::2015-07-23 09:55:07,056::protocoldetector::201::vds.MultiProtocolAcceptor::(_remove_connection) Connection removed from 127.0.0.1:34692

Is it okay ?
Comment 12 Piotr Kliczewski 2015-07-23 09:15:44 UTC 
It looks ok. Connection was closed by vdsm due to:

Error during handshake: http request

and there was no infinite.
Comment 13 Petr Kubica 2015-07-23 09:41:40 UTC 
Ok, so verified in vdsm-4.16.22-1.el7ev.x86_64
Comment 15 errata-xmlrpc 2015-09-03 18:12:37 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2015-1729.html