microsoft / botframework-sdk

Bot Framework provides the most comprehensive experience for building conversation applications.
MIT License
7.5k stars 2.44k forks source link

[Bug] Facebook integration error with Node -[TypeError: Cannot read property 'logger' of undefined] #2846

Closed barrychc closed 6 years ago

barrychc commented 7 years ago

Pre-flight checklist

System Information (Required)

Issue Description

Describe the issue here. I've deployed my simple chatbot to heroku/beanstalk and encountered an error with facebook integration. As soon as the server received the first message, an (internal) error was found on the server log.

Note: The code worked well with the webchat on botframework.com and slack integration.

Example Code

The complete bot code that reproduces the issue.

var builder = require('botbuilder');
var restify = require('restify');
var apiairecognizer = require('api-ai-recognizer');
var request = require('request');

// Setup Restify Server

var server = restify.createServer();
server.listen(process.env.port || process.env.PORT || 3978, function () {
    console.log('%s listening to %s', server.name, server.url);
});

// Create chat bot
var connector = new builder.ChatConnector({
    appId: process.env.MICROSOFT_APP_ID,
    appPassword: process.env.MICROSOFT_APP_PASSWORD
});

server.post('/api/messages', connector.listen());
var bot = new builder.UniversalBot(connector, [
    function (session, args, next) {
        if (!session.userData.name) {
            // Ask user for their name
            builder.Prompts.text(session, "Hello... What's your name?");
        } else {
            // Skip to next step
            next();
        }
    },
    function (session, results) {
        // Update name if answered
        if (results.response) {
            session.userData.name = results.response;
        }

        // Greet the user
        session.send("Hi %s!", session.userData.name);
        session.beginDialog('/mainMenu');
    }
]);
var recognizer = new apiairecognizer(process.env.APIAI_CLIENT_ACCESS_TOKEN);
var intents = new builder.IntentDialog({
    recognizers: [recognizer]
});
bot.dialog('/mainMenu', [
    function (session) {
        builder.Prompts.choice(session, "How may I help?", ["1. XXXX","2. FAQ"]);
    },
    function (session, results) {
        switch (results.response)
        {
            case "2":
                session.beginDialog('/faq');
        };
        session.endDialog();
    }
]);
bot.dialog('/faq',intents, [
    function (session) {
        builder.Prompts.text(session, "What's your question?");
    }
]);
intents.matches('smalltalk.greetings.hello',function(session, args){
    var fulfillment = builder.EntityRecognizer.findEntity( args.entities, 'fulfillment');
    if (fulfillment){
        var speech = fulfillment.entity;
        session.send(speech);
    }else{
        session.send('Sorry...not sure how to respond to that');
    }
});
var cache = [];
processIntent (intents, 'welab.faq');

intents.onDefault(function(session){
    session.send("Sorry...can you please rephrase?");
});
function processIntent (intents, intentName){
    intents.matches(intentName,function(session, args){
        var fulfillment = builder.EntityRecognizer.findEntity(args.entities, 'fulfillment');
        if (fulfillment){
            var speech = fulfillment.entity;
            session.send(speech);

            showIntentMeassage(intentName, session);

        }else{
            session.send('Sorry...not sure how to respond to that');
        }
    });
}

function showIntentMeassage(intentName, session){
    session.send("inTentName: " + intentName);
}

Steps to Reproduce

  1. Configure the facebook integration on botframework.com
  2. Send a message, such as 'hi' from facebook messenger.
  3. The error occured

Expected Behavior

What you expected to happen. I expect facebook messenger would receive a response from the chatbot

Actual Results

What actually happened. Please give examples and support it with screenshots, copied output or error messages.

The following error occured

2017-05-29T02:39:49.801852+00:00 app[web.1]: /app/node_modules/promise/lib/done.js:10
2017-05-29T02:39:49.801865+00:00 app[web.1]:       throw err;
2017-05-29T02:39:49.801867+00:00 app[web.1]:       ^
2017-05-29T02:39:49.801868+00:00 app[web.1]: 
2017-05-29T02:39:49.801869+00:00 app[web.1]: TypeError: Cannot read property 'logger' of undefined
2017-05-29T02:39:49.801871+00:00 app[web.1]:     at UniversalBot.Library.findActiveDialogRoutes (/app/node_modules/botbuilder/lib/bots/Library.js:135:20)
2017-05-29T02:39:49.801871+00:00 app[web.1]:     at /app/node_modules/botbuilder/lib/bots/Library.js:243:31
2017-05-29T02:39:49.801872+00:00 app[web.1]:     at /app/node_modules/async/lib/async.js:718:13
2017-05-29T02:39:49.801873+00:00 app[web.1]:     at async.forEachOf.async.eachOf (/app/node_modules/async/lib/async.js:233:13)
2017-05-29T02:39:49.801874+00:00 app[web.1]:     at _parallel (/app/node_modules/async/lib/async.js:717:9)
2017-05-29T02:39:49.801875+00:00 app[web.1]:     at Object.async.parallel (/app/node_modules/async/lib/async.js:731:9)
2017-05-29T02:39:49.801876+00:00 app[web.1]:     at /app/node_modules/botbuilder/lib/bots/Library.js:241:23
2017-05-29T02:39:49.801876+00:00 app[web.1]:     at UniversalBot.Library.recognize (/app/node_modules/botbuilder/lib/bots/Library.js:68:13)
2017-05-29T02:39:49.801877+00:00 app[web.1]:     at UniversalBot.Library.defaultFindRoutes (/app/node_modules/botbuilder/lib/bots/Library.js:236:14)
2017-05-29T02:39:49.801877+00:00 app[web.1]:     at UniversalBot.Library.findRoutes (/app/node_modules/botbuilder/lib/bots/Library.js:85:18)
2017-05-29T02:39:49.868006+00:00 heroku[web.1]: Process exited with status 1
2017-05-29T02:39:49.881799+00:00 heroku[web.1]: State changed from up to crashed
TrejGun commented 7 years ago

I have this error in slack integration

looks like this is a case only if you did not finish last session properly there is a line in example

bot.use(Middleware.dialogVersion({version: 1.0, resetCommand: /^reset/i}));

if you include it in your code and type reset in chat it will fix session

barrychc commented 7 years ago

Thanks, @TrejGun, for the info. In my case, the error still occurs even if the server is restarted and the FB messenger is the only client connecting to the server.

stevengum commented 7 years ago

@barrychc Are you still running into this issue? If so, what's the name of your FB bot? Is it currently being hosted on this channel or any others?

Has your bot been upgraded to SDK version 3.8.4? Have you also tried simplifying your bot down to the base waterfall dialogs and seeing if the error message is repeated?

pourmesomecode commented 7 years ago

I'm also getting this error. I can talk to my chatbot via the emulator but whenever I try to talk throught facebook messenger I get the TypeError: Cannot read property 'logger' of undefined error.

I've took my application apart back down to just one dialog and still getting this issue.

const restify = require('restify');
const builder = require('botbuilder');

const server = restify.createServer();
server.listen(process.env.port || process.env.PORT || 5000, () => {
  console.log('%s listening to %s', server.name, server.url);
});

const connector = new builder.ChatConnector({
  appId: process.env.MICROSOFT_APP_ID,
  appPassword: process.env.MICROSOFT_APP_PASSWORD,
});
const bot = new builder.UniversalBot(connector);
server.post('/api/messages', connector.listen());

bot.dialog('/', [
  (session) => {
    session.send('Hi... I\'m the Microsoft Bot Framework demo bot for Facebook. I can show you everything you can use our Bot Builder SDK to do on Facebook.');
    session.endDialog('Finish the dialog');
  },
]);

@barrychc did you manage to fix your issue?

amitbend commented 7 years ago

Hi, I can see the issue as well. but just for some of my users. I'm using the api-ai-recognizer.

this is the error details 2017-06-25T11:47:57.320 System.InvalidOperationException : TypeError: Cannot read property 'logger' of undefined at Library.findActiveDialogRoutes (D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\bots\Library.js:135:20) at D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\bots\Library.js:243:31 at D:\home\site\wwwroot\messages\node_modules\async\lib\async.js:718:13 at async.forEachOf.async.eachOf (D:\home\site\wwwroot\messages\node_modules\async\lib\async.js:233:13) at _parallel (D:\home\site\wwwroot\messages\node_modules\async\lib\async.js:717:9) at Object.async.parallel (D:\home\site\wwwroot\messages\node_modules\async\lib\async.js:731:9) at D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\bots\Library.js:241:23 at Library.recognize (D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\bots\Library.js:68:13) at Library.defaultFindRoutes (D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\bots\Library.js:236:14) at Library.findRoutes (D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\bots\Library.js:85:18) at D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\bots\UniversalBot.js:374:21 at D:\home\site\wwwroot\messages\node_modules\async\lib\async.js:181:20 at Object.async.forEachOf.async.eachOf (D:\home\site\wwwroot\messages\node_modules\async\lib\async.js:233:13) at Object.async.forEach.async.each (D:\home\site\wwwroot\messages\node_modules\async\lib\async.js:209:22) at D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\bots\UniversalBot.js:373:19 at D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\bots\Library.js:64:17 at next (D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\dialogs\IntentRecognizer.js:68:17) at IntentRecognizerSet.IntentRecognizer.filter (D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\dialogs\IntentRecognizer.js:71:9) at D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\dialogs\IntentRecognizer.js:20:31 at D:\home\site\wwwroot\messages\node_modules\botbuilder\lib\dialogs\IntentRecognizerSet.js:80:17 at D:\home\site\wwwroot\messages\node_modules\async\lib\async.js:52:16 at replenish (D:\home\site\wwwroot\messages\node_modules\async\lib\async.js:306:28)

barrychc commented 7 years ago

Sorry @pourmesomecode @stevengum97 that it was a proof of concept code which is no longer maintained so no more information can be provided.

We were also using the api-ai-recognizer and the complete code had been included in the issue though.

Sprinkle commented 7 years ago

@stevengum97 I think this is a bug with BotBuilder, in Library.ts of the function findActiveDialogRoutes

            if (dialog) {
                // Call recognize for the active dialog
                var ctx = <IRecognizeDialogContext>utils.clone(context);
                ctx.libraryName = this.name;
                ctx.dialogData = entry.state;
                ctx.activeDialog = true;
                dialog.recognize(ctx, (err, result) => {
                    if (!err) {
                        if (result.score < 0.1) {
                            // The active dialog should always have some score otherwise it
                            // can't ensure that its route data will be properly round tripped.
                            result.score = 0.1;
                        }
                        callback(null, Library.addRouteResult({
                            score: result.score,
                            libraryName: this.name,
                            routeType: Library.RouteTypes.ActiveDialog,
                            routeData: result
                        }, results));
                    } else {
                        callback(err, null);
                    }
                });
            } else {
                ctx.logger.warn(ctx.dialogStack(), "Active dialog '" + entry.id + "' not found in library.");
                callback(null, results);
            }

See the ctx object was declared using var and it probably should be declared with let, then notice the declaration of ctx is in the wrong scope.

In the outer most else block where it is trying to use ctx.logger, ctx is undefined (as ctx was declared for use by if branch above. The ctx.logger.warn line should be replaced with context.logger.warn.

mukeshzt commented 7 years ago

I'm also receiving the same error for skype client. But I'm using the botbuilder-calling and botbuilder node.js skype client botbuilder-calling

var restify = require('restify');
var builder = require('botbuilder');
var calling = require('botbuilder-calling');
// Setup Restify Server
var server = restify.createServer();
server.listen(process.env.port || process.env.PORT || 3978, function () {
   console.log('%s listening to %s', server.name, server.url); 
});
// Create chat bot
var chatConnector = new builder.ChatConnector({
     appId: process.env.MICROSOFT_APP_ID,
    appPassword: process.env.MICROSOFT_APP_PASSWORD
});
var chatBot = new builder.UniversalBot(chatConnector);
server.post('/api/messages', chatConnector.listen());
// Create calling bot
var connector = new calling.CallConnector({
    callbackUrl: 'https://<your host>/api/calls',
    appId: process.env.MICROSOFT_APP_ID,
    appPassword: process.env.MICROSOFT_APP_PASSWORD
});
var callingBot = new calling.UniversalCallBot(connector);
server.post('/api/calls', connector.listen());
// Add root dialog
chatBot.dialog('/', function (session) {
    session.send('Hi... Please call me to interact with me.'); 
});

callingBot.dialog('/', function (session) {
    session.send('Watson... come here!');
});;

run the node app.js

The following error occured

/home/marcus/advbot/node_modules/botbuilder/node_modules/promise/lib/done.js:10
      throw err;
      ^

TypeError: Cannot read property 'logger' of undefined
    at UniversalBot.Library.findActiveDialogRoutes (/home/marcus/advbot/node_modules/botbuilder/lib/bots/Library.js:135:20)
    at /home/marcus/advbot/node_modules/botbuilder/lib/bots/Library.js:243:31
    at /home/marcus/advbot/node_modules/botbuilder/node_modules/async/lib/async.js:718:13
    at async.forEachOf.async.eachOf (/home/marcus/advbot/node_modules/botbuilder/node_modules/async/lib/async.js:233:13)
    at _parallel (/home/marcus/advbot/node_modules/botbuilder/node_modules/async/lib/async.js:717:9)
    at Object.async.parallel (/home/marcus/advbot/node_modules/botbuilder/node_modules/async/lib/async.js:731:9)
    at /home/marcus/advbot/node_modules/botbuilder/lib/bots/Library.js:241:23
    at UniversalBot.Library.recognize (/home/marcus/advbot/node_modules/botbuilder/lib/bots/Library.js:68:13)
    at UniversalBot.Library.defaultFindRoutes (/home/marcus/advbot/node_modules/botbuilder/lib/bots/Library.js:236:14)
    at UniversalBot.Library.findRoutes (/home/marcus/advbot/node_modules/botbuilder/lib/bots/Library.js:85:18)

Please guide

nwhitmont commented 7 years ago

Relates to @mukeshzt SO post here: https://stackoverflow.com/questions/44824493/skype-integration-error-with-node-typeerror-cannot-read-property-logger-of

amitbend commented 7 years ago

Any news?

stevengum commented 7 years ago

A fix for the ctx issue has been filed and needs to be reviewed; it however won't fix the underlying problem that the dialog id hasn't been found in the current bot/library. I haven't had the chance to take a look at the code people have posted but I'll try to get around to it this week.

For the original issue, it looks like there is something strange going on with the intent handling through IntentDialog. Since the utterance OP provided is hi, it should just go to the default dialog because the IntentDialog hasn't been reached yet.

Edit: The above said, there shouldn't be any reason that your code would work on one channel and then not work on another, so there are definitely other issues that need to be looked into.

@amitbend and @mukeshzt did you run into this error message while using FB Messenger as well?

mukeshzt commented 7 years ago

@stevengum97 I'm only working on skype client and not yet tried with FB Messenger.

Now Today again I'm receiving the same error message. TypeError: Cannot read property 'logger' of undefined. Does it because of I'm deploying the files continuously and testing my bot on skype client?

amitbend commented 7 years ago

I see it on messenger as well

On 18 Jul 2017 01:33, "Steven Gum" notifications@github.com wrote:

A fix for the ctx https://github.com/Microsoft/BotBuilder/pull/3128 issue has been filed and needs to be reviewed; it however won't fix the underlying problem that the dialog id hasn't been found in the current bot/library. I haven't had the chance to take a look at the code people have posted but I'll try to get around to it this week.

For the original issue, it looks like there is something strange going on with the intent handling through IntentDialog. Since the utterance OP provided is hi, it should just go to the default dialog because the IntentDialog hasn't been reached yet.

@amitbend https://github.com/amitbend and @mukeshzt https://github.com/mukeshzt did you run into this error message while using FB Messenger as well?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/Microsoft/BotBuilder/issues/2846#issuecomment-315904529, or mute the thread https://github.com/notifications/unsubscribe-auth/AKvNgY8RROjklwtwN88mIcqi9WT_2jJDks5sO-EfgaJpZM4No20Q .

dominickm commented 7 years ago

I can confirm that the Middleware solution @TrejGun suggested works for this issue in Slack, however, the syntax that worked for me was: bot.use(builder.Middleware.dialogVersion({ version: 1.0, resetCommand: /^reset/i }));

amitbend commented 7 years ago

Any update? I can still see it on 3.9.0

mukeshzt commented 7 years ago

@amitbend Can you try to use the another user account for FB Messenger or Skype client. It works for me but not working on my previous account where I received the error.

pourmesomecode commented 7 years ago

I'd like to understand why the middleware solution fixes the issue for some as I don't completely understand what's going wrong to cause the issue to begin with. Why does setting the dialogVersion fix it?

I've not added in the dialogVersion to get around my issue by the way.

I reworked some of my dialogs. I managed to drop console.log's in my application until I found it was always erroring when trying to call session within a dialog. I figure it's something related to the dialog stack, not sure why though. After using beginDialogActions to always navigate between dialogs and disabling persistent data for conversations bot.set('persistConversationData', false); I've not ran into the issue.

But again, I don't understand the issue and therefore don't really understand why beginDialogActions and the persistent convo being false would fix it. My reasoning for trying the above methods was my guess at the issue, that the dialog stack couldn't handle the amount of pending dialogs or something and errors out. But I'd be interested to see what the actual issue is with.