poljar / weechat-matrix

Weechat Matrix protocol script written in python
Other
958 stars 120 forks source link

Cannot connect to homeserver behind an NGINX reverse proxy #48

Closed ghost closed 5 years ago

ghost commented 5 years ago

I have a standard setup. NGINX listening on 443 (ssl, http2) proxying to synapse with the client port listening on localhost. The only way I can get the plugin to connect is by setting the port to my federation port and disabling SSL validity checking.

matrix: Error while reading from socket is the only error message, even after turning on debugging.

I don't even see my IP hitting the synapse or NGINX logs. No server-side errors either. The output indicates the TLS handshake completed successfully - I'm just using a standard Let's Encrypt cert.

Is there a known-good NGINX configuration I should be using? No other clients have this issue.

ghost commented 5 years ago

Update: by disabling http2 on NGINX, I'm able to connect, though it disconnects and reconnects repeatedly due to the HTTP connection closing. I believe NGINX is not currently able to proxy http2 to an upstream server - it keeps an http2 connection on the client side and uses plain HTTP 1 to connect to the upstream: https://trac.nginx.org/nginx/ticket/923

Perhaps this should be noted in the README? I feel like this is an extremely common setup.

dkasak commented 5 years ago

We're actually using the same setup on our server (nginx, 443, ssl with LE cert, HTTP/2) and it's working without problems. HTTP/2 is the recommended setup for weechat-matrix. We're simply doing a proxy_pass to synapse, like

location /_matrix {
    proxy_pass http://192.168.0.4:8008$request_uri;
}

nginx does seem to use HTTP/1 for the backend connection, but this doesn't appear to be a problem.

It's curious that you were unable to connect while http2 was enabled. Which nginx is this? Could you show us the relevant parts of the nginx config?

ghost commented 5 years ago

Sure.

Server:

$ uname -a
OpenBSD host.example.com 6.4 GENERIC.MP#364 amd64
$ nginx -V        
nginx version: nginx/1.14.0
built with LibreSSL 2.8.2
TLS SNI support enabled
configure arguments: --add-dynamic-module=/usr/obj/ports/nginx-1.14.0/nginx-1.14.0/lua-nginx-module --add-dynamic-module=/usr/local/lib/phusion-passenger24/src/nginx_module --prefix=/var/www --conf-path=/etc/nginx/nginx.conf --sbin-path=/usr/local/sbin/nginx --pid-path=/var/run/nginx.pid --lock-path=/var/run/nginx.lock --http-log-path=logs/access.log --error-log-path=logs/error.log --http-client-body-temp-path=/var/www/cache/client_body_temp --http-proxy-temp-path=/var/www/cache/proxy_temp --http-fastcgi-temp-path=/var/www/cache/fastcgi_temp --http-scgi-temp-path=/var/www/cache/scgi_temp --http-uwsgi-temp-path=/var/www/cache/uwsgi_temp --user=www --group=www --with-http_image_filter_module=dynamic --with-http_geoip_module=dynamic --with-http_gzip_static_module --with-http_gunzip_module --with-http_perl_module=dynamic --with-http_realip_module --with-http_slice_module --with-http_ssl_module --with-http_stub_status_module --with-http_v2_module --with-http_xslt_module=dynamic --with-mail=dynamic --with-ipv6 --with-stream=dynamic --add-dynamic-module=/usr/obj/ports/nginx-1.14.0/nginx-1.14.0/naxsi/naxsi_src/ --add-dynamic-module=/usr/obj/ports/nginx-1.14.0/nginx-1.14.0/ngx_devel_kit --add-dynamic-module=/usr/obj/ports/nginx-1.14.0/nginx-1.14.0/headers-more-nginx-module --add-dynamic-module=/usr/obj/ports/nginx-1.14.0/nginx-1.14.0/nginx-auth-ldap

Fails:

server {
  listen      443 ssl http2;
  listen      [::]:443 ssl http2;
    server_name matrix.c0ffee.net;
    client_max_body_size 50m;
    location / {
      proxy_pass  http://127.0.0.1:8008$request_uri;
      proxy_set_header Host              $host;
      proxy_set_header X-Forwarded-For   $remote_addr;
      proxy_set_header X-Forwarded-Proto https;
      proxy_http_version 1.1;
    }
  }

Works:

server {
  listen      443 ssl ;
  listen      [::]:443 ssl ;
    server_name matrix.c0ffee.net;
    client_max_body_size 50m;
    location / {
      proxy_pass  http://127.0.0.1:8008$request_uri;
      proxy_set_header Host              $host;
      proxy_set_header X-Forwarded-For   $remote_addr;
      proxy_set_header X-Forwarded-Proto https;
      proxy_http_version 1.1;
    }
  }

The rest of my NGINX configs are here. I tried turning off pretty much all the fancy TLS settings - the result was the same.

Client is Arch Linux with weechat-matrix and matrix-nio built from master using the included PKGBUILDs in contrib. Everything else is straight from Arch repos.

Note that I'm using SNI, so I had to disable http2 from all other vhosts to actually disable it.

I'm sure it could be some curiousity in OpenBSD's build of NGINX, but other clients have no issue. I actually want HTTP2 for my other sites, so I worked around it for now by letting synapse use my LetsEncrypt cert on port 8008 on my external interface. Clients can connect directly to that just fine.

poljar commented 5 years ago

Could you please as well share your Weechat configuration, just the server address/port settings for your matrix server?

ghost commented 5 years ago

Of course.

[network]
debug_buffer = off
debug_category = all
debug_level = error
fetch_backlog_on_pgup = on
lag_min_show = 500
lag_reconnect = 90
lazy_load_room_users = off
max_backlog_sync_events = 10
max_initial_sync_events = 30
max_nicklist_users = 5000
print_unconfirmed_messages = on
read_markers_conditions = "${markers_enabled}"
typing_notice_conditions = "${typing_enabled}"

[server]
c0ffee.username = "username"
c0ffee.autoconnect = on
c0ffee.autoreconnect_delay = 10
c0ffee.device_name = "Weechat Matrix"
c0ffee.proxy = ""
c0ffee.address = "matrix.c0ffee.net"
c0ffee.ssl_verify = on
c0ffee.password = "${sec.data.matrix_password}"

# if i set this to 8008, bypassing the nginx proxy, it works fine.
c0ffee.port = 443
poljar commented 5 years ago

I tried to connect to your server using the 443 port. I get a nice Invalid password error from synapse and I checked that Weechat was using http2 to connect to the server.

The server seems to work fine, and your Weechat settings are fine as well.

Does anything else get printed out after the TLS handshake and before the disconnect?

ghost commented 5 years ago

Sadly no. That’s the first message I get after the certificate info gets printed out.

I’ve reproduced this issue on multiple WiFi networks, though on the same laptop.

Oddly from my server log’s perspective, no HTTP request is made. Nginx doesn’t log any errors, presumably because the client has closed the connection before sending any HTTP over the wire?

When I get some time after work today I’ll run weechat under strace.

dkasak commented 5 years ago

You can also try setting matrix.network.debug_level to debug and then posting the logs.

EDIT: Hmm, you did mention you turned on debugging, but just to confirm: did you set the level to debug?

ghost commented 5 years ago

No additional messages appear with debugging turned on.

0828  c0ffee  -- │ matrix: Connecting to matrix.c0ffee.net:443 (SSL)...
0828  c0ffee  -- │ matrix: Doing SSL handshake...
0828  c0ffee  -- │ matrix: Connected using TLSv1.2, and 256 bit ECDHE-RSA-AES256-GCM-SHA384 cipher suite.
0828  c0ffee  -- │ matrix: received certificate
0828  c0ffee     │  - certificate info:
0828  c0ffee     │     - subject: commonName=c0ffee.net, serial number
0828  c0ffee     │         0456E819E5162CC1C752E5A2118000EDA3CC
0828  c0ffee     │     - issuer: countryName=US, organizationName=Let's Encrypt,
0828  c0ffee     │         commonName=Let's Encrypt Authority X3
0828  c0ffee     │     - key info: RSA key 4096 bits, signed using
0828  c0ffee     │         sha256WithRSAEncryption
0828  c0ffee     │     - period of validity:
0828  c0ffee     │         Begins on:  Jan 14 04:55:24 2019 GMT
0828  c0ffee     │         Expires on: Apr 14 04:55:24 2019 GMT
0828  c0ffee     │     - fingerprints:
0828  c0ffee     │         SHA1:   FE:68:8D:53:8E:F1:7B:9E:46:88:8C:70:7F:9E:06:F7:12:B4:5A:13
0828  c0ffee     │         SHA256: 49:E8:8C:3B:8B:0F:1B:48:9F:04:4E:6D:77:23:CD:E5:F3:CB:0A:A0:E7:44:34:88:9F:3C:E5:4D:E3:D1:B9:46
0828  c0ffee  -- │ matrix: Logging in...
0828  c0ffee  -- │ matrix: Error while reading from socket
0828  c0ffee  -- │ matrix: disconnecting from server...
0828  c0ffee  -- │ matrix: disconnected from server
dkasak commented 5 years ago

Okay, thanks for the clarification. That's really weird. This is what happens for me when trying to connect to your server with matrix.network.debug_level set to debug:

14:24       c0ffee  --   matrix: Connected using TLSv1.2, and 256 bit ECDHE-RSA-AES256-GCM-SHA384 cipher suite.
14:24       c0ffee  --   matrix: received certificate
14:24       c0ffee        - certificate info:
14:24       c0ffee           - subject: commonName=c0ffee.net, serial number
14:24       c0ffee               0456E819E5162CC1C752E5A2118000EDA3CC
14:24       c0ffee           - issuer: countryName=US, organizationName=Let's Encrypt,
14:24       c0ffee               commonName=Let's Encrypt Authority X3
14:24       c0ffee           - key info: RSA key 4096 bits, signed using
14:24       c0ffee               sha256WithRSAEncryption
14:24       c0ffee           - period of validity:
14:24       c0ffee               Begins on:  Jan 14 04:55:24 2019 GMT
14:24       c0ffee               Expires on: Apr 14 04:55:24 2019 GMT
14:24       c0ffee           - fingerprints:
14:24       c0ffee               SHA1:   FE:68:8D:53:8E:F1:7B:9E:46:88:8C:70:7F:9E:06:F7:12:B4:5A:13
14:24       c0ffee               SHA256: 49:E8:8C:3B:8B:0F:1B:48:9F:04:4E:6D:77:23:CD:E5:F3:CB:0A:A0:E7:44:34:88:9F:
                         3C:E5:4D:E3:D1:B9:46
14:24      weechat       nio.http: Making Http2 request [(u':method', u'POST'),
14:24      weechat        (u':path', u'/_matrix/client/r0/login'),
14:24      weechat        (u':authority', u'matrix.c0ffee.net:443'),
14:24      weechat        (u':scheme', u'https'),
14:24      weechat        (u'user-agent', u'nio'),
14:24      weechat        (u'accept', u'application/json'),
14:24      weechat        (u'content-type', u'application/json'),
14:24      weechat        (u'content-length', u'106')] b'{"initial_device_display_name":"Weechat
                         Matrix","password":"test","type":"m.login.password","user":"test"}'.
14:24      weechat       nio.http: New stream id 1
14:24      weechat       nio.http: Sending data: stream id: 1; request size: 106; window size: 65535; max frame size
                         16384
14:24       c0ffee  --   matrix: Logging in...

Note the several nio.http messages between the certificate and "Logging in...".

ghost commented 5 years ago

It’s must be an issue with my client then, if you can successfully connect.

On which platforms are y’all testing from? I’ll set up a VM and test. I’m running Arch with everything up to date as of yesterday. Using master branch of weechat-matrix, weechat-nio, and python olm. Maybe the issue lies in some underlying dependency.

My weechat is straight from arch repos, which build it with python2.

dkasak commented 5 years ago

We are using basically the same setup: up to date Arch Linux, all three packages made by running make archpkg (EDIT: just make for weechat-matrix) on the master branch. I don't think I have a custom version of anything relevant. poljar's setup should be similar.

ghost commented 5 years ago

I didn’t notice the archpkg target...I used the PKGBUILDs manually. Doubt there’s much difference but I’ll give it a shot.

ghost commented 5 years ago

Well, that did change things. Now I get the following error though:

0912 weechat     │ python: stdout/stderr (matrix): Traceback (most recent call last):
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/matrix/utf.py", line 91, in wrapper
0912 weechat     │ python: stdout/stderr (matrix):     return function(*decode_from_utf8(args), **decode_from_utf8(kwargs))
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/autoload/matrix.py", line 198, in ssl_fd_cb
0912 weechat     │ python: stdout/stderr (matrix):     try_ssl_handshake(server)
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/autoload/matrix.py", line 223, in try_ssl_handshake
0912 weechat     │ python: stdout/stderr (matrix):     finalize_connection(server)
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/autoload/matrix.py", line 348, in finalize_connection
0912 weechat     │ python: stdout/stderr (matrix):     data = server.client.connect(server.transport_type)
0912 weechat     │ python: stdout/stderr (matrix): AttributeError: 'NoneType' object has no attribute 'connect'
0912 weechat =!= │ python: error in function " ????U"
0912 weechat     │ python: stdout/stderr (matrix): Traceback (most recent call last):
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/matrix/utf.py", line 91, in wrapper
0912 weechat     │ python: stdout/stderr (matrix):     return function(*decode_from_utf8(args), **decode_from_utf8(kwargs))
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/autoload/matrix.py", line 302, in receive_cb
0912 weechat     │ python: stdout/stderr (matrix):     server.client.receive(data)
0912 weechat     │ python: stdout/stderr (matrix): AttributeError: 'NoneType' object has no attribute 'receive'
0912 weechat =!= │ python: error in function "receive_cb"
0912 weechat     │ python: stdout/stderr (matrix): Traceback (most recent call last):
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/matrix/utf.py", line 91, in wrapper
0912 weechat     │ python: stdout/stderr (matrix):     return function(*decode_from_utf8(args), **decode_from_utf8(kwargs))
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/matrix/server.py", line 1615, in matrix_timer_cb
0912 weechat     │ python: stdout/stderr (matrix):     server.lag = server.client.lag * 1000
0912 weechat     │ python: stdout/stderr (matrix): AttributeError: 'NoneType' object has no attribute 'lag'
0912 weechat =!= │ python: error in function "matrix_timer_cb"
0912 weechat     │ python: stdout/stderr (matrix): Traceback (most recent call last):
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/matrix/utf.py", line 91, in wrapper
0912 weechat     │ python: stdout/stderr (matrix):     return function(*decode_from_utf8(args), **decode_from_utf8(kwargs))
0912 weechat     │ python: stdout/stderr (matrix):   File "/home/cullum/.weechat/python/matrix/server.py", line 1615, in matrix_timer_cb
0912 weechat     │ python: stdout/stderr (matrix):     server.lag = server.client.lag * 1000
0912 weechat     │ python: stdout/stderr (matrix): AttributeError: 'NoneType' object has no attribute 'lag'

So looks like it can’t determine whether it’s http 1 or http 2. The plot thickens.

poljar commented 5 years ago

The server.client variable that is None for you is set when the config is loaded and changed every time you change the server address or port.

It seems like there is still an issue with your package. There are two Make targets for matrix-nio.

Did you install the tagged release of matrix-nio or latest master (archpkg is tagged release and arch-git-pkg is latest master)? Also it may be necessary to restart Weechat completely after a package is updated in such a way (not sure why or even if this is true, but worth a shot).

ghost commented 5 years ago

arch-git-pkg did the trick. I'm connecting fine now.

Thanks for your help!