Bosh with auth_external or auth_phpbb

[Pierre Monteux]

I've just gotten a server setup, and I am having a problem with bosh and/or two of the auth plugins. 

On arch linux, I installed the included server.  I modified the config file to use auth_external, and enable bosh.  The server functioned correctly using pidgin as a client.  When I connected in using converse.js through bosh, converse.js shows a spinning wheel for connecting, and doesn't ever login.  If I restart the server at this point, converse.js does show the disconnect from the server.  

My first thought was that converse.js had a bug, so I downloaded candy, with similar results.  At this point i reverted my config file, and only enabled bosh.  I created a local account, tested that it worked from pidgin, then verifed bosh.  Both converse.js and candy functioned correctly at this point, so I know that bosh was working.  I switched the auth to auth_external, and pdigin worked, but the bosh interface failed.

I thought i had a problem with the auth module, since at this point I proved bosh worked.  So I added some debugging hooks to the script i was using, and as best i can tell the script didn't even get called when a connection came in using bosh.  Since I"m connecting to a phpbb database I found auth_phpbb and used that instead of auth external.  I'm getting the same results with this.  A client using bosh just waits forever, never logs in. Pidgin always works fine.

Any ideas on what i should try?  Is there a known compatibly problem when using bosh and another auth module?  

I'm not geting any debugging out of this thing right now, beyond one message in journalctl (syslog replacement) that I"ve pasted below.  

Nov 21 18:52:22 usb_archie prosodyctl[1952]: general             info        Hello and welcome to Prosody version 0.9.6

Nov 21 18:52:22 usb_archie prosodyctl[1952]: general             info        Prosody is using the select backend for connection handling

Nov 21 18:52:22 usb_archie prosodyctl[1952]: portmanager         info        Activated service 'console' on [127.0.0.1]:5582, [::1]:5582

Nov 21 18:52:22 usb_archie prosodyctl[1952]: portmanager         info        Activated service 'http' on [::]:5280, [*]:5280

Nov 21 18:52:22 usb_archie prosodyctl[1952]: portmanager         info        Activated service 'https' on [::]:5281, [*]:5281

Nov 21 18:52:22 usb_archie prosodyctl[1952]: portmanager         info        Activated service 'c2s' on [::]:5222, [*]:5222

Nov 21 18:52:22 usb_archie prosodyctl[1952]: portmanager         info        Activated service 'legacy_ssl' on no ports

Nov 21 18:52:22 usb_archie prosodyctl[1952]: portmanager         info        Activated service 's2s' on [::]:5269, [*]:5269

Nov 21 18:52:22 usb_archie prosodyctl[1952]: mod_posix           info        Prosody is about to detach from the console, disabling further console output

Nov 21 18:52:22 usb_archie prosodyctl[1952]: Started

thanks,

[deoren]

On 11/22/2014 1:21 AM, Pierre Monteux wrote:
> Is there a known compatibly problem when using bosh and another auth module?

I can't speak to other auth modules, but I use auth_dovecot with BOSH
and it works well with the 0.10 (nightly).

> I'm not geting any debugging out of this thing right now, beyond one
> message in journalctl (syslog replacement) that I"ve pasted below.

I don't know anything about systemd, but within Prosody's config file
you can enable debug mode to get additional information.

log = {
debug = "*syslog"; -- Send debug and higher to the syslog sink
}

Because I still have other problems with Prosody (mod_smacks in
particular) I keep debug mode enabled on our box. I just send anything
higher than severity level 6 to a separate file and anything severity
level 6 or lower to the normal log file.

I review the normal log on a regular basis and view the debug copy when
I need additional information. The debug log is also requested by the
developers when reporting a problem, so it's handy to already have it
available.

I'm attaching a copy of the /etc/rsyslog.d/02-prosody.conf file that I
use in case it gives you any ideas on filtering the debug output.

Hope it helps.

[Pierre Monteux]

I updated my system, and got prosody 9.7.  

I went ahead and redid my config file, and have debugging working now.

When I try to login using bosh, i get this in the log.

Nov 26 02:02:21 usb_archie prosody[610]: socket: server.lua: accepted new client connection from 127.0.0.1:55076 to 5280

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: Handling new request table: 0x266f690: <body rid='4022347724' xmlns='http://jabber.org/protocol/httpbind' to='drrr.no-ip.org' xml:lang='en' wait='60' hold='1' content='text/xml; charset=utf-8' ver='1.6' xmpp:version='1.0' xmlns:xmpp='urn:xmpp:xbosh'/>

                                         ----------

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: BOSH body open (sid: <none>)

Nov 26 02:02:21 usb_archie prosody[610]: bosh90e49e16-4442-4834-b2f0-60ff1e352c27: BOSH session created for request from 192.168.10.235

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: New BOSH session, assigned it sid '90e49e16-4442-4834-b2f0-60ff1e352c27'

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: We have an open request, so sending on that

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: Request destroyed: table: 0x266fb30

Nov 26 02:02:21 usb_archie prosody[610]: bosh90e49e16-4442-4834-b2f0-60ff1e352c27: BOSH session marked as inactive (for 60s)

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: Session 90e49e16-4442-4834-b2f0-60ff1e352c27 has 0 out of 1 requests open

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: and there are 0 things in the send_buffer:

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: Handling new request table: 0x2522c60: <body rid='4022347725' xmlns='http://jabber.org/protocol/httpbind' sid='90e49e16-4442-4834-b2f0-60ff1e352c27'/>

                                         ----------

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: BOSH body open (sid: 90e49e16-4442-4834-b2f0-60ff1e352c27)

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: Session 90e49e16-4442-4834-b2f0-60ff1e352c27 has 1 out of 1 requests open

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: and there are 0 things in the send_buffer:

Nov 26 02:02:21 usb_archie prosody[610]: mod_bosh: Have nothing to say, so leaving request unanswered for now

this is with the connection forever spinning trying to connect.

When i connect from pidgin, i get this in the logs, and it works.

Nov 26 02:06:04 usb_archie prosody[657]: socket: server.lua: accepted new client connection from 192.168.10.235:51949 to 5222

Nov 26 02:06:04 usb_archie prosody[657]: c2sf3d040: Client connected

Nov 26 02:06:04 usb_archie prosody[657]: c2sf3d040: Client sent opening <stream:stream> to drrr.no-ip.org

Nov 26 02:06:04 usb_archie prosody[657]: c2sf3d040: Sent reply <stream:stream> to client

Nov 26 02:06:04 usb_archie prosody[657]: c2sf3d040: Received[c2s_unauthed]: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>

Nov 26 02:06:04 usb_archie prosody[657]: socket: server.lua: we need to do tls, but delaying until send buffer empty

Nov 26 02:06:04 usb_archie prosody[657]: c2sf3d040: TLS negotiation started for c2s_unauthed...

Nov 26 02:06:04 usb_archie prosody[657]: socket: server.lua: attempting to start tls on tcp{client}: 0xfd5788

Nov 26 02:06:04 usb_archie prosody[657]: socket: server.lua: ssl handshake done

Nov 26 02:06:04 usb_archie prosody[657]: c2sf3d040: Client sent opening <stream:stream> to drrr.no-ip.org

Nov 26 02:06:04 usb_archie prosody[657]: c2sf3d040: Sent reply <stream:stream> to client

Nov 26 02:06:04 usb_archie prosody[657]: [177B blob data]

Nov 26 02:06:04 usb_archie prosody[657]: c2sf3d040: Authenticated as da...@drrr.no-ip.org

Nov 26 02:06:04 usb_archie prosody[657]: drrr.no-ip.org:saslauth: sasl reply: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'></success>

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Client sent opening <stream:stream> to drrr.no-ip.org

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Sent reply <stream:stream> to client

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f9549' type='set'>

Nov 26 02:06:05 usb_archie prosody[657]: rostermanager: load_roster: asked for: da...@drrr.no-ip.org

Nov 26 02:06:05 usb_archie prosody[657]: rostermanager: load_roster: loading for new user: da...@drrr.no-ip.org

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Resource bound: da...@drrr.no-ip.org/215ce199-23ba-4e80-b034-4d7602c63eb3

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f954a' type='set'>

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f954b' type='get' to='drrr.no-ip.org'>

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f954c' type='get' to='drrr.no-ip.org'>

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f954d' type='get' to='conference.drrr.no-ip.org'>

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f954e' type='get'>

Nov 26 02:06:05 usb_archie prosody[657]: datamanager: Assuming empty vcard storage ('cannot open /var/lib/prosody/drrr%2eno%2dip%2eorg/vcard/dare.dat: No such file or directory') for user: da...@drrr.no-ip.org

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f954f' type='get'>

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f9550' type='get' to='drrr.no-ip.org'>

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f9551' type='get' to='proxy.eu.jabber.org'>

Nov 26 02:06:05 usb_archie prosody[657]: stanzarouter: Routing to remote...

Nov 26 02:06:05 usb_archie prosody[657]: mod_s2s: opening a new outgoing connection for this stanza

Nov 26 02:06:05 usb_archie prosody[657]: mod_s2s: stanza [iq] queued until connection complete

Nov 26 02:06:05 usb_archie prosody[657]: mod_s2s: First attempt to connect to proxy.eu.jabber.org, starting with SRV lookup...

Nov 26 02:06:05 usb_archie prosody[657]: adns: Records for _xmpp-server._tcp.proxy.eu.jabber.org. already cached, using those...

Nov 26 02:06:05 usb_archie prosody[657]: mod_s2s: proxy.eu.jabber.org has SRV records, handling...

Nov 26 02:06:05 usb_archie prosody[657]: mod_s2s: Best record found, will connect to hermes2.jabber.org.:5269

Nov 26 02:06:05 usb_archie prosody[657]: adns: Records for hermes2.jabber.org. already cached, using those...

Nov 26 02:06:05 usb_archie prosody[657]: mod_s2s: DNS reply for hermes2.jabber.org. gives us 208.68.163.218

Nov 26 02:06:05 usb_archie prosody[657]: adns: Records for hermes2.jabber.org. not in cache, sending query (thread: 0x10a1bb0)...

Nov 26 02:06:05 usb_archie prosody[657]: adns: Sending DNS query to 192.168.10.1

Nov 26 02:06:05 usb_archie prosody[657]: socket: server.lua: closed client handler and removed socket from list

Nov 26 02:06:05 usb_archie prosody[657]: adns: Reply for hermes2.jabber.org. (thread: 0x10a1bb0)

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: Beginning new connection attempt to proxy.eu.jabber.org ([208.68.163.218]:5269)

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: Connection attempt in progress...

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <presence>

Nov 26 02:06:05 usb_archie prosody[657]: drrr.no-ip.org:presence: outbound presence subscribe from da...@drrr.no-ip.org for dare

Nov 26 02:06:05 usb_archie prosody[657]: rostermanager: load_roster: asked for: da...@drrr.no-ip.org

Nov 26 02:06:05 usb_archie prosody[657]: stanzarouter: Routing to remote...

Nov 26 02:06:05 usb_archie prosody[657]: s2soutfc02b0: trying to send over unauthed s2sout to dare

Nov 26 02:06:05 usb_archie prosody[657]: s2soutfc02b0: stanza [presence] queued

Nov 26 02:06:05 usb_archie prosody[657]: datamanager: Assuming empty offline storage ('cannot open /var/lib/prosody/drrr%2eno%2dip%2eorg/offline/dare.list: No such file or directory') for user: da...@drrr.no-ip.org

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='purple1f5f9552' type='set'>

Nov 26 02:06:05 usb_archie prosody[657]: c2sf3d040: Received[c2s]: <iq id='lx2' type='result'>

Nov 26 02:06:05 usb_archie prosody[657]: stanzarouter: Discarding iq from c2s of type: result

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: sending: <?xml version='1.0'?>

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: sending: <stream:stream xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='drrr.no-ip.org' to='proxy.eu.jabber.org' xml:lang='en' xmlns='jabber:server'>

Nov 26 02:06:05 usb_archie prosody[657]: drrr.no-ip.org:dialback: Initiating dialback...

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: sending: <db:result to='proxy.eu.jabber.org' from='drrr.no-ip.org'>

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: sent dialback key on outgoing s2s stream

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: Session closed by remote with error: host-unknown

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: sending: </stream:stream>

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: outgoing s2s stream drrr.no-ip.org->proxy.eu.jabber.org closed: host-unknown

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: Destroying outgoing session drrr.no-ip.org->proxy.eu.jabber.org: host-unknown

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: Sending error replies for 1 queued stanzas because of failed outgoing connection to proxy.eu.jabber.org

Nov 26 02:06:05 usb_archie prosody[657]: stanzarouter: Received[s2sin]: <iq id='purple1f5f9551' type='error' to='da...@drrr.no-ip.org/215ce199-23ba-4e80-b034-4d7602c63eb3' from='proxy.eu.jabber.org'>

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: s2s disconnected: nil->nil (connection closed)

Nov 26 02:06:05 usb_archie prosody[657]: socket: server.lua: closed client handler and removed socket from list

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: Received </stream:stream>

Nov 26 02:06:05 usb_archie prosody[657]: s2soutd58480: Attempt to close already-closed session

So bosh isn't working, pidgin connecting directly is.

Anything further I can try to pinpoint where the problem is?

thanks

[deoren]

First I'd like to preface my response with the statement that I'm not
very fluent with Prosody setup, so might send you in the wrong direction
with some of my comments.

That said, what are the values for these options?

* c2s_require_encryption
* consider_bosh_secure

What options do you have in the matching virtual host for your webserver?

I looked back through my old notes and I mentioned having to have my web
server proxy connections to 127.0.0.1:5281 (encryption active) instead
of 127.0.0.1:5280 (encryption disabled) because I had
'c2s_require_encryption' set to "yes". My notes were not clear whether I
too was experiencing timeouts, but it sounds familiar.

Documentation:

* http://prosody.im/doc/setting_up_bosh#proxying_requests
* http://prosody.im/doc/modules/mod_bosh

[Pierre Monteux]

Ok, let me actually just post my whole conf file, and save potential back and forth.

I've blanked the MYSQL password, and removed all comments to save space, other than that its what i have right now.

daemonize = true

pidfile = "/run/prosody/prosody.pid"

s2s_require_encryption = true

admins = {"da...@drrr.no-ip.org" }

modules_enabled = {

                "roster"; -- Allow users to have a roster. Recommended ;)

                "saslauth"; -- Authentication for clients and servers. Recommended if you want to log in.

                "tls"; -- Add support for secure TLS on c2s/s2s connections

                "dialback"; -- s2s dialback support

                "disco"; -- Service discovery

                "private"; -- Private XML storage (for room bookmarks, etc.)

                "vcard"; -- Allow users to set vCards

                "version"; -- Replies to server version requests

                "uptime"; -- Report how long server has been running

                "time"; -- Let others know the time here on this server

                "ping"; -- Replies to XMPP pings with pongs

                "pep"; -- Enables users to publish their mood, activity, playing music and more

                "register"; -- Allow users to register on this server using a client and change passwords

                "admin_adhoc"; -- Allows administration via an XMPP client that supports ad-hoc commands

                "bosh"; -- Enable BOSH clients, aka "Jabber over HTTP"

                "posix"; -- POSIX functionality, sends server to background, enables syslog, etc.

};

modules_disabled = {

};

allow_registration = false;

ssl = {

                key = "/etc/httpd/conf/drrr.no-ip.org.key";

                certificate = "/etc/httpd/conf/drrr.no-ip.org.crt";

}

c2s_require_encryption = true

s2s_secure_auth = false

authentication = "phpbb3"

sql = { driver = "MySQL", database = "jap", username = "root", password = "", host = "localhost" }

log = {

        "*syslog"; -- Uncomment this for logging to syslog

}

VirtualHost "localhost"

VirtualHost "drrr.no-ip.org"

        ssl = {

                key = "/etc/httpd/conf/drrr.no-ip.org.key";

                certificate = "/etc/httpd/conf/drrr.no-ip.org.crt";

        }

        authentication = "phpbb3"

        external_auth_protocol = "ejabberd"

        external_auth_command = "/etc/prosody/phpbb3_extauth.php"

Component "conference.drrr.no-ip.org" "muc"

And my for the webserver virtual host, (using apache) the lines i added to the virtual host are as follows.

        ProxyPass /http-bind http://127.0.0.1:5280/http-bind

        ProxyPassReverse /http-bind http://127.0.0.1:5280/http-bind

If you go to http://drrr.no-ip.org/http-bind/ The message make me feel that at least I have apache working correctly.

consider_bosh_secure did not appear in the conf file (unless i'm blind)

I tried setting c2s_require_encryption to false, but it didn't change anything in the behavior of the bosh connection.

Any further troubleshooting i could do?

thanks,

[deoren]

On 11/27/2014 12:35 AM, Pierre Monteux wrote:
> c2s_require_encryption = true

Unless I'm mistaken, you're saying that you want _all_ client
connections to be secure. Prosody sees the web server proxying client
connections _as_ a client, so web server process has to comply with that
setting.

> consider_bosh_secure did not appear in the conf file (unless i'm blind)

Nope. That setting has a default value of 'false', which unless you
override it you will need to have your web server connect to the
encryption-enabled (by default) TCP 5281 port. TCP 5280 is for
unencrypted connections (by default).

Or, you can change the 'consider_bosh_secure' setting to 'true' which
will treat connections to the BOSH port as secure. Prosody assumes at
this point that you're taking full responsibility for securing the
connections with encryption and will allow connections to the TCP 5280
port via 127.0.0.1. From what I can tell this is controlled by the
'trusted_proxies' mod_bosh config option.

This would look something like this:

client -> web server public IP:443 (via TLS) -> 127.0.0.1:5280 (no
encryption)

On to the Apache conf snippet:

> ProxyPass /http-bind http://127.0.0.1:5280/http-bind
> ProxyPassReverse /http-bind http://127.0.0.1:5280/http-bind

I'm not as familiar with proxying connections with Apache, but this
looks right if you have 'consider_bosh_secure = true' in your conf file.

Suggestions:

#1) Leave "c2s_require_encryption = true" in place
#2) Add "consider_bosh_secure = true" to your conf
#3) Configure Apache to serve up https://drrr.no-ip.org/http-bind (note
the lack of a trailing slash and 'https')
#4 Leave your Apache Proxy settings as-is so the unencrypted port on
localhost will be used.
#5) Restart Prosody
#6) Visit https://drrr.no-ip.org/http-bind in your web browser

You should get back a success message. If you don't, then your XMPP
client(s) won't have any luck either.

References:

http://prosody.im/doc/modules/mod_bosh
http://prosody.im/doc/setting_up_bosh#configuring

[Pierre Monteux]

Suggestion #2 was the solution, at least the one I wanted for now.  I'm replacing a webchat that is already unsecure, so for now this is the ideal solution for me. I did test it both ways for suggestion #1, and am leaving it as you suggested.  I'll try the other suggestions when I'm ready to move the server to use SSL for everything.

Thanks again.

[deoren]

On 11/28/2014 2:19 PM, Pierre Monteux wrote:
> Suggestion #2 was the solution, at least the one I wanted for now. I'm
> replacing a webchat that is already unsecure, so for now this is the
> ideal solution for me. I did test it both ways for suggestion #1, and am
> leaving it as you suggested. I'll try the other suggestions when I'm
> ready to move the server to use SSL for everything.
>
> Thanks again.

You're welcome, I'm glad I could help.