search

hipchat / hubot-hipchat

HipChat adapter for GitHub's Hubot
https://www.hipchat.com/help/page/bots
MIT License
666 stars 252 forks source link

Listening but not Responding #112

Closed caselas closed 11 years ago

caselas commented 11 years ago

Our hubot has been running fine for several months, until I updated it today. I've been trying to debug this for quite a while, but can not find the source of the problem. I can see in the Heroku logs that hubot is in fact listening in the rooms, but there is no response to any commands. I've confirmed the Heroku config variables are all correct. Anybody see anything obvious? I'm really stumped.

package.json file:

{
  "name": "hosted-hubot",
  "version": "2.5.3",
  "author": "GitHub Inc.",
  "keywords": [
    "github",
    "hubot",
    "campfire",
    "bot"
  ],
  "description": "A simple helpful robot for your Company",
  "licenses": [
    {
      "type": "MIT",
      "url": "http://github.com/github/hubot/raw/master/LICENSE"
    }
  ],
  "repository": {
    "type": "git",
    "url": "https://github.com/github/hubot.git"
  },
  "dependencies": {
    "hubot": ">= 2.5.4",
    "hubot-scripts": ">= 2.4.6",
    "hubot-hipchat": "~2.5.1-4",
    "redis": "0.8.2",
    "twit": "1.1.6",
    "underscore": "1.4.4"
  },
  "engines": {
    "node": ">= 0.8.x",
    "npm": ">= 1.1.x"
  }
}

Heroku logs (with HUBOT_LOG_LEVEL set to debug) :

2013-06-19T00:02:44.081363+00:00 app[web.1]: [Wed Jun 19 2013 00:02:44 GMT+0000 (UTC)] DEBUG   IN > <message to='16932_16939@chat.hipchat.com/hubot-hipchat' type='groupchat' from='1693_gravbot_testing@conf.hipchat.com/Chris Caselas'><body>gravbot help</body></message>
2013-06-19T00:02:45.774658+00:00 app[web.1]: [Wed Jun 19 2013 00:02:45 GMT+0000 (UTC)] DEBUG  OUT >

Heroku restart:

2013-06-19T00:06:40.609567+00:00 heroku[web.1]: State changed from up to starting
2013-06-19T00:06:41.857679+00:00 heroku[web.1]: Starting process with command `bin/hubot --adapter hipchat -n "Grav Bot"`
...
2013-06-19T00:06:45.441070+00:00 app[web.1]: 2013-06-18T20:05:38Z' from_jid='16932_21042@chat.hipchat.com'/></message><presence to='16932_16939@chat.hipchat.com/hubot-hipchat-37793' from='1932_watercooler@conf.hipchat.com/Grav Bot'><x xmlns='http://jabber.org/protocol/muc#user'><item affiliation='member' jid='1632_69399@chat.hipchat.com/hubot-hipchat-3793' role='participant'/><status code='110'/></x></presence>
2013-06-19T00:06:47.144508+00:00 heroku[web.1]: Process exited with status 143
caselas commented 11 years ago

Aha, I found this in the logs:

2013-06-19T00:30:49.621763+00:00 app[web.1]: [Wed Jun 19 2013 00:30:49 GMT+0000 (UTC)] DEBUG Loading hubot-scripts from /app/node_modules/hubot-scripts/src/scripts
2013-06-19T00:30:49.656051+00:00 app[web.1]: [Wed Jun 19 2013 00:30:49 GMT+0000 (UTC)] INFO Disabling brain auto-saving
2013-06-19T00:30:49.658971+00:00 app[web.1]: [Wed Jun 19 2013 00:30:49 GMT+0000 (UTC)] ERROR Unable to load /app/node_modules/hubot-scripts/src/scripts/redis-brain:
2013-06-19T00:30:49.658971+00:00 app[web.1]: TypeError: Object #<Brain> has no method 'setAutoSave'
2013-06-19T00:30:49.658971+00:00 app[web.1]:   at module.exports (/app/node_modules/hubot-scripts/src/scripts/redis-brain.coffee:48:3, <js>:35:17)
2013-06-19T00:30:49.658971+00:00 app[web.1]:   at Scripts.loadFile (/app/node_modules/hubot/src/scripts.coffee:107:9, <js>:102:24)
2013-06-19T00:30:49.658971+00:00 app[web.1]:   at Scripts.loadHubotScripts (/app/node_modules/hubot/src/scripts.coffee:121:5, <js>:118:28)
2013-06-19T00:30:49.658971+00:00 app[web.1]:   at /app/node_modules/hubot/src/scripts.coffee:56:9, <js>:45:24
2013-06-19T00:30:49.658971+00:00 app[web.1]:   at fs.js:266:14
2013-06-19T00:30:49.658971+00:00 app[web.1]:   at Object.oncomplete (fs.js:107:15)
2013-06-19T00:30:49.658971+00:00 app[web.1]:
2013-06-19T00:30:50.789585+00:00 heroku[web.1]: Process exited with status 1
2013-06-19T00:30:50.803781+00:00 heroku[web.1]: State changed from up to crashed
caselas commented 11 years ago

Hm, fixed that (by simply removing redis-brain) and still not getting any response from hubot. Just this:

2013-06-19T01:13:39.038639+00:00 app[web.1]: [Wed Jun 19 2013 01:13:39 GMT+0000 (UTC)] DEBUG   IN > <message to='1692_16999@chat.hipchat.com/hubot-hipchat' type='groupchat' from='1693_gravbot_testing@conf.hipchat.com/Chris Caselas'><body>gravbot help</body></message>
2013-06-19T01:13:48.237766+00:00 app[web.1]: [Wed Jun 19 2013 01:13:48 GMT+0000 (UTC)] DEBUG  OUT >
rbergman commented 11 years ago

It's be interesting to try downgrading your hubot to 2.5.1 -- we haven't tested with 2.5.4 yet.

caselas commented 11 years ago

@rbergman Ah, I'll give that a try, and post the results here. Thanks.

caselas commented 11 years ago

You were exactly right. Thanks.

bhardin commented 11 years ago

I downgraded hubot to 2.5.1 and I'm still getting the issue stated above.

caselas commented 11 years ago

@bhardin This is what I ended up with, in order to get hubot to start responding again:

{
  "name": "hosted-hubot",
  "version": "2.5.3",
  "author": "GitHub Inc.",
  "keywords": [
    "github",
    "hubot",
    "campfire",
    "bot"
  ],
  "description": "A simple helpful robot for your Company",
  "licenses": [
    {
      "type": "MIT",
      "url": "http://github.com/github/hubot/raw/master/LICENSE"
    }
  ],
  "repository": {
    "type": "git",
    "url": "https://github.com/github/hubot.git"
  },
  "dependencies": {
    "hubot": "2.5.1",
    "hubot-scripts": ">= 2.4.6",
    "hubot-hipchat": "2.5.1-4",
    "redis": "0.8.2",
    "twit": "1.1.6",
    "underscore": "1.4.4"
  },
  "engines": {
    "node": ">= 0.8.x",
    "npm": ">= 1.1.x"
  }
}

Do you see anything in your logs? (I imagine its hosted on Heroku.) You can set your log level to debug:

heroku config:add HUBOT_LOG_LEVEL=debug
mcfiredrill commented 11 years ago

Having the same problem. I tried using your package.json but then I get this error:

[Thu Aug 08 2013 04:46:02 GMT-0700 (PDT)] DEBUG Loading hubot-scripts from /home/tony/src/mybot/node_modules/hubot-scripts/src/scripts
[Thu Aug 08 2013 04:46:02 GMT-0700 (PDT)] ERROR Unable to load /home/tony/src/mybot/node_modules/hubot-scripts/src/scripts/redis-brain: TypeError: Object #<Brain> has no method 'setAutoSave'
  at module.exports (/home/tony/src/mybot/node_modules/hubot-scripts/src/scripts/redis-brain.coffee:13:17)
  at Robot.loadFile (/home/tony/src/mybot/node_modules/hubot/src/robot.coffee:133:24)
  at Robot.loadHubotScripts (/home/tony/src/mybot/node_modules/hubot/src/robot.coffee:169:28)
  at /home/tony/src/mybot/node_modules/hubot/bin/hubot:98:15, <js>:101:30
  at fs.js:266:14
  at Object.oncomplete (fs.js:107:15)
halkeye commented 11 years ago

@mcfiredrill your hubot-scripts is too new for your hubot. You should probably update hubot version.

dkador commented 11 years ago

I'm still having this problem. I've tried a bunch of different package.json configs. Here's what I'm at now:

{
  "name": "hosted-hubot",
  "version": "2.4.8",
  "author": "GitHub Inc.",
  "keywords": "github hubot campfire bot",
  "description": "A simple helpful Robot for your Company",
  "licenses": [
    {
      "type": "MIT",
      "url": "http://github.com/github/hubot/raw/master/LICENSE"
    }
  ],
  "repository": {
    "type": "git",
    "url": "https://github.com/github/hubot.git"
  },
  "dependencies": {
    "hubot": "2.5.1",
    "hubot-scripts": "2.4.2",
    "hubot-hipchat": "2.5.1-4",
    "scraper": ">= 0.0.9",
    "optparse": "1.0.3"
  },
  "engines": {
    "node": "0.8.x",
    "npm": "1.1.x"
  }
}

Private messaging my hubot (its name is "robot" because I am very creative) works. But @ messages in public rooms don't. I'm seeing the same kind of log output as @caselas was seeing when I turn on debug logs (hubot sees the messages but doesn't think they're a regex match).

mcfiredrill commented 11 years ago

My bot seems to respond after I private message it first.

dkador commented 11 years ago

Weird, I don't have that behavior. Can you share your package.json, @mcfiredrill?

mcfiredrill commented 11 years ago 
{
  "name": "hosted-hubot",
  "version": "2.6.0",
  "author": "GitHub Inc.",
  "keywords": [
    "github",
    "hubot",
    "campfire",
    "bot"
  ],
  "description": "A simple helpful robot for your Company",
  "licenses": [
    {
      "type": "MIT",
      "url": "https://github.com/github/hubot/raw/master/LICENSE"
    }
  ],
  "repository": {
    "type": "git",
    "url": "https://github.com/github/hubot.git"
  },
  "dependencies": {
    "hubot": "2.6.2",
    "hubot-scripts": ">= 2.5.0 < 3.0.0",
    "hubot-hipchat": "~2.5.1-4"
  },
  "engines": {
    "node": ">= 0.8.x",
    "npm": ">= 1.1.x"
  }
}
dkador commented 11 years ago

Still no go. I'm going to guess I've just ruined something at some point. Will attempt to start from scratch.

beaugunderson commented 11 years ago

Also had the problem the original reporter did, downgrading from hubot-scripts 2.5.3 to 2.5.2 fixed the issue. Note that by downgrade I mean rm -rf node_modules && npm install.

russmatney commented 10 years ago

Just ran into this, thought i'd share my working package.json if it helps anyone:

{
  "name": "hosted-hubot",
  "version": "2.3.2",
  "author": "GitHub Inc.",
  "keywords": "github hubot campfire bot",
  "description": "A simple helpful Robot for your Company",
  "licenses": [
    {
      "type": "MIT",
      "url": "http://github.com/github/hubot/raw/master/LICENSE"
    }
  ],
  "repository": {
    "type": "git",
    "url": "https://github.com/github/hubot.git"
  },
  "dependencies": {
    "hubot": "2.5.1",
    "hubot-scripts": "2.5.2",
    "optparse": "1.0.3",
    "hubot-hipchat": "~2.5.1-5"
  },
  "engines": {
    "node": "0.8.x",
    "npm": "1.1.x"
  }
}