Unable to login to Prosody via Nextcloud

[chriscroome]

I have a Nextcloud server running Prosody and Prosody appears to work without any issues, I can test the connection using the command line:

./xcauth.py --auth-test admin $( hostname -f ) SOMERANDOMPASSWD
2018-07-07 18:59:28,489 DEBUG: Start external auth script 1.0.0 for prosody with endpoint: https://example.org.uk/apps/ojsxc/ajax/externalApi.php
2018-07-07 18:59:28,493 DEBUG: Token is too short: 12 != 23 (maybe not a token?)
2018-07-07 18:59:28,519 DEBUG: Starting new HTTPS connection (1): example.org.uk
2018-07-07 18:59:28,701 DEBUG: https://example.org.uk:443 "POST /apps/ojsxc/ajax/externalApi.php HTTP/1.1" 200 43
2018-07-07 18:59:28,705 INFO: SUCCESS: Cloud says password for admin@example.org.uk is valid

But when I try to connect via Nextcloud the Prosody servers logs the following and I get "No connection! relogin" message:

Jul 07 18:58:21 bosh2177f922-70de-4cf0-a674-179af4f1c960        debug   Received[c2s_unauthed]: <auth mechanism='PLAIN' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Jul 07 18:58:21 example.org.uk:auth_external      warn    Auth process exited unexpectedly with exit 1, restarting
Jul 07 18:58:21 example.org.uk:auth_external      warn    Error while waiting for result from auth process: unknown error
Jul 07 18:58:21 example.org.uk:saslauth   debug   sasl reply: <failure xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><not-authorized/><text>Unable to authorize you with the authentication credentials you&apos;ve sent.</text></failure>
Jul 07 18:58:21 mod_bosh        debug   We have an open request, so sending on that
Jul 07 18:58:21 mod_bosh        debug   Request destroyed: table: 0x5578322e2d80
Jul 07 18:58:21 bosh2177f922-70de-4cf0-a674-179af4f1c960        debug   BOSH session marked as inactive (for 60s)
Jul 07 18:58:21 mod_bosh        debug   Session 2177f922-70de-4cf0-a674-179af4f1c960 has 0 out of 1 requests open
Jul 07 18:58:21 mod_bosh        debug   and there are 0 things in the send_buffer:

Does anyone have any suggestions regarding how to debug and potentially solve this issue?

[MarcelWaldvogel]

Yes, it seems like a frontend issue. Therefore, @sualko should look into it (because possibly some hook is not called on SSO logins).

I can't help here.

[chriscroome]

I also found this in /var/log/prosody/xcauth.err:

Traceback (most recent call last):
  File "/opt/xmpp-cloud-auth/xcauth.py", line 14, in <module>
    perform(args)
  File "/opt/xmpp-cloud-auth/xclib/authops.py", line 33, in perform
    cache_db = anydbm.open(args.cache_db, 'c', 0600)
  File "/usr/lib/python2.7/anydbm.py", line 85, in open
    return mod.open(file, flag, mode)
  File "/usr/lib/python2.7/dbhash.py", line 18, in open
    return bsddb.hashopen(file, flag, mode)
  File "/usr/lib/python2.7/bsddb/__init__.py", line 364, in hashopen
    d.open(file, db.DB_HASH, flags, mode)
bsddb.db.DBAccessError: (13, 'Permission denied')

Does anyone have any idea which particular files need their permissions checking?

[chriscroome]

These are the current permissions / ownerships:

ls -lah /var/log/ | grep xcauth
drwx------  2 xcauth      xcauth  4.0K Jul  7 18:46 xcauth

ls -lah /var/lib/ | grep xcauth
drwx------  2 xcauth  xcauth  4.0K Jul  7 18:46 xcauth

ls -lah /var/cache/ | grep xcauth
drwx------  2 xcauth xcauth 4.0K Jul  7 18:59 xcauth

ls -lah /opt/xmpp-cloud-auth/
total 76K
drwxr-xr-x 8 root root 4.0K Jul  7 19:28 .
drwxr-xr-x 3 root root 4.0K Jul  7 18:46 ..
-rw-r--r-- 1 root root 4.2K Jul  7 18:46 CHANGELOG.md
drwxr-xr-x 2 root root 4.0K Jul  7 18:46 doc
drwxr-xr-x 8 root root 4.0K Jul  7 18:46 .git
-rw-r--r-- 1 root root   26 Jul  7 18:46 .gitignore
-rwxr-xr-x 1 root root  407 Jul  7 18:46 install.sh
-rw-r--r-- 1 root root 1.1K Jul  7 18:46 LICENSE
drwxr-xr-x 2 root root 4.0K Jul  7 18:46 prosody-modules
-rw-r--r-- 1 root root  686 Jul  7 18:46 README.md
drwxr-xr-x 2 root root 4.0K Jul  7 18:46 systemd
drwxr-xr-x 2 root root 4.0K Jul  7 18:46 tests
-rw-r--r-- 1 root root  270 Jul  7 18:46 .travis.yml
-rw-r--r-- 1 root root 2.9K Jul  7 18:46 xcauth.conf
-rwxr-xr-x 1 root root  556 Jul  7 18:46 xcauth.py
-rwxr-xr-x 1 root root  100 Jul  7 18:46 xcauth.sh
-rwxr-xr-x 1 root root  480 Jul  7 18:46 xcdbm.py
drwxr-xr-x 3 root root 4.0K Jul  7 19:29 xclib

grep prosody /etc/group
www-data:x:33:prosody
ssl-cert:x:113:prosody
prosody:x:117:xcauth

[MarcelWaldvogel]

Thanks for reporting. This is unrelated, but I'll fix it (it's the login cache, in case Nextcloud were unreachable; it should be disabled unless explicitly activated; it lives in /var/cache/xcauth/)

[chriscroome]

Thanks, so what do I need to change?

[MarcelWaldvogel]

• Commenting out cache-db= in /etc/xcauth.conf (to disable), or
• run ./install.sh to make all the directories and fix all the permissions (or manually just the part that relates to /var/cache/xcauth)

(I had a quick look at the code, and the mistake I thought I might have made wasn't there)

If it persists, please open a separate bug to keep things separated.

[chriscroome]

I have commented out cache-db=/var/cache/xcauth/user-cache.db in /etc/xcauth.conf and there isn't an issue with ownerships or permissions as far as I can tell:

./install.sh 
Warning: The home dir /var/cache/xcauth you specified already exists.
The system user `xcauth' already exists. Exiting.
The user `prosody' is already a member of `xcauth'.

But I still can't use JSXC, I get the "No connection! relogin" message in Nextcloud and when I try to connect nothing happens.

Does anyone have any suggestions regarding what I can check?

[chriscroome]

So I think the main problem was that when I was restarting Prosody it was failing to restart because the ports were still in use, this is from /var/log/prosody/prosody.err:

Jul 13 12:20:42 portmanager     error   Failed to open server port 5269 on ::, check that Prosody or another XMPP server is not already running and using this port
Jul 13 12:20:42 portmanager     error   Failed to open server port 5269 on *, check that Prosody or another XMPP server is not already running and using this port
Jul 13 12:20:42 portmanager     error   Failed to open server port 5280 on 127.0.0.1, check that Prosody or a BOSH connection manager is not already running
Jul 13 12:20:42 portmanager     error   Failed to open server port 5281 on *, this port is in use by another application
Jul 13 12:20:42 portmanager     error   Failed to open server port 5222 on ::, check that Prosody or another XMPP server is not already running and using this port
Jul 13 12:20:42 portmanager     error   Failed to open server port 5222 on *, check that Prosody or another XMPP server is not already running and using this port

Sometime the process listening was python and sometimes lua5.1 and these needed to be killed manually before Prosody could be restarted.

I asked about this in the prosody XMPP chat room and they suggested it was an issue with the external authentication that was being used, this is why I'm posting this here.

So, I have written some Ansible to stop and restart prosody and a Bash script to stop and restart Prosody as work-around for this problem.

[MarcelWaldvogel]

Did you install the patches to Prosody extauth as explained in https://github.com/jsxc/xmpp-cloud-auth/blob/master/doc/Installation.md#prosody ?

[chriscroome]

Yes, lua-lpty is installed and authentication and external_auth_command are set in the prosody.cfg config file.

[MarcelWaldvogel]

As well as the update to mod_auth_external.lua?

lua-lpty seems to be a source of frustration in the Prosody community (see the issues on mod_auth_external). I found the interfacing over the socket interface much more reliable.

[chriscroome]

I haven't tried the socket interface, I might do that next week or later tonight, mod_auth_external.lua is in /opt/xmpp-cloud-auth/prosody-modules/ and /etc/prosody/prosody.cfg.lua contains plugin_paths = { "/opt/xmpp-cloud-auth/prosody-modules" }, see the config file template, does auth_external need to be added to the list of modules_enabled for it to be loaded?

[MarcelWaldvogel]

I didn't have to do anything related to modules_enabled, AFAIK.

BTW: I am working on improving the socket interface, especially for larger installations (e.g., our managed server). This is currently WIP, depending on when I find time to analyze a bug.

[chriscroome]

Using the socket interface seems to work fine with JavaScript XMPP Chat in Nextcloud, but when I try to connect using an external client (Gajim in this case) I get the following in the /var/log/xcauth/xcauth.log file:

2018-07-16 11:50:03,224 INFO: FAILURE: Could not authenticate user chris@example.org.uk: noauth

The following in the /var/log/prosody/prosody.log file:

Jul 16 12:39:16 c2s55657c6351a0 info    Client connected
Jul 16 12:39:17 c2s55657c6351a0 info    Stream encrypted (TLSv1.2 with DHE-RSA-AES256-GCM-SHA384)
Jul 16 12:39:17 example.org.uk:auth_external      info    plpty:read: socket to localhost:23664 timeout
Jul 16 12:39:17 example.org.uk:auth_external      info    plpty:send: socket to localhost:23664 closed
Jul 16 12:39:17 example.org.uk:auth_external      info    plpty:reconnect succeeded

And the following in /var/log/prosody/prosody.log:

Jul 16 12:39:18 c2s55657c6351a0 info    Client disconnected: closed

Is it possible to use a stand alone XMPP client when the socket interface is used?

[chriscroome]

The problems I was having when I posted the comment above seems to have gone way, I'm not sure why but it all now seems to be working :-)

I'm going to close this.

[MarcelWaldvogel]

Whether going through a pipe ("normal" usage), a PTY (Prosody external), or socket (future default) makes no difference to what clients etc. you can use.