Blather attempts to (re)set password on login

[bklang]

Tonight I noticed a strange problem while running an old app with a newer version of Blather. My authentications were failing. This particular server uses ejabberd with an extauth script that only implements authentication. The errors in my logs indicated that the ejabberd server was asking my extauth script to update the password for the user. Looking at the Blather logs I see this:

D, [2012-09-12T22:06:22.133647 #82260] DEBUG -- : RECEIVING (iq) <iq from="[email protected]" to="[email protected]/3282288313134750143164923" id="blather0006" type="result">
  <query xmlns="jabber:iq:register">
    <username>999</username>
    <password>asdf</password>
  </query>
</iq>

Which, based on my reading is Blather telling the server to change my password. However I did not request that:

#!/usr/bin/env ruby

require 'blather/client'

Blather.logger = Logger.new $stdout
Blather.logger.level = Logger::DEBUG

setup '[email protected]', 'asdf'
message {|m| p m}

Besides my one-off case of the extauth script not supporting password changes, there are other reasons that an XMPP server may not support password changes. In my case this causes Blather to crash:

D, [2012-09-12T22:18:21.855504 #83075] DEBUG -- : SENDING: (/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/stream/features/register.rb:22:in `receive_data') <iq type="set" id="blather0006">
  <query xmlns="jabber:iq:register">
    <username>999</username>
    <password>asdf</password>
  </query>
</iq>
D, [2012-09-12T22:18:21.904223 #83075] DEBUG -- : RECEIVING (iq) <iq from="[email protected]" to="[email protected]/5981716151347502150808318" id="blather0006" type="error">
  <query xmlns="jabber:iq:register">
    <username>999</username>
    <password>asdf</password>
  </query>
  <error code="500" type="wait">
    <internal-server-error xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/>
  </error>
</iq>
D, [2012-09-12T22:18:21.904479 #83075] DEBUG -- : SENDING: (/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/stream.rb:248:in `stop') </stream:stream>
D, [2012-09-12T22:18:21.991720 #83075] DEBUG -- : RECEIVING (end) <stream:end xmlns:stream="http://etherx.jabber.org/streams"/>
999asdf
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:232:in `block in setup_initial_handlers'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:295:in `call'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:295:in `call_handler'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:286:in `block (2 levels) in call_handler_for'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:286:in `catch'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:286:in `block in call_handler_for'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:285:in `each'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:285:in `find'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:285:in `call_handler_for'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:278:in `block in handle_stanza'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:277:in `each'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:277:in `handle_stanza'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:194:in `block in handle_data'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:192:in `catch'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:192:in `handle_data'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/blather-0.8.0/lib/blather/client/client.rb:63:in `block in initialize'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/work_queue.rb:147:in `call'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/work_queue.rb:147:in `block (2 levels) in start'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/actor.rb:86:in `call'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/actor.rb:86:in `block in spawn_link'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/actor.rb:69:in `call'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/actor.rb:69:in `block (2 levels) in spawn'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/actor.rb:212:in `block in initialize'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/actor.rb:377:in `watchdog'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/actor.rb:212:in `initialize'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/actor.rb:66:in `new'
/Users/bklang/.rvm/gems/ruby-1.9.3-p194/gems/girl_friday-0.10.0/lib/girl_friday/actor.rb:66:in `block in spawn'

I do not know why ejabberd responded with a 500 error code, but I think there are two bugs here:

1. The failing password change should raise a more reasonable exception.
2. Blather should not try to change the user's password unless it is done explicitly.

[benlangfeld]

@jackhong Are you able to comment on this?

[jackhong]

Looks like ejabberd doesn't follow the the xep0077 spec correctly. Basically when the server was setup using 'in-band registration, then the initial feature list should include when asked for authentication methods supported, but it shouldn't include it once user has already been authenticated. As 0077 spec states, when user has already been authenticated, a register stanza will automatically become 'change password' stanza, that is where the error occurs. Even that, throwing a 500 internal error when change password failed is not very nice.

Openfire implemented the feature correctly.

This log fragment is extracted from issue #103

    RECEIVING (features) <stream:features xmlns:stream="http://etherx.jabber.org/streams">
    <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/>
    <session xmlns="urn:ietf:params:xml:ns:xmpp-session"/>
    <c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://www.process-one.net/en/ejabberd/" ver="yy7di5kE0syuCXOQTXNBTclpNTo="/>
    <register xmlns="http://jabber.org/features/iq-register"/>
    </stream:features>

I guess the easiest solution is to turn off in-band registration feature if using ejabberd and not actually requiring in-band registration.

I'd rather not hard code the behaviour fix just for the sake of ejabberd.

[benlangfeld]

Would you mind filing a bug report against ejabberd and linking it here for reference?

[jackhong]

Issued created in ejabberd project.

processone/ejabberd#41

[Piratonym]

I experienced the same issue while testing with Prosody, but haven't had time yet to do further research for a bug report.

A very hackish workaround (if anyone needs it in the meantime) seems to be ignoring the stanza using this code:

module Blather; class Stream; class Register; def receive_data(stanza); succeed!; end; end; end; end

[benlangfeld]

This appears to have been fixed in ejabberd: processone/ejabberd#41. I would suggest that a similar fix be made to Prosody if you are experiencing it with that server, @Piratonym. I'm closing this ticket because there is no evidence this is a bug in Blather. If you follow this up with Prosody, I'd appreciate a link here to the fix.