Error while doing SSL handshake: Unknown error

[sanjayankur31]

Hiya,

Could someone please help me connect to matrix.org (element.io)? I've followed the instructions and set up my username/password etc. However, when I try to connect, I get:

matrix: Connecting to matrix.org:443...
matrix: Doing SSL handshake...
Error while doing SSL handshake: Unknown error
matrix: disconnecting from server...

I've got a virtual enviroment set up, so all the deps should be installed correctly. I'm on Fedora 33 if that makes a difference.

weechat-2.9-2.fc33.x86_64

Cheers!

[sanjayankur31]

This is commit: 81be90c

[wavexx]

@sanjayankur31 are you using wee-slack as well by chance, or just weechat-matrix?

Did you recently got updated to python 3.9?

wee-slack/wee-slack#812

[sanjayankur31]

Ah, yes, I've also got wee-slack here, and yes, Fedora 33 is on Python 3.9 too. So, it's probably the same issue.

[jonorthwash]

Same issue, I recently upgraded to python3.9 and I'm using wee-slack as well.

[demlak]

is there any chance of getting this fixed?
i'm not on wee-slack.

Edit: a /script reload matrix.py seems to help..

[wavexx]

@demlak are you using other python plugins, or just weechat-matrix?

[demlak]

i'm using autosort.py, buffer_autohide.py, matrix.py, shell.py, weemustfeed.py, whois_on_query.py

[wavexx]

Given the problem, I suspect that if you only use "matrix.py" the problem will go away (just to verify, I know this is not a solution).

[demlak]

i gave it a try.. if i start without weemustfeed.py, the error does not happen.. when i load weemustfeed.py manualy after matrix.py has connected to server.. the connection fails and the error starts again

[wavexx]

I suppose weemustfeed is doing some connection underneath. As expected, this is similar to wee-slack.

[Zenuncl]

Having similar issue, don't have wee-slack or weemustfeed but I do have another jabber.py running.
Python 3.9
Any plan to fix it soon?

[sanjayankur31]

@wavexx : not a python pro either, but I can try to help with this. Any hints on getting started?

@SharkIng : if you can help diagnose the issue, that'll be helpful. @wavexx has already noted that this isn't an easy one to diagnose. (See also: wee-slack/wee-slack#812)

[poljar]

The error happens here. Adding a `print(error) reveals this error message:

21:39 python: stdout/stderr (matrix): The operation did not complete (read) (_ssl.c:1123)

I have no idea why that would start happening, seems like the other scripts start messing with the existing SSLContext. If a /script reload matrix or loading the matrix script last helps I'm inclined to leave this be and continue working on the rewrite.

[poljar]

There's this comment on the Python bug tracker pointing in the same direction as well:

tl;dr SSLObject and SSLSocket cannot be safely used by multiple threads at the same time. SSLContext can be shared across multiple threads. However it's not safe to reconfigure a context once it's attached to a connection. Only getters, wrap_*(), and load_verify_locations() are safe.

[fluix-dev]

Just throwing more logs here, after running /script reload matrix, wee-slack spits out the same error as print(error) would:

python: error in function "receive_ws_callback"
python: stdout/stderr (slack): Traceback (most recent call last):
python: stdout/stderr (slack):   File "/home/main/.config/weechat/python/autoload/wee_slack.py", line 162, in wrapper
python: stdout/stderr (slack):     return f(*decode_from_utf8(args), **decode_from_utf8(kwargs))
python: stdout/stderr (slack):   File "/home/main/.config/weechat/python/autoload/wee_slack.py", line 531, in receive_ws_callback
python: stdout/stderr (slack):     handle_socket_error(e, team, 'receive')
python: stdout/stderr (slack):   File "/home/main/.config/weechat/python/autoload/wee_slack.py", line 526, in receive_ws_callback
python: stdout/stderr (slack):     opcode, data = team.ws.recv_data(control_frame=True)
python: stdout/stderr (slack):   File "/usr/lib/python3.9/site-packages/websocket/_core.py", line 331, in recv_data
python: stdout/stderr (slack):     opcode, frame = self.recv_data_frame(control_frame)
python: stdout/stderr (slack):   File "/usr/lib/python3.9/site-packages/websocket/_core.py", line 344, in recv_data_frame
python: stdout/stderr (slack):     frame = self.recv_frame()
python: stdout/stderr (slack):   File "/usr/lib/python3.9/site-packages/websocket/_core.py", line 378, in recv_frame
python: stdout/stderr (slack):     return self.frame_buffer.recv_frame()
python: stdout/stderr (slack):   File "/usr/lib/python3.9/site-packages/websocket/_abnf.py", line 361, in recv_frame
python: stdout/stderr (slack):     self.recv_header()
python: stdout/stderr (slack):   File "/usr/lib/python3.9/site-packages/websocket/_abnf.py", line 309, in recv_header
python: stdout/stderr (slack):     header = self.recv_strict(2)
python: stdout/stderr (slack):   File "/usr/lib/python3.9/site-packages/websocket/_abnf.py", line 396, in recv_strict
python: stdout/stderr (slack):     bytes_ = self.recv(min(16384, shortage))
python: stdout/stderr (slack):   File "/usr/lib/python3.9/site-packages/websocket/_core.py", line 453, in _recv
python: stdout/stderr (slack):     return recv(self.sock, bufsize)
python: stdout/stderr (slack):   File "/usr/lib/python3.9/site-packages/websocket/_socket.py", line 100, in recv
python: stdout/stderr (slack):     bytes_ = sock.recv(bufsize)
python: stdout/stderr (slack):   File "/usr/lib/python3.9/ssl.py", line 1226, in recv
python: stdout/stderr (slack):     return self.read(buflen)
python: stdout/stderr (slack):   File "/usr/lib/python3.9/ssl.py", line 1101, in read
python: stdout/stderr (slack):     return self._sslobj.read(len)
python: stdout/stderr (slack): ssl.SSLWantReadError: The operation did not complete (read) (_ssl.c:2622)

[sanjayankur31]

I found a few issues which all pointed to this upstream bug: https://bugs.python.org/issue12343, which is related to non-blocking SSL behaviour.

I'll go tinker around and see if I can get some more info.

[fluix-dev]

That doesn't seem right, it's form 2011 and has ssl.SSLError not ssl.SSLWantReadError.

[vstinner]

Hi, I'm working on Python upstream and a colleague asked me to look into this issue.

python: stdout/stderr (slack):   File "/usr/lib/python3.9/site-packages/websocket/_socket.py", line 100, in recv
python: stdout/stderr (slack):     bytes_ = sock.recv(bufsize)
(...)
python: stdout/stderr (slack): ssl.SSLWantReadError: The operation did not complete (read) (_ssl.c:2622)

It seems like the websocket module uses non-blocking SSL socket but is not prepared to handle ssl.SSLWantReadError error. Where does this module come from? https://pypi.org/project/websocket/ looks unrelated (11 years old).

I tried to install weechat-matrix using:

sudo dnf install -y libolm-devel
git clone https://github.com/poljar/weechat-matrix
cd weechat-matrix
python3.9 -m venv env
env/bin/python -m pip install .

But it doesn't install a "websocket" module and find cannot find any file called _socket.py.

Is there a simple way to reproduce the issue? I'm using Fedora 33.

Should I install weechat and the matrix plugin in weechat? I'm not used to weechat, can someone please explain me how to install these things?

---

I tried to use the matrix plugin in weechat using:

sudo dnf install -y weechat libolm-devel
git clone https://github.com/poljar/weechat-matrix
cd weechat-matrix
python3 -m pip install --user -r requirements.txt   # Python 3.9
ln -s $PWD/matrix ~/.weechat/python/matrix
ln -s $PWD/main.py ~/.weechat/python/matrix.py
weechat

In weechat:

/python load matrix.py
/set matrix.server.matrix_org.username myusername
/set matrix.server.matrix_org.password mypassword
/matrix connect matrix_org

Logs:

│16:54:05 matrix_org -- | matrix: Logging in...
│16:54:24 matrix_org -- | matrix: Logged in as @vstinner:matrix.org

I fail to reproduce the issue.

Also, I cannot find websocket/ or _socket.py in ~/.local/lib/python3.9/site-packages/.

[demlak]

Hey.. thx for digging in..
try to install another plugin that uses ssl connections.. like weemustfeed or wee-slack.
The problem seems to occure when there are more connections

[vstinner]

My main question is: where does the websocket/_socket.py file come from? How can I get it?

I'm not sure why a traceback related to wee_slack.py was reported here. Does it use weechat-matrix?

[poljar]

The the _socket.py file seems to come from wee_slack.py, it lists websocket-client as a dependency which seems to be this file.

The traceback was reported because there seems to be some weird interaction with weechat-matrix (a script that implements the Matrix protocol for Weechat) and wee-slack (a script that implements Slack protocol support for Weechat).

It was later on discovered that the issue isn't specific to wee-slack but any Python script that opens a connection messes up the connection for weechat-matrix. This happens since Python 3.9 and it seems to be somehow related to the SSL context, though I have not investigated in depth.

[mweinelt]

I am pretty sure I have had this issue on Python 3.8 as well, which my distro still defaults to. It is the reason I disabled weechat-matrix. Not sure why y'all are only hitting it on 3.9, maybe it was caused by a websocket-client update instead?

[edmundmiller]

@mweinelt Did you figure out any work around? It looks like your on nixos as well from your bumps of the weechat version. Maybe we can change the version in the scripts package.

Do you happen to have a config floating around I could take a peak at as well?

[mweinelt]

@emiller88 This is my weechat config on NixOS 20.09, where python3.8 is the default.

{ config, pkgs, ... }:
let
  weechat = pkgs.wrapWeechat pkgs.weechat-unwrapped {
    configure = { availablePlugins, ... }: {
      plugins = builtins.attrValues (availablePlugins // {
        python = (availablePlugins.python.withPackages (ps: [
          pkgs.weechatScripts.wee-slack
          # pkgs.weechatScripts.weechat-matrix
        ]));
      });
      scripts = [
        pkgs.weechatScripts.wee-slack
        # pkgs.weechatScripts.weechat-matrix
      ];
    };
  };

  tmuxConf = pkgs.writeText "tmux.conf" ''
     set -g default-terminal "screen-256color"
     set -g status off
  '';
in {
  imports = [
    ./nginx.nix
  ];

  users = {
    groups.weechat = {
      members = [ "hexa" ];
    };
    users.weechat = {
      group = "weechat";
      createHome = true;
      home = "/var/lib/weechat";
      useDefaultShell = true;
      isSystemUser = true;
    };
  };

  systemd.services.weechat = {
    environment.WEECHAT_HOME = "/var/lib/weechat";
    after = [ "network.target "];
    wantedBy = [ "multi-user.target" ];
    serviceConfig = {
      User = "weechat";
      Group = "weechat";
      Type = "forking";
      RemainAfterExit  = "yes";
      ExecStart = "${pkgs.tmux}/bin/tmux -f ${tmuxConf} -S /var/lib/weechat/tmux.session new-session -d -s irc '${weechat}/bin/weechat'";
      ExecStop = "${pkgs.tmux}/bin/tmux -f ${tmuxConf} -S /var/lib/weechat/tmux.session kill-session -t irc";
    };
    postStart = ''
      chmod 660 /var/lib/weechat/tmux.session
      chmod g+rX /var/lib/weechat
    '';
    #reload = ''
    #  echo "*/upgrade -yes ${weechat}/bin/weechat" > /var/lib/weechat/weechat_fifo
    #'';
    #reloadIfChanged = true;
    restartIfChanged = false;
  };

  services.nginx = {
    appendHttpConfig = ''
      limit_req_zone $binary_remote_addr zone=weechat:10m rate=5r/m;
    '';

    virtualHosts = {
      "${config.networking.hostName}.${config.networking.domain}" = {

        locations."/weechat" = {
          proxyPass = "http://localhost:11000/weechat";
          proxyWebsockets = true;
          extraConfig = ''
            proxy_read_timeout 4h;
            limit_req zone=weechat burst=1 nodelay;
          '';
        };
      };
    };
  };
}

[edmundmiller]

Thanks!

I tried overriding the python version for weechat matrix.

        (weechatScripts.weechat-matrix.override {
          buildPythonPackage = python37Packages.buildPythonPackage;
          python = python37;
          pyopenssl = python37Packages.pyopenssl;
          webcolors = python37Packages.webcolors;
          future = python37Packages.future;
          atomicwrites = python37Packages.atomicwrites;
          attrs = python37Packages.attrs;
          Logbook = python37Packages.Logbook;
          pygments = python37Packages.pygments;
          matrix-nio = python37Packages.matrix-nio;
          aiohttp = python37Packages.aiohttp;
          requests = python37Packages.requests;
        })

But weechat didn't like trying to run a python3.7 script with python 3.8.9.

[trygveaa]

I have investigated the issue. It is a regression in Python 3.9, that was recently fixed in main/3.10. I have opened this bug report for Python 3.9: https://bugs.python.org/issue44050

There is also some more discussion around my investigation here: wee-slack/wee-slack#812

[poljar]

Oh nice, it wasn't my fault doing weird things in the end after all. 😅

[Tonux599]

Is there a hotfix for this issue? Due to this bug it currently it seems impossible to use both weechat-matrix and wee-slack on Debian 11, which has Python 3.9.2.

[jonorthwash]

It looks like there's a PR pending review? python/cpython#27794

[Tonux599]

If I understand correctly (and I'm not well versed in Python), that PR makes changes to the Python interpreter? Which would require users to either wait until it's implemented in their distribution, or build and replace python themselves, or build and have weechat plugins use the fixed build.

@jonorthwash by 'hotfix' I was wondering if there was an easier temporary fix for end users so they could avoid one of those I mentioned above?

[dmilith]

Will the issue be fixed with Python 3.10?

[poljar]

As far as I know, yes, this should be fixed in Python 3.10.

[dmilith]

And also in Python 3.9.9 as well

[jonorthwash]

Just upgraded from Python 3.9.7 to 3.9.10 and things work again! Just over a year from encountering the issue to having it solved. Thanks to everyone who helped figure this out and get Python fixed!