Bot loading stale state

[CNKrit]

We have developed our bot using Microsoft Bot Composer 2.1.2 in C#. We have installed the app in Slack. We use Slack Adapter(package : Bot.Builder.Community.Adapters.Slack, version 4.13.5) to post messages from Slack to the bot. However, we are facing an issue in which the bot's response does not appear in the order it has been designed in the composer. For ex:

Slack User : help -- Begin Turn 1 Bot : Do you want to login? Enter the email address -- Bot State 1 Slack User : abc@test.com -- Begin Turn 2 Bot: OTP has been emailed to you. Enter the OTP. -- Bot State 2 Slack User: 123456 -- Begin Turn 3 Bot : The email address is invalid. Re-enter the valid email address. -- Bot State 3

During Turn 3, the Bot instead of loading Bot State 2, loads Bot State 1 and expects an email address. Slack sends payloads of type Activity.Message and Activity.Event to the bot.

In the Microsoft.Bot.Builder project, SaveChangesAsync method of BotState.cs, I added some code to dump the BotState in a json file

` public virtual async Task SaveChangesAsync(ITurnContext turnContext, bool force = false, CancellationToken cancellationToken = default(CancellationToken)) {

        BotAssert.ContextNotNull(turnContext);
        var cachedState = GetCachedState(turnContext);

        using (StreamWriter writer = new StreamWriter("/Users/krithikavenugopal/Documents/Continube/BotCode/monkrit/cache-bot-state.json", append: true))
        {
            if (cachedState != null && cachedState.State != null && cachedState.State.ContainsKey("DialogState"))
            {
                writer.WriteLine("=================START OF DATA SAVE INFO====================");
                string docStr = $"Activity = {turnContext.Activity.Type} and message = {turnContext.Activity.Text}";
                writer.WriteLine(docStr);

                docStr = Newtonsoft.Json.JsonConvert.SerializeObject(cachedState);
                writer.WriteLine("Cached State is : " + docStr);
            }

            if (cachedState != null && cachedState.State != null && cachedState.State.ContainsKey("DialogState")
                        && cachedState.IsChanged())
                writer.WriteLine("Cached State Change Status is : " + ((cachedState.IsChanged()) ? "changed" : "Unchanged"));

            if (cachedState != null && (force || cachedState.IsChanged()))
            {
                if (cachedState != null && cachedState.State != null && cachedState.State.ContainsKey("DialogState"))
                    writer.WriteLine("Cached State is : " + ((cachedState.IsChanged()) ? "changed" : "not changed"));

                var key = GetStorageKey(turnContext);
                var changes = new Dictionary<string, object>
                {
                    { key, cachedState.State },
                };
                if (cachedState != null && cachedState.State != null && cachedState.State.ContainsKey("DialogState"))
                    writer.WriteLine ("Changes are : " + Newtonsoft.Json.JsonConvert.SerializeObject(changes));

                await _storage.WriteAsync(changes, cancellationToken).ConfigureAwait(false);
                cachedState.Hash = CachedBotState.ComputeHash(cachedState.State);
                if (cachedState != null && cachedState.State != null && cachedState.State.ContainsKey("DialogState"))
                    writer.WriteLine("Hash is " + cachedState.Hash);
                return;
            }
            if (cachedState != null && cachedState.State != null && cachedState.State.ContainsKey("DialogState"))
                writer.WriteLine("=====================END OF DATA SAVE INFO================");
        }
    }

` In the output below, we can see the Bot state with 'eventCounter:17' is being loaded after bot state 'eventCounter: 19' has been written to the storage layer.

=====================================START OF DATA SAVE INFO==================== Activity = message and message = mailto:abc@test.com Cached State is : {"State":{"DialogState":{"dialogStack":[{"id":"MyBotApp","state":{"action":"MAIN_MENU","eventCounter":19,"_adaptive":{"actions":[{"dialogId" .... Cached State Change Status is : changed Cached State is : changed Changes are : {"slack/conversations/Z890LNRSMT":{"DialogState":{"dialogStack":[{"id":"MyBotApp","state":{"action":"MAIN_MENU","eventCounter":19,"_adaptive":{"actions":[{"dialogId": ... Hash is {"DialogState":{"dialogStack":[{"id":"MyBotApp","state":{"action":"MAIN_MENU","eventCounter":19,"_adaptive":{"actions":[{"dialogId": ... =====================================START OF DATA SAVE INFO======================== Activity = message and message = mailto:abc@test.com Cached State is : {"State":{"DialogState":{"dialogStack":[{"id":"MyBotApp","state":{"action":"MAIN_MENU","eventCounter":19,"_adaptive":{"actions":[{"dialogId": .... =====================================END OF DATA SAVE INFO============================== =====================================START OF DATA SAVE INFO============================ Activity = event and message = Cached State is : {"State":{"DialogState":{"dialogStack":[{"id":"MyBotApp","state":{"action":"MAIN_MENU","eventCounter":17,"_adaptive":{"actions":[{"dialogId": ... Cached State is : changed Changes are : {"slack/conversations/Z890LNRSMT":{"DialogState":{"dialogStack":[{"id":"MyBotApp","state":{"action":"MAIN_MENU","eventCounter":17,"_adaptive":{"actions":[{"dialogId": .... Hash is {"DialogState":{"dialogStack":[{"id":"MyBotApp","state":{"action":"MAIN_MENU","eventCounter":17,"_adaptive":{"actions":[{"dialogId": .... =====================================START OF DATA SAVE INFO============================= Activity = event and message = Cached State is : {"State":{"DialogState":{"dialogStack":[{"id":"MyBotApp","state":{"action":"MAIN_MENU","eventCounter":17,"_adaptive":{"actions":[{"dialogId": ... =====================================END OF DATA SAVE INFO===============================

Every event is always reading the cached state of ConverstationState from it's TurnContext.TurnState. Should we not have a SetCachedState in BotState.cs along with the existing GetCachedState.cs. GetCachedState should read from the memory instead of TurnContext's TurnState. When the bot responds to an event, it should compare the 'EventCounter' parameter of the ConverstationState in the TurnContext.TurnState and in memory cache and load the latest.

Please let us know how to solve this issue. When trying to debug, asynchronous threads run causes the debugging point to shift from one thread to another.

We are new to the bot code implementation and this level of asynchronous programming

Thanks

[OEvgeny]

I think the adapter needs updates as I see some other issues with it: https://github.com/BotBuilderCommunity/botbuilder-community-dotnet/issues/547 and the https://github.com/BotBuilderCommunity/botbuilder-community-dotnet/issues/535 seems related

Looks like the adapter doesn't function properly, probably due to Slack API updates

[CNKrit]

Thanks @OEvgeny.

The adapter's ProcessAsync method is getting called when the message is posted to the slack or the webex by the user as well as the bot. When the bot posts multiple messages for a query, the ProcessAsync method gets called that many times..

For ex: Bot : Waiting to log you in.. Bot : You are successfully logged in. Bot : What would you like to do Bot : 1. Access XYZ service

2. Access ABC service Bot : Please enter the option number

In the case above, bot posts 5 messages and Process Async gets called 5 times.

When I try to return just return an empty message in the Adapter's ProcessAsync without invoking the bot's OnTurnAsync method inside ProcessAsync whenever it is invoked for a message posted by the bot, I don't have any issues. But, I am not sure if there could be any issues in production down the line.

Shouldn't the bot be resilient in handling its state irrespective of number of events/messages etc triggered?

Thanks,

[OEvgeny]

Shouldn't the bot be resilient in handling its state irrespective of number of events/messages etc triggered?

It should. And I believe the issue mentioned is the adapter issue, not Composer issue. If you're able to reproduce the issue with Composer only, please contact us.

Looks like botbuilder-community-dotnet haven't receive updates for a while, so there is a high chance something got changed with the Slack API preventing the adapter from working correctly

[OEvgeny]

Closing due to inactivity. Feel free to reopen