TypeError: Cannot read property 'message' of null

[andyhmltn]

Hi There!

I'm getting an error using this adapter with Heroku. I have uploaded it etc and this is in the output of heroku logs:

2013-02-12T14:03:44+00:00 app[web.1]: /app/node_modules/hubot-hipchat/src/hipchat.coffee:135
2013-02-12T14:03:44+00:00 app[web.1]:         if (message.message) {
2013-02-12T14:03:44+00:00 app[web.1]:                    ^
2013-02-12T14:03:44+00:00 app[web.1]: TypeError: Cannot read property 'message' of null
2013-02-12T14:03:44+00:00 app[web.1]:     at Bot.HipChat.run.bot.onMessage.author (/app/node_modules/hubot-hipchat/src/hipchat.coffee:135:20)
2013-02-12T14:03:44+00:00 app[web.1]:     at Bot.module.exports.Bot.onStreamError (/app/node_modules/hubot-hipchat/node_modules/wobot/lib/bot.js:32:12)
2013-02-12T14:03:44+00:00 app[web.1]:     at Bot.EventEmitter.emit (events.js:126:20)
2013-02-12T14:03:44+00:00 app[web.1]:     at Client.EventEmitter.emit (events.js:96:17)
2013-02-12T14:03:44+00:00 app[web.1]:     at Client.onRawStanza (/app/node_modules/hubot-hipchat/node_modules/wobot/node_modules/node-xmpp/lib/xmpp/client.js:124:18)
2013-02-12T14:03:44+00:00 app[web.1]:     at Client.Connection.onStanza (/app/node_modules/hubot-hipchat/node_modules/wobot/node_modules/node-xmpp/lib/xmpp/connection.js:237:14)
2013-02-12T14:03:44+00:00 app[web.1]:     at Client.EventEmitter.emit (events.js:96:17)
2013-02-12T14:03:44+00:00 app[web.1]:     at StreamParser.EventEmitter.emit (events.js:96:17)
2013-02-12T14:03:44+00:00 app[web.1]:     at StreamParser.Connection.startParser (/app/node_modules/hubot-hipchat/node_modules/wobot/node_modules/node-xmpp/lib/xmpp/connection.js:136:14)
2013-02-12T14:03:44+00:00 app[web.1]:     at null.<anonymous> (/app/node_modules/hubot-hipchat/node_modules/wobot/node_modules/node-xmpp/lib/xmpp/stream_parser.js:42:22)

Any ideas? Thanks

[powdahound]

What version of hubot and hubot-hipchat?

[andyhmltn]

Woops sorry!

"dependencies": {
    "hubot": ">=2.4.6",
    "hubot-scripts": ">= 2.4.1",
    "optparse": "1.0.3",
    "hubot-hipchat": ">= 2.4.5-1"
  },

[powdahound]

Looks like the error is being thrown in the error handling code. I see the onStreamError call in the stack there too. Could you set HUBOT_HIPCHAT_DEBUG="true" in the environment vars and check the logs again? You'll see XML output and there should be a <stream:error> element at the end somewhere. Thanks!

[andyhmltn]

There doesn't seem to be any reference to <stream:error>. Here's the full output:

2013-02-12T16:20:44+00:00 app[web.1]:   host: null,
2013-02-12T16:20:44+00:00 app[web.1]:  OUT > <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" version="1.0" to="chat.hipchat.com">
2013-02-12T16:20:44+00:00 app[web.1]:   mucHost: 'conf.hipchat.com' }
2013-02-12T16:20:44+00:00 app[web.1]:   IN > <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' version='1.0' from='chat.hipchat.com' id='2c4f61ae8324a030'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features>
2013-02-12T16:20:44+00:00 app[web.1]:   IN > <proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
2013-02-12T16:20:44+00:00 app[web.1]:  OUT > <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" version="1.0" to="chat.hipchat.com">
2013-02-12T16:20:44+00:00 app[web.1]:  OUT > <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">MzQzOTBfMjM2MDMzQGNoYXQuaGlwY2hhdC5jb20AMzQzOTBfMjM2MDMzAGdlbGVydDU1</auth>
2013-02-12T16:20:44+00:00 app[web.1]:   IN > <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' version='1.0' from='chat.hipchat.com' id='cced9955252d259e'><stream:features><auth xmlns='http://jabber.org/features/iq-auth'/><auth xmlns='http://hipchat.com'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism></mechanisms></stream:features>
2013-02-12T16:20:44+00:00 app[web.1]: 
2013-02-12T16:20:44+00:00 app[web.1]: /app/node_modules/hubot-hipchat/src/hipchat.coffee:135
2013-02-12T16:20:44+00:00 app[web.1]:         if (message.message) {
2013-02-12T16:20:44+00:00 app[web.1]:                    ^
2013-02-12T16:20:45+00:00 app[web.1]: TypeError: Cannot read property 'message' of null
2013-02-12T16:20:45+00:00 app[web.1]:     at Bot.HipChat.run.bot.onMessage.author (/app/node_modules/hubot-hipchat/src/hipchat.coffee:135:20)
2013-02-12T16:20:45+00:00 app[web.1]:     at Bot.EventEmitter.emit (events.js:126:20)
2013-02-12T16:20:45+00:00 app[web.1]:     at Bot.module.exports.Bot.onStreamError (/app/node_modules/hubot-hipchat/node_modules/wobot/lib/bot.js:32:12)
2013-02-12T16:20:45+00:00 app[web.1]:     at Client.EventEmitter.emit (events.js:96:17)
2013-02-12T16:20:45+00:00 app[web.1]:     at Client.onRawStanza (/app/node_modules/hubot-hipchat/node_modules/wobot/node_modules/node-xmpp/lib/xmpp/client.js:124:18)
2013-02-12T16:20:45+00:00 app[web.1]:     at Client.EventEmitter.emit (events.js:96:17)
2013-02-12T16:20:45+00:00 app[web.1]:     at Client.Connection.onStanza (/app/node_modules/hubot-hipchat/node_modules/wobot/node_modules/node-xmpp/lib/xmpp/connection.js:237:14)
2013-02-12T16:20:45+00:00 app[web.1]:     at StreamParser.Connection.startParser (/app/node_modules/hubot-hipchat/node_modules/wobot/node_modules/node-xmpp/lib/xmpp/connection.js:136:14)
2013-02-12T16:20:45+00:00 app[web.1]:     at StreamParser.EventEmitter.emit (events.js:96:17)
2013-02-12T16:20:45+00:00 app[web.1]:     at null.<anonymous> (/app/node_modules/hubot-hipchat/node_modules/wobot/node_modules/node-xmpp/lib/xmpp/stream_parser.js:42:22)
2013-02-12T16:20:44+00:00 app[web.1]:  OUT > <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
2013-02-12T16:20:46+00:00 heroku[web.1]: Process exited with status 1
2013-02-12T16:20:46+00:00 heroku[web.1]: State changed from starting to crashed
2013-02-12T16:20:32+00:00 heroku[web.1]: State changed from crashed to starting

[powdahound]

Very strange. I don't have time to jump into this now but will try to take a look soon. If anyone feels up for a little debugging the help would be very much appreciated!

[andyhmltn]

Awesome, thank you very much!

[pusewicz]

Having the same issue ;)

[kiddouk]

Hi,

I believe that my latest pull request should solve you problems. At least, it solved mine. Would you mind testing @pusewicz and @andyhmltn .

you can find it here : https://github.com/hipchat/hubot-hipchat/pull/84

Thanks.

[andyhmltn]

Okay I'll test it out ASAP. I ended up ditching heroku so I'll try and recreate what I done before.

[mal]

Also getting this. @powdahound any chance you guys will be able to jump on this? The number of people seeing seems to be increasing!

Incidentally #84 stopped the error, but also stopped the bot doing anything (never connected).

[pusewicz]

Actually, for me the problem turned out to be wrong credentials. Instead of failing nicely, it would explode in my face ;)

[kiddouk]

@mal weird. #84 is in production for me. Can you maybe activate the debug to see what is happening on your side ?

[powdahound]

I'll try to take a look at this in the next few days. Damn upstream breaking stuff...

[mal]

Aha! Thanks @pusewicz!

Turns out the password was wrong :anguished:. Apparently one of my colleages changed it ages ago and forgot, and we only encountered the issue when restarting hubot after a crazy amount of uptime.

The null error can be solved by changing the onError function to handle the arguments it recieves, I guess they changed upstream; here's a dump of the arguments object it was receiving:

{ '0': null, '1': null, '2': 'XMPP authentication failure' }

[jameswritescode]

Has anyone been able to find more on this?

[rbergman]

Master includes better error reporting now. In the case of authentication failure, you'll now see a message like this:

[Mon May 13 2013 15:31:16 GMT-0600 (MDT)] ERROR null, null, 'XMPP authentication failure'