search

jsxc / xmpp-cloud-auth

:key: Authentication hub for Nextcloud+JSXC→Prosody, ejabberd, saslauthd, Postfix
https://www.jsxc.org
MIT License
59 stars 18 forks source link

Sometimes fails to authenticate (OJSXC, Nextcloud, Prosody, xmpp-cloud-auth) #10

Closed mejo- closed 7 years ago

mejo- commented 7 years ago

Sometimes the authentication fails. My impression is that this happens when this particular user didn't login for several minutes/hours. If I logout+login immediately, the authentication against Prosody succeeds. The relevant log from prosody.log is:

Apr 07 10:37:19 mod_bosh    debug   BOSH body open (sid: e4332ffc-e8ab-4fd3-ae75-2f008ffa9e16)
Apr 07 10:37:19 mod_bosh    debug   BOSH stanza received: <auth mechanism='PLAIN' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>

Apr 07 10:37:19 boshe4332ffc-e8ab-4fd3-ae75-2f008ffa9e16    debug   Received[c2s_unauthed]: <auth mechanism='PLAIN' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Apr 07 10:37:19 cloud.example.org:auth_external debug   Sent 44 bytes
Apr 07 10:37:19 cloud.example.org:auth_external warn    Unable to interpret data from auth process, [2 bytes]
Apr 07 10:37:19 cloud.example.org:auth_external warn    Unable to interpret data from auth process, [2 bytes]
Apr 07 10:37:19 cloud.example.org: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>
Apr 07 10:37:19 mod_bosh    debug   We have an open request, so sending on that
Apr 07 10:37:19 mod_bosh    debug   Request destroyed: table: 0x561dda266780
Apr 07 10:37:19 boshe4332ffc-e8ab-4fd3-ae75-2f008ffa9e16    debug   BOSH session marked as inactive (for 60s)
Apr 07 10:37:19 mod_bosh    debug   Session e4332ffc-e8ab-4fd3-ae75-2f008ffa9e16 has 0 out of 1 requests open
Apr 07 10:37:19 mod_bosh    debug   and there are 0 things in the send_buffer:

extauth.log says:

2017-04-07 10:37:19,808 INFO: Receive operation auth
2017-04-07 10:37:19,809 DEBUG: Token is too short
2017-04-07 10:37:19,810 DEBUG: Starting new HTTPS connection (1): cloud.example.org
2017-04-07 10:37:19,941 DEBUG: https://cloud.example.org:443 "POST /index.php/apps/ojsxc/ajax/externalApi.php HTTP/1.1" 200 48
2017-04-07 10:37:19,944 INFO: Cloud says this password is valid
mejo- commented 7 years ago

Sorry for spaming you with issues, hope that this time I spotted a valid bug ;)

sualko commented 7 years ago

Sorry for not responding. Do you still encounter this issue?

mejo- commented 7 years ago

No worries. I'm on holidays right now but will recheck in a few days. Last time I checked, I still encountered that issue (~10 days ago).

MarcelWaldvogel commented 7 years ago

Any news?

MarcelWaldvogel commented 7 years ago

The log messages in the current version should be more helpful. Could you please check again?

MarcelWaldvogel commented 7 years ago

Related to #21? However, why should this only happen sometimes?

MarcelWaldvogel commented 7 years ago

@mejo- I'm assuming this has been fixed by the Prosody-related changes. Please reopen if necessary. (Also, the Wiki now contains installation and configuration instructions.)

mejo- commented 7 years ago

Sorry for not coming back earlier. I gave the current versions of ojsxc and xmpp-cloud-auth a quick try. So far I was not able to reproduce this bug. Will report back if it happens again.