search

xmppo / xmpp-webhook

Multipurpose XMPP-Webhook (Built for DevOps Alerts)
https://github.com/xmppo/xmpp-webhook
MIT License
21 stars 8 forks source link

Errors on Debian 10 - malformed-request #16

Open konstantine-v opened 3 years ago

konstantine-v commented 3 years ago

OS: Debian 10 Kernel: 4.19.0-12-amd64 Go: na Xmpp-webhook: 0.3 XMPP Client: Prosody v0.11.2

I get this error below as I try to start the systemd service:

Feb 04 15:43:43 box.andrasmedia.org xmpp-webhook[19658]: panic: malformed-request
Feb 04 15:43:43 box.andrasmedia.org xmpp-webhook[19658]: goroutine 1 [running]:
Feb 04 15:43:43 box.andrasmedia.org xmpp-webhook[19658]: main.panicOnErr(...)
Feb 04 15:43:43 box.andrasmedia.org xmpp-webhook[19658]:         /home/thomas/projects/xmpp-webhook/main.go:23
Feb 04 15:43:43 box.andrasmedia.org xmpp-webhook[19658]: main.main()
Feb 04 15:43:43 box.andrasmedia.org xmpp-webhook[19658]:         /home/thomas/projects/xmpp-webhook/main.go:88 +0x6b6

I'm currently trying to run this on the same machine Prosody is running. I've created the bot users, and tested it before running the script.

I have also tried the script on the machine that runs Grafana where the webhook would be coming from and I get the same errors. That machine runs Ubuntu 20.04 LTS.

Should I try building from source rather than using the binary?

tmsmr commented 3 years ago

What do you mean with "script"? The webhook binary or the Systemd service? Are you able to connect to Prosody using any other Jabber client (There are also CLI-based ones if you are running headless - e.g. https://profanity-im.github.io/) using the same hostname and protocol? Feel free to debug/compile the webhook on your own, but there is no need IMO - this seems like a configuration/connection issue.

konstantine-v commented 3 years ago

I apologize, I meant to say the xmpp-webhook binary. I'm able to connect to Prosody using Profanity and Conversations with OMEMO working. Sometime this week I will try and check the configuration for this and see what else may have gone wrong and update this issue accordingly.

tmsmr commented 3 years ago

Hey @MaterialFuture, please use https://github.com/tmsmr/xmpp-webhook/releases/tag/v0.4.0 for your tests. v0.4.0 contains mellium/xmpp v0.18.0, which should improve the verbosity of errors.

tmsmr commented 3 years ago

Since there is no feedback, i'm closing the issue.

XeonSquared commented 2 years ago

Also having issues with the same error, Debian 10 host, Prosody 11. Here's my Prosody debug log, with the SASL reply removed because I don't know if that's sensitive or not

Sep 20 21:08:55 socket  debug   server.lua: accepted new client connection from 10.0.0.1:47502 to 5222
Sep 20 21:08:55 c2s559946921d90 info    Client connected
Sep 20 21:08:55 c2s559946921d90 debug   Client sent opening <stream:stream> to shadowkat.net
Sep 20 21:08:55 c2s559946921d90 debug   Sending[c2s_unauthed]: <?xml version='1.0'?>
Sep 20 21:08:55 c2s559946921d90 debug   Sending[c2s_unauthed]: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='shadowkat.net' xmlns='jabber:client' xml:lang='en' id='60b00319-b0de-49ea-9634-913aaf47f3dd'>
Sep 20 21:08:55 c2s559946921d90 debug   Sent reply <stream:stream> to client
Sep 20 21:08:55 c2s559946921d90 debug   Not offering authentication on insecure connection
Sep 20 21:08:55 c2s559946921d90 debug   Sending[c2s_unauthed]: <stream:features>
Sep 20 21:08:55 runner9UPu5Cc7  debug   creating new coroutine
Sep 20 21:08:55 c2s559946921d90 debug   Received[c2s_unauthed]: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
Sep 20 21:08:55 c2s559946921d90 debug   Sending[c2s_unauthed]: <proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
Sep 20 21:08:55 socket  debug   server.lua: we need to do tls, but delaying until send buffer empty
Sep 20 21:08:55 c2s559946921d90 debug   TLS negotiation started for c2s_unauthed...
Sep 20 21:08:55 socket  debug   server.lua: attempting to start tls on tcp{client}: 0x559945a729a8
Sep 20 21:08:55 socket  debug   server.lua: ssl handshake done
Sep 20 21:08:55 c2s559946921d90 debug   Client sent opening <stream:stream> to shadowkat.net
Sep 20 21:08:55 c2s559946921d90 debug   Sending[c2s_unauthed]: <?xml version='1.0'?>
Sep 20 21:08:55 c2s559946921d90 debug   Sending[c2s_unauthed]: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='shadowkat.net' xmlns='jabber:client' xml:lang='en' id='e4f4b7a7-bf5d-499a-95df-4c1508354951'>
Sep 20 21:08:55 c2s559946921d90 debug   Sent reply <stream:stream> to client
Sep 20 21:08:55 c2s559946921d90 info    Stream encrypted (TLSv1.3 with TLS_AES_256_GCM_SHA384)
Sep 20 21:08:55 c2s559946921d90 debug   Offering mechanism SCRAM-SHA-1
Sep 20 21:08:55 c2s559946921d90 debug   Offering mechanism PLAIN
Sep 20 21:08:55 c2s559946921d90 debug   Offering mechanism SCRAM-SHA-1-PLUS
Sep 20 21:08:55 c2s559946921d90 debug   Sending[c2s_unauthed]: <stream:features>
Sep 20 21:08:55 c2s559946921d90 debug   Received[c2s_unauthed]: <auth mechanism='SCRAM-SHA-1-PLUS' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Sep 20 21:08:55 sql debug   SQL transaction begin [function(mod_storage_sql.lua:62)]
Sep 20 21:08:55 sql debug   SQL transaction success [function(mod_storage_sql.lua:62)]
Sep 20 21:08:55 shadowkat.net:saslauth  debug   sasl reply: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>SNIP</challenge>
Sep 20 21:08:55 c2s559946921d90 debug   Sending[c2s_unauthed]: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Sep 20 21:08:55 c2s559946921d90 debug   Received[c2s_unauthed]: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Sep 20 21:08:55 shadowkat.net:saslauth  debug   sasl reply: <failure xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><malformed-request/><text>Invalid channel binding value.</text></failure>
Sep 20 21:08:55 c2s559946921d90 debug   Sending[c2s_unauthed]: <failure xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Sep 20 21:08:55 socket  debug   server.lua: client 10.0.0.1:47502 read error: closed
Sep 20 21:08:55 c2s559946921d90 info    Client disconnected: closed
Sep 20 21:08:55 c2s559946921d90 debug   Destroying session for (unknown) ((unknown)@shadowkat.net): closed
Sep 20 21:08:55 socket  debug   server.lua: closed client handler and removed socket from list
tmsmr commented 2 years ago

Would you mind sharing your Prosody-Config? You are the third one who reported that but i were not able to reproduce the issue yet.

EDIT: I suppose you are using v0.4.0?

XeonSquared commented 2 years ago

Not a problem, put it up as a gist:
https://gist.github.com/XeonSquared/86d74b770f10e7b9affe2c92bc2bdacd

And yup, tried 0.4.0 and 0.3 at various points with the same result.

Additionally, here's the output of prosodyctl about

Prosody 0.11.2

# Prosody directories
Data directory:     /var/lib/prosody
Config directory:   /etc/prosody
Source directory:   /usr/lib/prosody
Plugin directories:
  /usr/lib/prosody/modules/
  /usr/local/lib/prosody/modules - prosody-modules rev: dc35d2932d3e
  /usr/lib/prosody/modules/

# Lua environment
Lua version:                Lua 5.2

Lua module search paths:
  /usr/lib/prosody/?.lua
  /usr/local/share/lua/5.2/?.lua
  /usr/local/share/lua/5.2/?/init.lua
  /usr/local/lib/lua/5.2/?.lua
  /usr/local/lib/lua/5.2/?/init.lua
  /usr/share/lua/5.2/?.lua
  /usr/share/lua/5.2/?/init.lua

Lua C module search paths:
  /usr/lib/prosody/?.so
  /usr/local/lib/lua/5.2/?.so
  /usr/lib/x86_64-linux-gnu/lua/5.2/?.so
  /usr/lib/lua/5.2/?.so
  /usr/local/lib/lua/5.2/loadall.so

LuaRocks:           Not installed

# Lua module versions
lfs:        LuaFileSystem 1.6.3
libevent:   2.1.8-stable
luaevent:   0.4.6
lxp:        LuaExpat 1.3.0
socket:     LuaSocket 3.0-rc1
ssl:        0.7
tmsmr commented 2 years ago

@XeonSquared Thanks for the infos.

I am able to reproduce the issue now! I'm on it...

tmsmr commented 2 years ago

There was an issue in Prosody 0.11 where it would advertise channel binding when TLS 1.3 is used. This is causing the authentication problems. The problem was fixed with https://hg.prosody.im/0.11/rev/1bfd238e05ad. Unfortunately this patch never reached Prosody 0.11 in Buster. Since this is no security issue, i doubt the maintainers are willing to to include the Change. https://github.com/mellium/sasl/commit/14279962860ce30296ea528fc1cca4f439c480b1 adds an error message regarding that issue. I'll update the lib ASAP, hopefully this will be less confusing then...

Possible solutions:

tmsmr commented 2 years ago

@XeonSquared Have you tried one of those "Workarounds" with Prosody on Debian Buster?