weechat-matrix icon indicating copy to clipboard operation
weechat-matrix copied to clipboard

Error while doing SSL handshake: Unknown error

Open sanjayankur31 opened this issue 4 years ago • 34 comments

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 avatar Nov 21 '20 19:11 sanjayankur31

This is commit: 81be90c7c97ee9b1ff41dd9ffd9b7eb97d751c0d

sanjayankur31 avatar Nov 21 '20 19:11 sanjayankur31

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

Did you recently got updated to python 3.9?

https://github.com/wee-slack/wee-slack/issues/812

wavexx avatar Nov 21 '20 19:11 wavexx

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.

sanjayankur31 avatar Nov 21 '20 19:11 sanjayankur31

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

jonorthwash avatar Jan 02 '21 18:01 jonorthwash

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

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

demlak avatar Jan 17 '21 08:01 demlak

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

wavexx avatar Jan 17 '21 14:01 wavexx

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

demlak avatar Jan 17 '21 19:01 demlak

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).

wavexx avatar Jan 17 '21 20:01 wavexx

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

demlak avatar Jan 17 '21 20:01 demlak

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

wavexx avatar Jan 17 '21 23:01 wavexx

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?

Zenuncl avatar Jan 20 '21 19:01 Zenuncl

@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: https://github.com/wee-slack/wee-slack/issues/812)

sanjayankur31 avatar Jan 20 '21 20:01 sanjayankur31

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 avatar Jan 20 '21 20:01 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.

poljar avatar Jan 20 '21 20:01 poljar

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)

fluix-dev avatar Jan 20 '21 20:01 fluix-dev

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.

sanjayankur31 avatar Jan 20 '21 21:01 sanjayankur31

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

fluix-dev avatar Jan 20 '21 21:01 fluix-dev

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/.

vstinner avatar Mar 12 '21 15:03 vstinner

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

demlak avatar Mar 12 '21 15:03 demlak

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?

vstinner avatar Mar 12 '21 16:03 vstinner

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.

poljar avatar Mar 12 '21 16:03 poljar

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?

mweinelt avatar Mar 12 '21 16:03 mweinelt

@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?

edmundmiller avatar May 03 '21 19:05 edmundmiller

@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;
          '';
        };
      };
    };
  };
}

mweinelt avatar May 03 '21 19:05 mweinelt

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.

edmundmiller avatar May 05 '21 13:05 edmundmiller

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: https://github.com/wee-slack/wee-slack/issues/812

trygveaa avatar May 05 '21 14:05 trygveaa

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

poljar avatar May 05 '21 15:05 poljar

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.

Tonux599 avatar Sep 29 '21 13:09 Tonux599

It looks like there's a PR pending review? https://github.com/python/cpython/pull/27794

jonorthwash avatar Oct 01 '21 02:10 jonorthwash

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?

Tonux599 avatar Oct 01 '21 21:10 Tonux599