Botkit: bot.say fails when using middleware (dashbot)

[alecl]

Happening with 0.4.7 and latest 0.5.1. Worked fine before putting in a dashbot API key. My bot is based on the Slack starter from howdy.

I'm running this after controller.startTicking().

  var myTeam = 'Txxxxx';

  controller.storage.teams.get(myTeam, (err, team) => {
    if (err || !team) {
      controller.log.error('Error: could not load my team from storage system', err);
    } else {
      var botToken = team.bot.token;
      var channel = team.bot.createdBy;

      if (process.env.NODE_ENV === 'staging') {
        channel = 'Cxxxxx';
      }

      var startupBot = controller.spawn({
        token: botToken,
      });
      startupBot.say({ text: `started`, channel });
    }
  });

After hitting the startupBot.say link it then fails here where worker is null so .send isn't valid.

https://github.com/howdyai/botkit/blob/0188c5bfce2c7bf1942234d9aa057cc1c588ee61/lib/CoreBot.js#L1031

If I remove the DASHBOT_API_KEY all is fine again.

[peterkinmond]

@alecl what repo are you testing this with? I tried to reproduce with my bot (using Botkit 0.4.7 and Dashbot 0.6.1) but didn't see the error. The bot.say function worked both with and without the middleware. Used the following:

var bot = controller.spawn({
  token: process.env.SLACK_TOKEN
});

if (process.env.DASHBOT_TOKEN) {
   // Add the dashbot middleware - used for bot analytics (dashbot.io)
  var dashbot = require('dashbot')(process.env.DASHBOT_TOKEN).slack;
  controller.middleware.receive.use(dashbot.receive);
  controller.middleware.send.use(dashbot.send);
}

bot.api.channels.list({}, function(err, response) {
  var channel = response.channels[0];
  bot.say({text: 'started', channel: channel.id});
});

[alecl]

Super weird. I pulled https://github.com/howdyai/botkit-starter-slack and wasn't able to repeat. Then I messed with the versions of dashbot back and forth and now I can't get it to stop happening even on a fresh pull in a new directory. I found the root cause though.

First off there's a missing error check here which obscured the problem

https://github.com/howdyai/botkit/blob/master/lib/CoreBot.js#L1031

I added it like this and this is the error I am seeing when dashbot is enabled. Not sure if this is the error style that's appropriate. If so happy to PR it.

        worker.say = function(message, cb) {
            botkit.middleware.send.run(worker, message, function(err, worker, message) {
                if (err) {
                    botkit.log('Error in worker say: ' + err);
                } else {
                    worker.send(message, cb);
                }
            });
        };

TypeError: Cannot convert undefined or null to object
    at addTeamInfo (/Users/alec/gitproj/botkit-starter2/node_modules/dashbot/src/dashbot.js:171:12)
    at Ware.that.send (/Users/alec/gitproj/botkit-starter2/node_modules/dashbot/src/dashbot.js:224:25)
    at Ware.<anonymous> (/Users/alec/gitproj/botkit-starter2/node_modules/wrap-fn/index.js:45:19)
    at next (/Users/alec/gitproj/botkit-starter2/node_modules/ware/lib/index.js:85:20)
    at Ware.run (/Users/alec/gitproj/botkit-starter2/node_modules/ware/lib/index.js:88:3)
    at Object.botkit.spawn.worker.say (/Users/alec/gitproj/botkit-starter2/node_modules/botkit/lib/CoreBot.js:1030:36)
    at /Users/alec/gitproj/botkit-starter2/bot.js:178:9
    at Request._callback (/Users/alec/gitproj/botkit-starter2/node_modules/botkit/lib/Slack_web_api.js:242:28)
    at Request.init.self.callback (/Users/alec/gitproj/botkit-starter2/node_modules/request/request.js:186:22)
    at emitTwo (events.js:87:13)
    at Request.emit (events.js:172:7)
    at Request.<anonymous> (/Users/alec/gitproj/botkit-starter2/node_modules/request/request.js:1081:10)
    at emitOne (events.js:77:13)
    at Request.emit (events.js:169:7)
    at IncomingMessage.<anonymous> (/Users/alec/gitproj/botkit-starter2/node_modules/request/request.js:1001:12)
    at IncomingMessage.g (events.js:260:16)

This is the area in dashbot.js where the issue is:

https://github.com/actionably/dashbot/blob/master/src/dashbot.js#L176

  function addTeamInfo(bot, message) {
    var id = _.cloneDeep(bot.identity);
    delete id.prefs;
    var teamInfo = _.cloneDeep(bot.team_info);
    delete teamInfo.prefs;
    if (!id.id && _.get(teamInfo, 'bot.user_id')) {
      id = {
        id: _.get(teamInfo, 'bot.user_id')
      }
    }
    teamInfo.bot = id;
    return {
      team: teamInfo,
      bot: id,
      token: bot.config.token,
      message: message
    };
  }

The problem is bot.identity doesn't have the info:

{id: null, name: ""}

and bot.team_info doesn't exist at call blowing up

Creating a bot worker with the token in this manner causes these fields to not to be filled in. When you add the bot to the channel instead for instance, they are filled in by testbot.api.auth.test in components/user_registration.js

var bot = controller.spawn({
  token: process.env.SLACK_TOKEN
});

Sooo... I can recreate the identity and team_info structures on the bot loading from storage when needed like this and now it works all of the time. I'm not certain why this workaround is needed but it works.

  var myTeam = 'Txxxxx';

  controller.storage.teams.get(myTeam, (err, team) => {
    if (err || !team) {
      controller.log.error('Error: could not load my team from storage system', err);
    } else {
      var botToken = team.bot.token;
      var channel = team.bot.createdBy;

      if (process.env.NODE_ENV === 'staging') {
        channel = 'Cxxxxx';
      }

      var startupBot = controller.spawn({
        token: botToken,
      });

      if (!startupBot.identity || !startupBot.identity.id) {
        var identity = {
          ok: true,
          team: team.name,
          team_id: team.id,
          url: team.url,
          user: team.bot.name,
          user_id: team.bot.user_id,
        };
        startupBot.identity = identity;
      }
      if (!startupBot.team_info) {
        startupBot.team_info = team;
      }

      startupBot.say({ text: `started`, channel });
    }
  });

[sinned]

Aha.. Interesting, I wasn't able to reproduce the bug either so thanks for digging into this...

[alecl]

Added #691 to at least have the error logging in place that made the situation confusing in the first place and seeing if Ben has any idea why identity and team_info are missing at times.

[jonchurch]

@alecl When spawning a bot right now, team_info is not set _unless you start the RTM_. Which is left over from how things worked under RTM.

Under Events API, we are setting the team_info and identity inside the handleWebhookPayload function after spawning a bot to respond to a message received at the webhook.

It's acceptable to spawn a bot without a bot identity (slash commands for example), and that seems to have led to attaching team_info and identity elsewhere under Events API. Leaving you with a bot.config but not a bot.team_info after spawning.

Not sure what is appropriate here as a fix, either set team_info on spawn, or have dashbot look in bot.config for the identity.
@sinned

[znat]

Same happens with a facebook bot:
Cannot convert undefined or null to object at addTeamInfo (/app/node_modules/dashbot/src/dashbot.js:169:12)

[sinned]

Ok.. we're taking a look at this and will update with a fix soon.

[itozapata]

@jonchurch @alecl This is Ito at Dashbot.

Ive modified the library to send us information that the team is unknown so as to not fail in this instance and still get information back to dashbot for analytics. Can you give it a try to use an alpha version of the dashbot library and see if it clears up the problem on your end before i push it as the new version of the dashbot library

should just require a npm install dashbot@alpha-1 --save inside your project to use it.

thanks

[alecl]

@itozapata sorry for the long delay. Confirmed fixed not crashing. However, I'm still going to be running my fallback code to fill in the info as I'd rather have as much as possible in dashbot and not lose the team.

[sinned]

Thanks Alec!!