microsoft / botbuilder-js

Welcome to the Bot Framework SDK for JavaScript repository, which is the home for the libraries and packages that enable developers to build sophisticated bot applications using JavaScript.
https://github.com/Microsoft/botframework
MIT License
681 stars 277 forks source link

Proactive message is throwing error in Transcript logger #3768

Closed tomSauret847 closed 3 years ago

tomSauret847 commented 3 years ago

Github issues should be used for bugs and feature requests. Use Stack Overflow for general "how-to" questions.

Versions

What package version of the SDK are you using. 4.13.6 What nodejs version are you using 10.24.1 What browser version are you using N/A What os are you using Windows

Describe the bug

Give a clear and concise description of what the bug is. When trying to implement Proactive messages the transcript logger is throwing this error TypeError: Cannot read property 'role' of undefined at TranscriptLoggerMiddleware. (c:\Users\user\project\node_modules\botbuilder-core\lib\transcriptLogger.js:46:44)

Running a debugger the "continueConversation" is passing in a empty event that has no "From" property

To Reproduce

Steps to reproduce the behavior: Implement proactive messaging route send proactive message to the bot When running the follow code the transcript logger will throw the error const continueConversation: Partial = turnContext.activity.value; // conversation reference is stored in the activity.value object await turnContext.adapter.continueConversation(continueConversation, async (context) => { context.activity.value = continueConversation.value;
await runDialog(this.dialog, context, this.dialogStateAccessor); });

Expected behavior

Give a clear and concise description of what you expected to happen. I expect the bot will continue the conversation and forward the event onto the dialog that is waiting on the stack

Additional context

Add any other context about the problem here. Object passed to transcript logger

channelId:'emulator' conversation:{id: 'a522e6d0-cfaa-11eb-bd65-154375251c8b|livechat-adskill-emulator-skillconvo'} from:undefined locale:'en-us' name:'ContinueConversation' recipient:undefined serviceUrl:'http://localhost:3979/api/skills' type:'event' proto:Object

joshgummersall commented 3 years ago

The adapter signatures for continueConversation here indicate that you can supply a Partial<ConversationReference>. However, the TurnContext.applyConversationReference function expects the conversation reference to include one of user or bot as that is what populates activity.from. Can you try including the bot property in your conversation reference?

tomSauret847 commented 3 years ago

Thank you @joshgummersall for looking into this. currently we are passing in a conversation reference that is from the user

channelId:'emulator' conversation:{id: 'f1e6ed20-d056-11eb-bd65-154375251c8b|livechat-adskill-emulator-skillconvo'} from:{id: '9cb9948a-99cf-4e37-a9d5-44d5737f4105', name: 'User', role: 'user'} id:'9cb9948a-99cf-4e37-a9d5-44d5737f4105' name:'User' role:'user' proto:Object id:'fd451520-d056-11eb-abe2-b1f9aaf21a40' locale:'en-us' localTimestamp:'2021-06-18T17:02:39.000Z' rawLocalTimestamp:'2021-06-18T17:02:39.000Z' rawTimestamp:'2021-06-18T17:02:39.986Z' recipient:{id: '92effe40-cfa4-11eb-bd65-154375251c8b', name: 'Bot', role: 'skill'} id:'92effe40-cfa4-11eb-bd65-154375251c8b' name:'Bot' role:'skill' proto:Object relatesTo:{serviceUrl: 'http://localhost:64138', activityId: 'fd451520-d056-11eb-abe2-b1f9aaf21a40', channelId: 'emulator', conversation: {…}, bot: null} serviceUrl:'http://localhost:3979/api/skills' text:'user' textFormat:'plain' timestamp:'2021-06-18T17:02:39.986Z' type:'message'

To provide more context I am using the VA /Skill model and trying to implement a long running process that will give the bot more time to complete the action. I am generating the event in the skill and providing the conversation reference that is generated in the skill from the last message the bot receives. I am substituting the serviceUrl for the serviceUrl of the VA to ensure it is sent to the correct endpoint. when replacing the from object with the bot's property like this //@ts-ignore continueConversation.from = continueConversation.recipient; I receive the same error where it cannot read the property "role" of undefined I am checking prior to calling continueConversation and the from property is populated, but when it gets to the transcript logger the from and recipient is undefined.

joshgummersall commented 3 years ago

Can you provide the full stack trace? I wonder if there is a shallow copy that's being modified somewhere.

tomSauret847 commented 3 years ago

Here is the full stack trace from the exception that is thrown

TypeError: Cannot read property 'role' of undefined at TranscriptLoggerMiddleware. (C:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\transcriptLogger.js:46:44) at Generator.next () at C:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\transcriptLogger.js:15:71 at new Promise () at __awaiter (C:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\transcriptLogger.js:11:12) at TranscriptLoggerMiddleware.onTurn (C:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\transcriptLogger.js:42:16) at middleware.push (C:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\middlewareSet.js:61:64) at runHandlers (C:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\middlewareSet.js:78:50) at Promise.resolve.handler (C:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\middlewareSet.js:78:73) at TelemetryLoggerMiddleware. (C:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\telemetryLoggerMiddleware.js:93:23)

joshgummersall commented 3 years ago

In attempting to reproduce the issue, I started with the Proactive Message sample project and then applied this diff:

diff --git a/samples/typescript_nodejs/16.proactive-messages/src/index.ts b/samples/typescript_nodejs/16.proactive-messages/src/index.ts
index 2a502137..b613a4a4 100644
--- a/samples/typescript_nodejs/16.proactive-messages/src/index.ts
+++ b/samples/typescript_nodejs/16.proactive-messages/src/index.ts
@@ -7,7 +7,7 @@ import * as restify from 'restify';

 // Import required bot services.
 // See https://aka.ms/bot-services to learn more about the different parts of a bot.
-import { BotFrameworkAdapter } from 'botbuilder';
+import { BotFrameworkAdapter, ConsoleTranscriptLogger, TranscriptLoggerMiddleware } from 'botbuilder';

 // This bot's main dialog.
 import { EchoBot } from './bot';
@@ -34,6 +34,12 @@ const adapter = new BotFrameworkAdapter({
     appPassword: process.env.MicrosoftAppPassword
 });

+adapter.use(
+  new TranscriptLoggerMiddleware(
+    new ConsoleTranscriptLogger()
+  )
+)
+
 // Catch-all for errors.
 const onTurnErrorHandler = async (context, error) => {
     // This check writes out errors to console log .vs. app insights.
@@ -113,4 +119,4 @@ server.post('/api/notify', async (req, res) => {
     res.writeHead(200);
     res.write('Proactive messages have been sent.');
     res.end();
-});
\ No newline at end of file
+});

I connect to the Bot using the Emulator, then trigger the proactive message with:

curl http://localhost:3978/api/notify

And everything works as expected. Could you share more details on what middleware you're using? Are you manipulating or copying activities anywhere inside your codebase? If you could test your Bot while disabling middleware components to try to isolate the problem, that would be helpful!

tomSauret847 commented 3 years ago

Thank you @joshgummersall I disabled all the middleware and ran it again and got his error Error: missing activity.from.id at UserState.getStorageKey (c:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\userState.js:45:19) at UserState [as storageKey] (c:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\userState.js:28:30) at UserState.load (c:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\botState.js:63:41) at BotStatePropertyAccessor. (c:\Users\user\Desktop\Cori\CORI_Virtual_Assistant\node_modules\botbuilder-core\lib\botStatePropertyAccessor.js:55:42)

we are not doing any other manipulation on the activities in the bot. I am following this example for implementing a long running operation (converting to Typescript)

instead of using a proactive message route in index.ts I am using a event handler inside of the activity handler that is extending the Teams activity handler. The skill is sending a event to the VA with a name of "LongRunningProccess" which it catches in the onEvent method. Passing in the conversation reference should allow us to pass the event back to the skill to let it notify the user of the results of the long running process. I have also tested this in the .Net version and it functions as expected passing the event back and returning the event to the skill. Our VA is in typescript so we will need to use this process in Node.

joshgummersall commented 3 years ago

@tomSauret847, can you share more of your code? I'm actually having a hard time putting together the Typescript version of the C# example you linked above. In particular, I'd like to see the code that pushes activities into the Azure Storage Queue, then the Azure Function code listening to the Queue. If you can't share the exact source code, approximations should be fine. I'm just trying to get a sample together that reproduces your issue so I can debug it. Thank you!

tomSauret847 commented 3 years ago

Thank you @joshgummersall for looking into this. Give me a couple of days and I will generate a bot that has the template code in it that is causing the issue. I will be able to zip up the project and attach it here for you to use.

tomSauret847 commented 3 years ago

LongRunningExample.zip @joshgummersall I have attached a zip file with the sample code that reproduces the issue I reported. To run the sample follow these steps: Add a bot ID and secret to the appsettings.json file in the "sample-skill" Add a Application insights key to the appsettings.json in the sample-skill Add a different bot ID and secret in the appsettings.json file in the "sample-assistant" Add the app insights key from the sample skill to the sample-assistant Add the bot Id you assigned the skill into the appsettings.json in the sample-assistant on line 28 start debugging both bots with a break point on line 105 in the defaultActivityHandler.ts in the sample assistant there is no LUIS involved so you can just message the bot and it will prompt you for your name then send any message to the bot and it will start the skill, the skill will prompt you for your name again then kick off the long running prompt. When the sample assistant receives the event back from the skill, it will throw the error that is listed above.

joshgummersall commented 3 years ago

sample.zip

This is an amended sample that I confirmed is working.

There were a few issues with your code. The first was using a context reference after a turn ended (in the Skill, this was due to not awaiting the long running process). The context is not valid once a turn is over, you must use adapter.continueConversation with a reference in that case.

The second was how you passed the reference back to the parent from the skill.

Take a look at the code and let me know if you have any other questions!

tomSauret847 commented 3 years ago

Thank you @joshgummersall !!! this was what I was needing to fix the issue. My apologies for opening a issue for my mistake. The issue is resolved and I will close out this issue. Thank you again for all your assistance!

joshgummersall commented 3 years ago

Glad to help - it's a trick scenario! Cheers.