Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

ssl.SSLEOFError when using HTTPS #439

Open
andy-maier opened this issue Nov 28, 2023 · 3 comments
Open

ssl.SSLEOFError when using HTTPS #439

andy-maier opened this issue Nov 28, 2023 · 3 comments
Assignees
@andy-maier
Labels
area: code discussion needed type: bug Something isn't working
Milestone
2.1.0

Comments

@andy-maier
Copy link
Member

andy-maier commented Nov 28, 2023 •
edited
Loading

Occasionally, the exporter fails with this traceback:

Traceback (most recent call last):
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 138, in run
    self.finish_response()
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 184, in finish_response
    self.write(data)
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 288, in write
    self.send_headers()
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 346, in send_headers
    self.send_preamble()
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 268, in send_preamble
    self._write(
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 467, in _write
    result = self.stdout.write(data)
  File "/usr/lib/python3.10/socketserver.py", line 826, in write
    self._sock.sendall(b)
  File "/usr/lib/python3.10/ssl.py", line 1237, in sendall
    v = self.send(byte_view[count:])
  File "/usr/lib/python3.10/ssl.py", line 1206, in send
    return self._sslobj.write(data)
ssl.SSLEOFError: EOF occurred in violation of protocol (_ssl.c:2426)
Traceback (most recent call last):
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 138, in run
    self.finish_response()
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 184, in finish_response
    self.write(data)
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 288, in write
    self.send_headers()
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 346, in send_headers
    self.send_preamble()
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 268, in send_preamble
    self._write(
  File "/usr/lib/python3.10/wsgiref/handlers.py", line 467, in _write
    result = self.stdout.write(data)
  File "/usr/lib/python3.10/socketserver.py", line 826, in write
    self._sock.sendall(b)
  File "/usr/lib/python3.10/ssl.py", line 1237, in sendall
    v = self.send(byte_view[count:])
  File "/usr/lib/python3.10/ssl.py", line 1206, in send
    return self._sslobj.write(data)
ssl.SSLEOFError: EOF occurred in violation of protocol (_ssl.c:2426)

This happened in the L&M team when using version 1.5.0b3, which already had the exception handling around start_http_server() so we know now that it is not raised in that function, but in the HTTP server thread.

See also issue #397 for the earlier occurrence of this error.
@andy-maier andy-maier self-assigned this Nov 28, 2023
@andy-maier andy-maier added type: bug Something isn't working area: code labels Nov 28, 2023
@andy-maier andy-maier added this to the 1.6.0 milestone Nov 28, 2023
@andy-maier
Copy link
Member Author

andy-maier commented Nov 28, 2023 •
edited
Loading

Investigation shows that these exceptions are printed in the request handler threads run by the WSGIServer, at https://github.com/python/cpython/blob/main/Lib/wsgiref/handlers.py#L382:

    def handle_error(self):
        """Log current error, and send error output to client if possible"""
        self.log_exception(sys.exc_info())
        if not self.headers_sent:
            self.result = self.error_output(self.environ, self.start_response)
            self.finish_response()
        # XXX else: attempt advanced recovery techniques for HTML or text?

This means it is just a somewhat crude way of logging the error, and otherwise an error response is sent back to the web client (i.e. Prometheus, or web browser), who can retry (?).

Specifically, neither the WSGIServer thread inside of the zhmc exporter process, nor the zhmc exporter process are terminated. In fact, it seems to me that at some level within the WSGIServer, a retry happens, because when I inject the raising of an ssl.SSLEOFError, the web browser reading from the zhmc exporter still gets its data. Although it depends a little on where I inject the exception.

When I inject the exception as close as possible to where it is originally raised, the WSGIServer retries. This is when adding the following code:

        # Raise so many SSL exceptions as specified in the env var SSLEOFERROR
        var = os.environ.get('SSLEOFERROR', None)
        fails = int(var) if var else 0
        if fails > 0:
            fails = fails - 1
            os.environ['SSLEOFERROR'] = str(fails)
            import ssl
            thread = threading.current_thread()
            raise ssl.SSLEOFError(
                "Debug: SSLEOFError raised in process {} thread {}, remaining fails: {}".
                format(os.getpid(), thread.getName(), fails))

at the begin of socketserver._SocketWriter.write() (at https://github.com/python/cpython/blob/main/Lib/socketserver.py#L839). That is the lowest possible point. It cannot be injected in the ssl module, because it then also affects the communication with the HMC.

@Charles1000Chen
Can you please verify whether the zhmc exporter is still functional when in your case the real error happens?

@andy-maier
Copy link
Member Author

andy-maier commented Nov 28, 2023 •
edited
Loading

With some debug code added, the output with the injected SSLEOFError looks like this:

Exporter is up and running on port 9291
Debug: Main process 16422 thread: MainThread   # <- thread of the zhmc exporter main() function
Debug: Server process 16422 thread: Thread-2 (serve_forever)   # <- thread created by prometheus_client 

# -> Web Server sends GET to zhmc exporter and triggers injected exception

Debug: wsgiref.BaseHandler.handle_error() called in process 16422 thread Thread-3 (process_request_thread)

# -> Begin of output from exception logging in handle_error():
Traceback (most recent call last):
  File "/usr/local/Cellar/[email protected]/3.12.0/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 138, in run
    self.finish_response()
  File "/usr/local/Cellar/[email protected]/3.12.0/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 184, in finish_response
    self.write(data)
  File "/usr/local/Cellar/[email protected]/3.12.0/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 293, in write
    self.send_headers()
  File "/usr/local/Cellar/[email protected]/3.12.0/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 351, in send_headers
    self.send_preamble()
  File "/usr/local/Cellar/[email protected]/3.12.0/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 271, in send_preamble
    self._write(('HTTP/%s %s\r\n' % (self.http_version,self.status)).encode('iso-8859-1'))
  File "/usr/local/Cellar/[email protected]/3.12.0/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 480, in _write
    result = self.stdout.write(data)
             ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/Cellar/[email protected]/3.12.0/Frameworks/Python.framework/Versions/3.12/lib/python3.12/socketserver.py", line 849, in write
    raise ssl.SSLEOFError(
ssl.SSLEOFError: ('Debug: SSLEOFError raised in process 16422 thread Thread-3 (process_request_thread), remaining fails: 0',)
# -> End of output from exception logging in handle_error()

and the web browser properly displays the metrics page.

@andy-maier andy-maier mentioned this issue Nov 28, 2023
Open
@andy-maier andy-maier modified the milestones: 1.6.0, 1.7.0 Apr 2, 2024
@andy-maier andy-maier modified the milestones: 1.7.0, 2.0.0 Jul 30, 2024
@andy-maier andy-maier modified the milestones: 2.0.0, 2.1.0 Aug 13, 2024
@andy-maier
Copy link
Member Author

andy-maier commented Aug 14, 2024 •
edited
Loading

Another occurrence using the exporter code of the upcoming version 2.0.0 (as of PR #605) on Python 3.12 with stomp-py 8.1.2, and the config file for M12:

Exporter is up and running on port 9291
Traceback (most recent call last):
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 138, in run
    self.finish_response()
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 184, in finish_response
    self.write(data)
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 293, in write
    self.send_headers()
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 351, in send_headers
    self.send_preamble()
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 273, in send_preamble
    self._write(
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/wsgiref/handlers.py", line 472, in _write
    result = self.stdout.write(data)
             ^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/socketserver.py", line 840, in write
    self._sock.sendall(b)
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/ssl.py", line 1211, in sendall
    v = self.send(byte_view[count:])
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/ssl.py", line 1180, in send
    return self._sslobj.write(data)
           ^^^^^^^^^^^^^^^^^^^^^^^^
ssl.SSLEOFError: EOF occurred in violation of protocol (_ssl.c:2406)

The exporter was still functional after this. Logging was off when this happened.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@andy-maier andy-maier

Labels
area: code discussion needed type: bug Something isn't working
Projects
None yet
Milestone
2.1.0
Development

No branches or pull requests
1 participant
@andy-maier