#674 when external auth is using lpty not able to restart server due to not closing port 5281
Reporter
Paolo Nesti Poggi
Owner
Zash
Created
Updated
Stars
★★ (2)
Tags
Status-Fixed
Type-Defect
Priority-Medium
Paolo Nesti Poggi
on
What steps will reproduce the problem?
1. start server with config :
authentication = "external"
external_auth_protocol = "generic"
external_auth_command = "/etc/prosody/example_auth.sh"
2. service prosody start
root@erme:/etc/prosody# service prosody start
root@erme:/etc/prosody# lsof | grep 5281
lua5.1 23359 prosody 20u IPv6 6751365 0t0 TCP *:5281 (LISTEN)
lua5.1 23359 prosody 21u IPv4 6751366 0t0 TCP *:5281 (LISTEN)
3. Doing one authentication trial (via BOSH, but it is irrelevant)
root@erme:/etc/prosody# lsof | grep 5281
apache2 22696 www-data 46u IPv4 6750543 0t0 TCP localhost:32880->erme.munksoegaard.dk:5281 (ESTABLISHED)
lua5.1 23359 prosody 4u IPv4 6751533 0t0 TCP erme.munksoegaard.dk:5281->localhost:32880 (ESTABLISHED)
lua5.1 23359 prosody 20u IPv6 6751365 0t0 TCP *:5281 (LISTEN)
lua5.1 23359 prosody 21u IPv4 6751366 0t0 TCP *:5281 (LISTEN)
example_a 23364 prosody 20u IPv6 6751365 0t0 TCP *:5281 (LISTEN)
example_a 23364 prosody 21u IPv4 6751366 0t0 TCP *:5281 (LISTEN)
4. Stopping the service
root@erme:/etc/prosody# service prosody stop
root@erme:/etc/prosody# lsof | grep 5281
apache2 21953 www-data 46u IPv4 6750758 0t0 TCP localhost:32882->erme.munksoegaard.dk:5281 (ESTABLISHED)
example_a 23364 prosody 20u IPv6 6751365 0t0 TCP *:5281 (LISTEN)
example_a 23364 prosody 21u IPv4 6751366 0t0 TCP *:5281 (LISTEN)
or as an alternative:
root@erme:/etc/prosody# ps aux | grep prosody
root 23335 0.0 0.0 5736 628 pts/0 S+ 13:12 0:00 tail -f /var/log/prosody/prosody-debug.log
prosody 23364 0.0 0.3 7280 3116 pts/3 Ss+ 13:14 0:00 /bin/bash /etc/prosody/example_auth.sh
root 23402 0.0 0.2 6504 2068 pts/1 S+ 13:18 0:00 grep prosody
What is the expected output? What do you see instead?
The child process for the authentication script should also be stopped.
Being so the situation when I do
service prosody start
again
The log shows:
...
May 17 13:20:26 socket warn server.lua, [*]:5269: address already in use
May 17 13:20:26 portmanager error Failed to open server port 5269 on *, check that Prosody or another XMPP server is not already running and using this port
May 17 13:20:26 portmanager info Activated service 's2s' on no ports
May 17 13:20:26 mod_s2s warn s2s not listening on any ports, outgoing connections may fail
May 17 13:20:26 mod_posix info Prosody is about to detach from the console, disabling further console output
May 17 13:20:26 mod_posix info Successfully daemonized to PID 23426
May 17 13:20:26 portmanager debug No active service for http, activating...
May 17 13:20:26 socket warn server.lua, [::]:5280: address already in use
May 17 13:20:26 portmanager error Failed to open server port 5280 on ::, check that Prosody or a BOSH connection manager is not already running
May 17 13:20:26 socket warn server.lua, [*]:5280: address already in use
May 17 13:20:26 portmanager error Failed to open server port 5280 on *, check that Prosody or a BOSH connection manager is not already running
May 17 13:20:26 portmanager info Activated service 'http' on no ports
May 17 13:20:26 portmanager debug No active service for https, activating...
and I cannot connect any longer. Then I need to stop the service and then kill the active process manually.
What version of the product are you using? On what operating system?
Debian jessie, with prosody 0.10 package from: https://prosody.im/download/package_repository
Zash
on
So, my understanding is that this is likely because Prosody exit()s when it shuts down. The lpty finalizer will not run in this case and because the script is attached to a virtual terminal, it stays around.
Changes
tags Status-Accepted
Niklas Edmundsson
on
There are actually multiple problems here:
1) is lpty not properly closing unneeded file handles before exec:ing the command, causing fd:s to leak to the external process. This has been reported to the lpty developer.
2) is the auth script not being killed when prosody/mod_auth_external exits. The fix for this is likely to have mod_auth_external call lpty endproc when prosody/mod_auth_external is shut down.
In order to have the external auth script to properly exit in case prosody is violently killed, crashes etc, auth scripts also needs something similar to the following before the main while/read loop:
# mod_auth_external/lpty doesn't properly kill child processes on
# exit, so we have to ensure that ourselves.
mypid=$$
myppid=$PPID
(
while kill -0 $myppid >/dev/null 2>&1
do
# Requires a sleep command capable of non-integer arguments
sleep 0.1
done
kill -- -$mypid >/dev/null 2>&1
) &
This is from our auth-script, and it does a tight loop in able to handle an admin doing service prosody stop and start. It isn't quick enough to handle a service prosody restart, that's why mod_auth_external really should kill it by using lpty endproc when gracefully shut down.
What steps will reproduce the problem? 1. start server with config : authentication = "external" external_auth_protocol = "generic" external_auth_command = "/etc/prosody/example_auth.sh" 2. service prosody start root@erme:/etc/prosody# service prosody start root@erme:/etc/prosody# lsof | grep 5281 lua5.1 23359 prosody 20u IPv6 6751365 0t0 TCP *:5281 (LISTEN) lua5.1 23359 prosody 21u IPv4 6751366 0t0 TCP *:5281 (LISTEN) 3. Doing one authentication trial (via BOSH, but it is irrelevant) root@erme:/etc/prosody# lsof | grep 5281 apache2 22696 www-data 46u IPv4 6750543 0t0 TCP localhost:32880->erme.munksoegaard.dk:5281 (ESTABLISHED) lua5.1 23359 prosody 4u IPv4 6751533 0t0 TCP erme.munksoegaard.dk:5281->localhost:32880 (ESTABLISHED) lua5.1 23359 prosody 20u IPv6 6751365 0t0 TCP *:5281 (LISTEN) lua5.1 23359 prosody 21u IPv4 6751366 0t0 TCP *:5281 (LISTEN) example_a 23364 prosody 20u IPv6 6751365 0t0 TCP *:5281 (LISTEN) example_a 23364 prosody 21u IPv4 6751366 0t0 TCP *:5281 (LISTEN) 4. Stopping the service root@erme:/etc/prosody# service prosody stop root@erme:/etc/prosody# lsof | grep 5281 apache2 21953 www-data 46u IPv4 6750758 0t0 TCP localhost:32882->erme.munksoegaard.dk:5281 (ESTABLISHED) example_a 23364 prosody 20u IPv6 6751365 0t0 TCP *:5281 (LISTEN) example_a 23364 prosody 21u IPv4 6751366 0t0 TCP *:5281 (LISTEN) or as an alternative: root@erme:/etc/prosody# ps aux | grep prosody root 23335 0.0 0.0 5736 628 pts/0 S+ 13:12 0:00 tail -f /var/log/prosody/prosody-debug.log prosody 23364 0.0 0.3 7280 3116 pts/3 Ss+ 13:14 0:00 /bin/bash /etc/prosody/example_auth.sh root 23402 0.0 0.2 6504 2068 pts/1 S+ 13:18 0:00 grep prosody What is the expected output? What do you see instead? The child process for the authentication script should also be stopped. Being so the situation when I do service prosody start again The log shows: ... May 17 13:20:26 socket warn server.lua, [*]:5269: address already in use May 17 13:20:26 portmanager error Failed to open server port 5269 on *, check that Prosody or another XMPP server is not already running and using this port May 17 13:20:26 portmanager info Activated service 's2s' on no ports May 17 13:20:26 mod_s2s warn s2s not listening on any ports, outgoing connections may fail May 17 13:20:26 mod_posix info Prosody is about to detach from the console, disabling further console output May 17 13:20:26 mod_posix info Successfully daemonized to PID 23426 May 17 13:20:26 portmanager debug No active service for http, activating... May 17 13:20:26 socket warn server.lua, [::]:5280: address already in use May 17 13:20:26 portmanager error Failed to open server port 5280 on ::, check that Prosody or a BOSH connection manager is not already running May 17 13:20:26 socket warn server.lua, [*]:5280: address already in use May 17 13:20:26 portmanager error Failed to open server port 5280 on *, check that Prosody or a BOSH connection manager is not already running May 17 13:20:26 portmanager info Activated service 'http' on no ports May 17 13:20:26 portmanager debug No active service for https, activating... and I cannot connect any longer. Then I need to stop the service and then kill the active process manually. What version of the product are you using? On what operating system? Debian jessie, with prosody 0.10 package from: https://prosody.im/download/package_repository
So, my understanding is that this is likely because Prosody exit()s when it shuts down. The lpty finalizer will not run in this case and because the script is attached to a virtual terminal, it stays around.
ChangesThere are actually multiple problems here: 1) is lpty not properly closing unneeded file handles before exec:ing the command, causing fd:s to leak to the external process. This has been reported to the lpty developer. 2) is the auth script not being killed when prosody/mod_auth_external exits. The fix for this is likely to have mod_auth_external call lpty endproc when prosody/mod_auth_external is shut down. In order to have the external auth script to properly exit in case prosody is violently killed, crashes etc, auth scripts also needs something similar to the following before the main while/read loop: # mod_auth_external/lpty doesn't properly kill child processes on # exit, so we have to ensure that ourselves. mypid=$$ myppid=$PPID ( while kill -0 $myppid >/dev/null 2>&1 do # Requires a sleep command capable of non-integer arguments sleep 0.1 done kill -- -$mypid >/dev/null 2>&1 ) & This is from our auth-script, and it does a tight loop in able to handle an admin doing service prosody stop and start. It isn't quick enough to handle a service prosody restart, that's why mod_auth_external really should kill it by using lpty endproc when gracefully shut down.
Thanks for the writeup. Made it call endproc on module unload in https://hg.prosody.im/prosody-modules/rev/92f6f82397c9 and since apparently that's not done during shutdown, attached it to a cleanup event in https://hg.prosody.im/prosody-modules/rev/3fb5f173f213 That should cover what we can do on the Prosody side?
ChangesSeems to work as intended, thanks for fixing!
Thank you very much!