#855 mod_auth_external error in bash script response read
Reporter
Damien Fetis
Owner
Nobody
Created
Updated
Stars
★★ (2)
Tags
Component-Community
Priority-Medium
Type-Defect
Status-Accepted
Damien Fetis
on
On my system there is an issue regarding external bash script authentification response read.
What steps will reproduce the problem?
1. Set authentification in VirtualHost configuration file to :
authentication = "external"
external_auth_protocol = "generic"
external_auth_command = "prosody-auth-example.sh"
2. Restart prosody service
3. authenticate a user with "someone"
What is the expected output?
in /var/log/prosody/prosody.log :
info Authenticated as someone@XXXXXX
What do you see instead?
sasl reply: <failure xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><not-authorized/><text>Unable to authorize you with the aut
hentication credentials you've sent.</text></failure>
What version of the product are you using? On what operating system?
Prosody : 0.9.1
OS : Ubuntu 14.04 LTS
Please provide any additional information below.
If we log the script response seen by mod_auth_external.lua, we can see the echo of lpty.send(text) for the first response of the script. And the next call return the first call response. There is a known issue with lpty no_local_echo not working as expected as described in lpty README (https://tset.de/lpty/README.html).
My solution is to check manually if response is send echo or not :
--- mod_auth_external (2).lua 2017-03-17 11:58:24.000000000 +0100
+++ mod_auth_external.lua 2017-03-17 14:23:52.000000000 +0100
@@ -67,14 +67,22 @@
end
pty:send(text);
+ pty:flush("i");
if blocking then
- return pty:read(read_timeout);
+ local response;
+ response = pty:read(read_timeout);
+ if response == text then
+ response = pty:read(read_timeout);
+ end
+ return response;
else
local response;
local wait, done = waiter();
server.addevent(pty:getfd(), server.event.EV_READ, function ()
response = pty:read();
- done();
+ if not response == text then
+ done();
+ end
return -1;
end);
wait();
@@ -99,6 +107,9 @@
end
local response, err = send_query(query);
+ if response then log("debug", "Reponse %s", response ); end
+
+
if not response then
log("warn", "Error while waiting for result from auth process: %s", err or "unknown error");
elseif (script_type == "ejabberd" and response == "\0\2\0\0") or
Best Regards,
Damien
Marcel Waldvogel
on
The problem also happens in Ubuntu 16.04.2 LTS, with stock Prosody, as well as with prosody-0.9, prosody-0.10, or prosody-trunk from prosody.im. It happens with stock lua-lpty and with the current one from luarocks. It happens in bash and python.
The client process sees echo turned of (checked with stty/termios). So the explanation from the lpty documentation does not seem to match.
Also, doing a "service prosody restart" when one of the external commands is still running results in the process not being terminated and prosody being unable to reallocate its ports.
Did nobody ever test this module or am I doing something fundamentally wrong?
Marcel Waldvogel
on
Damien, thank you very much for the patch!
It indeed fixes the problem that has been plaguing us with Prosody and the JSXC external authentication mechanism (https://github.com/jsxc/xmpp-cloud-auth/issues/21 and other, older, issues).
The fix works perfectly (so far) for blocking mode. It seems the order of pty:send(text) and pty:flush("i") above could under some circumstances (process switch in between, and fast external auth script) cause the real response to be eaten. Switching the two would seem more defensive.
I could not get your patch to work in non-blocking mode (prosody-trunk and use_libevent=true): Logins will just never happen (and not time out within a reasonable timeframe).
(OT, but it looks like browsers normalize whitespace when copying)
kousu
on
I have another patch that solves this for me, in what seems to be a more reliable way:
```
diff -r 933049a60ce6 mod_auth_external/mod_auth_external.lua
--- a/mod_auth_external/mod_auth_external.lua Thu Jan 04 11:41:54 2018 +0100
+++ b/mod_auth_external/mod_auth_external.lua Fri Jan 12 05:26:22 2018 -0500
@@ -75,6 +75,15 @@
log("debug", "Started auth process");
end
+ -- Hotfix: lpty has a glitch in some versions: no_local_echo=true is not respected until *after*
+ -- the first read happens, it seems. The first do_query() therefore fails because it reads
+ -- back the query that was sent in, so the first login after restarting prosody -- or after
+ -- any time the auth process crashes -- mysteriously fails.
+ -- By calling read() immediately and discarding the result, we skip the problem;
+ -- The protocol says that this first read should be empty, since the subprocess shouldn't
+ -- be giving us any data until we probe it.
+ pty:read(read_timeout);
+
pty:send(text);
if blocking then
return pty:read(read_timeout);
```
(if the bug tracker eats this patch its also available at https://gist.githubusercontent.com/kousu/af2ce63a590e56c38795f9564586c6bf/raw/bea810017610208afda73856c34d2e12b495c486/mod_auth_external.patch)
Marcel Waldvogel
on
Thanks, @kousu, that would also explain why other users of lpty seem to be happy.
On my system there is an issue regarding external bash script authentification response read. What steps will reproduce the problem? 1. Set authentification in VirtualHost configuration file to : authentication = "external" external_auth_protocol = "generic" external_auth_command = "prosody-auth-example.sh" 2. Restart prosody service 3. authenticate a user with "someone" What is the expected output? in /var/log/prosody/prosody.log : info Authenticated as someone@XXXXXX What do you see instead? sasl reply: <failure xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><not-authorized/><text>Unable to authorize you with the aut hentication credentials you've sent.</text></failure> What version of the product are you using? On what operating system? Prosody : 0.9.1 OS : Ubuntu 14.04 LTS Please provide any additional information below. If we log the script response seen by mod_auth_external.lua, we can see the echo of lpty.send(text) for the first response of the script. And the next call return the first call response. There is a known issue with lpty no_local_echo not working as expected as described in lpty README (https://tset.de/lpty/README.html). My solution is to check manually if response is send echo or not : --- mod_auth_external (2).lua 2017-03-17 11:58:24.000000000 +0100 +++ mod_auth_external.lua 2017-03-17 14:23:52.000000000 +0100 @@ -67,14 +67,22 @@ end pty:send(text); + pty:flush("i"); if blocking then - return pty:read(read_timeout); + local response; + response = pty:read(read_timeout); + if response == text then + response = pty:read(read_timeout); + end + return response; else local response; local wait, done = waiter(); server.addevent(pty:getfd(), server.event.EV_READ, function () response = pty:read(); - done(); + if not response == text then + done(); + end return -1; end); wait(); @@ -99,6 +107,9 @@ end local response, err = send_query(query); + if response then log("debug", "Reponse %s", response ); end + + if not response then log("warn", "Error while waiting for result from auth process: %s", err or "unknown error"); elseif (script_type == "ejabberd" and response == "\0\2\0\0") or Best Regards, Damien
The problem also happens in Ubuntu 16.04.2 LTS, with stock Prosody, as well as with prosody-0.9, prosody-0.10, or prosody-trunk from prosody.im. It happens with stock lua-lpty and with the current one from luarocks. It happens in bash and python. The client process sees echo turned of (checked with stty/termios). So the explanation from the lpty documentation does not seem to match. Also, doing a "service prosody restart" when one of the external commands is still running results in the process not being terminated and prosody being unable to reallocate its ports. Did nobody ever test this module or am I doing something fundamentally wrong?
Damien, thank you very much for the patch! It indeed fixes the problem that has been plaguing us with Prosody and the JSXC external authentication mechanism (https://github.com/jsxc/xmpp-cloud-auth/issues/21 and other, older, issues). The fix works perfectly (so far) for blocking mode. It seems the order of pty:send(text) and pty:flush("i") above could under some circumstances (process switch in between, and fast external auth script) cause the real response to be eaten. Switching the two would seem more defensive. I could not get your patch to work in non-blocking mode (prosody-trunk and use_libevent=true): Logins will just never happen (and not time out within a reasonable timeframe).
Copying from here does not preserve line breaks, making the diff useless. I have applied Damien's patch here: https://github.com/jsxc/xmpp-cloud-auth/blob/master/prosody-modules/mod_auth_external.lua BTW: Reordering send/flush does not always seem to work. Some heisenbug in mod_auth_external/lpty?
(OT, but it looks like browsers normalize whitespace when copying)
I have another patch that solves this for me, in what seems to be a more reliable way: ``` diff -r 933049a60ce6 mod_auth_external/mod_auth_external.lua --- a/mod_auth_external/mod_auth_external.lua Thu Jan 04 11:41:54 2018 +0100 +++ b/mod_auth_external/mod_auth_external.lua Fri Jan 12 05:26:22 2018 -0500 @@ -75,6 +75,15 @@ log("debug", "Started auth process"); end + -- Hotfix: lpty has a glitch in some versions: no_local_echo=true is not respected until *after* + -- the first read happens, it seems. The first do_query() therefore fails because it reads + -- back the query that was sent in, so the first login after restarting prosody -- or after + -- any time the auth process crashes -- mysteriously fails. + -- By calling read() immediately and discarding the result, we skip the problem; + -- The protocol says that this first read should be empty, since the subprocess shouldn't + -- be giving us any data until we probe it. + pty:read(read_timeout); + pty:send(text); if blocking then return pty:read(read_timeout); ``` (if the bug tracker eats this patch its also available at https://gist.githubusercontent.com/kousu/af2ce63a590e56c38795f9564586c6bf/raw/bea810017610208afda73856c34d2e12b495c486/mod_auth_external.patch)
Thanks, @kousu, that would also explain why other users of lpty seem to be happy.