CloudAdapter: messages are not sorted correctly

[mschuelein]

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.16.0 What nodejs version are you using: 14.15.1 What browser version are you using: Google Chrome Version 104.0.5112.102 What os are you using: Windows 10 Pro (Version 10.0.19044)

Describe the bug

We recently started using CloudAdapter, because we've seen that BotFrameworkAdapter is deprecated. Since we use CloudAdapter, activities that get sent very shortly after each other dont get sorted correctly. They get shown in seemingly random order in the WebChat Frontend. This happens when sendActivities and sendActivity are used from the TurnContext. The reason the messages are not in the right order is, that the timestamp of the activities recieved in the WebChat Frontend are in different order then when the activities where sent from the Backend.

To Reproduce

Steps to reproduce the behavior:

1. Migrate from BotFrameworkAdapter to CloudAdapter
2. Send multiple activities directly after each other. This can either be done by using sendActivities, or multiple use of sendActivity, f.e. in a for loop.
3. Do this multiple times, and the activities dont get shown in the correct order, and for multiple tries they get shown in different orders.

Expected behavior

The timestamps that are recieved by the Frontend are in the same order as they get sent out in the Backend.

Additional context

• Initialization of CloudAdapter: const botFrameworkAuthentication = createBotFrameworkAuthenticationFromConfiguration(null, credentialsFactory); const adapter = new CloudAdapter(botFrameworkAuthentication);
• Usage of CloudAdapter: this.getCloudAdapter().process(req, res, async (turnContext) => { await BotInstance.getInstance().run(turnContext);});
• I have looked at the responses of sendActivities for both cases, and the only difference I could see was the user-agent value in the headers of the request: CloudAdapter: Microsoft-BotFramework/3.1 botframework-connector/4.16.0 ms-rest-js/1.9.1 Node/v14.15.1 OS/(x64-Windows_NT-10.0.19044) BotFrameworkAdapter: Microsoft-BotFramework/3.1 BotBuilder/4.16.0 (Node.js,Version=v14.15.1; Windows_NT 10.0.19044; x64)
• One way I could fix the problem, was by inserting a 50 millisecond delay after each call of sendActivity. When doing that, the timestamps seemed to be in the right order. But when I reduced the delay to 25 milliseconds the problem occured again.

[stevkan]

@mschuelein - Are you able to post a copy of your code for both your bot as well as your Web Chat implementation? Or, a basic repro of both in case you can't share your project? It looks like you have customized your code a little bit (when compared to our samples). Having your code will be easier than trying to guess your precise setup.

I'm curious to see your setup as I also migrated a test bot several months ago from the BF adapter to the cloud adapter. However, I did not run into this issue when doing so nor has it come up since.

[MatthiasGwiozda]

@stevkan I't very easy to reproduce, even without much customization:

reproduction - steps

• Use the latest webchat (Integrate With JavaScript)
• Install yeoman
• Create a new echo-bot with yeoman
• Use the sendactivities - function in the bot.ts:

  this.onMessage(async (context, next) => {
  const text1 = MessageFactory.text("1");
  const text2 = MessageFactory.text("2");
  await context.sendActivities([
      text1,
      text2
  ]);
  // By calling next() you ensure that the next BotHandler is run.
  await next();
  });

• Create a new Azure Bot or Web App Bot Ressource in Azure (The Bug happens in both ressources)
• Insert the secret of the Web App Bot in your Webchat
• Configure the MicrosoftAppId + MicrosoftAppPassword in the .env file in the backend
• Start the Backend with ngrok
• Configure the ngrok - URL in your Azure Web App
• send multiple messages to the bot

Note that this problem seems like a reace condition. Sometimes the order of the messages is wrong and sometimes it's correct. It's random:

Example - Code

Here the example, which Ive generated just today. You have to use npm install. before starting the bot: message_order_bug_reproduction.zip

Context

• I'm using node V16.17.0

[stevkan]

@mschuelein - Thank you for the code sample. I am able to repro the issue and am diving deeper into it. I have a suspicion as to what the cause may be. I need to speak with a colleague about it. When I know more, I will respond.

[dmvtech]

@JuanAr This was reproduced by Steve and myself. Please let us know if you have any questions regarding the behavior/repro.