Error message is not shown when the bot fails to start

[peterbozso]

Describe the bug

I am testing what happens when you create a bot containing an infinite loop of dialogs calling each other. (See attachment below in the Additional context section.) My testing is successful: the bot fails to start (even though not with the friendliest of error messages, but that's another, less important topic). But I am facing an issue while doing this: the Composer is not able to display the error message the runtime produces on failure. Nothing indicates that the bot failed to start (apart from the 400 error code I get in the Emulator when I try to chat with the bot), everything looks like the bot started just fine. I am only able to make the error popup visible by navigating to another page of the Composer (Settings, Home, etc.) then navigating back to the Design page. (See gif below in the Screenshots section.) But even then, the popup shows up quite randomly, I can't really connect it's behavior to any concrete action I take. I don't know if this has to do with the bot configuration I am trying to test (hence the exported zip file below to fully reproduce the issue) or this is the current behavior in 1.2 for any error coming from the runtime on startup failure.

Version

1.2.1

Browser

• Electron distribution
• Chrome
• Safari
• Firefox
• Edge

OS

• macOS
• Windows
• Ubuntu

To Reproduce

Steps to reproduce the behavior:

1. Open the attached bot.
2. Start the bot.
3. Observe that it seems the bot started correctly. Connect with the Emulator to see that in fact, it did not:

   {
     "error": {
       "code": "ServiceError",
       "message": "request to http://localhost:3979/api/messages failed, reason: connect ECONNREFUSED 127.0.0.1:3979"
     }
   }

4. Navigate to a different page of the Composer (Settings, Home, etc.) then back to the Design page to make the error popup appear.

Expected behavior

The error popup should appear as soon as the bot failed to start and the Composer should not offer to test the bot in the Emulator. Just like it was working in version 1.1.1.

Screenshots

Additional context

Bot

LoopProtectBot_export.zip

Error message

Start bot failed

Unhandled exception. System.NullReferenceException: Object reference not set to an instance of an object. at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.EnsureDependenciesInstalled() at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.GetDependencies()+MoveNext() at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.EnsureDependenciesInstalled() at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.GetDependencies()+MoveNext() at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.EnsureDependenciesInstalled() at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.GetDependencies()+MoveNext() at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.EnsureDependenciesInstalled() at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.GetDependencies()+MoveNext() at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.EnsureDependenciesInstalled() at Microsoft.Bot.Builder.Dialogs.Adaptive.AdaptiveDialog.GetDependencies()+MoveNext() at Microsoft.Bot.Builder.Dialogs.DialogSet.Add(Dialog dialog) at Microsoft.Bot.Builder.Dialogs.DialogManager.set_RootDialog(Dialog value) at Microsoft.Bot.Builder.Dialogs.DialogManager..ctor(Dialog rootDialog, String dialogStateProperty) at Microsoft.BotFramework.Composer.Core.ComposerBot.LoadRootDialogAsync() in C:\Users\peter\AppData\Roaming\BotFrameworkComposer\hostedBots\76270.46833883511\runtime\core\ComposerBot.cs:line 64 at Microsoft.BotFramework.Composer.Core.ComposerBot..ctor(ConversationState conversationState, UserState userState, ResourceExplorer resourceExplorer, BotFrameworkClient skillClient, SkillConversationIdFactoryBase conversationIdFactory, IBotTelemetryClient telemetryClient, String rootDialog, String defaultLocale, Boolean removeRecipientMention) in C:\Users\peter\AppData\Roaming\BotFrameworkComposer\hostedBots\76270.46833883511\runtime\core\ComposerBot.cs:line 43 at Microsoft.BotFramework.Composer.WebAppTemplates.Startup.<>c__DisplayClass13_0.<ConfigureServices>b__5(IServiceProvider s) in C:\Users\peter\AppData\Roaming\BotFrameworkComposer\hostedBots\76270.46833883511\runtime\azurewebapp\Startup.cs:line 194 at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitFactory(FactoryCallSite factoryCallSite, RuntimeResolverContext context) at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument) at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitCache(ServiceCallSite callSite, RuntimeResolverContext context, ServiceProviderEngineScope serviceProviderEngine, RuntimeResolverLock lockType) at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite singletonCallSite, RuntimeResolverContext context) at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument) at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.Resolve(ServiceCallSite callSite, ServiceProviderEngineScope scope) at Microsoft.Extensions.DependencyInjection.ServiceLookup.DynamicServiceProviderEngine.<>c__DisplayClass1_0.<RealizeService>b__0(ServiceProviderEngineScope scope) at Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngine.GetService(Type serviceType, ServiceProviderEngineScope serviceProviderEngineScope) at Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngineScope.GetService(Type serviceType) at Microsoft.Bot.Builder.Integration.AspNet.Core.ApplicationBuilderExtensions.UseNamedPipes(IApplicationBuilder applicationBuilder, String pipeName, String audience) at Microsoft.BotFramework.Composer.WebAppTemplates.Startup.Configure(IApplicationBuilder app, IWebHostEnvironment env) in C:\Users\peter\AppData\Roaming\BotFrameworkComposer\hostedBots\76270.46833883511\runtime\azurewebapp\Startup.cs:line 211 at System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor, Boolean wrapExceptions) at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture) at Microsoft.AspNetCore.Hosting.ConfigureBuilder.Invoke(Object instance, IApplicationBuilder builder) at Microsoft.AspNetCore.Hosting.ConfigureBuilder.<>c__DisplayClass4_0.<Build>b__0(IApplicationBuilder builder) at Microsoft.AspNetCore.Hosting.GenericWebHostBuilder.<>c__DisplayClass13_0.<UseStartup>b__2(IApplicationBuilder app) at Microsoft.ApplicationInsights.AspNetCore.ApplicationInsightsStartupFilter.<>c__DisplayClass2_0.<Configure>b__0(IApplicationBuilder app) at Microsoft.AspNetCore.Mvc.Filters.MiddlewareFilterBuilderStartupFilter.<>c__DisplayClass0_0.<Configure>g__MiddlewareFilterBuilder|0(IApplicationBuilder builder) at Microsoft.AspNetCore.HostFilteringStartupFilter.<>c__DisplayClass0_0.<Configure>b__0(IApplicationBuilder app) at Microsoft.AspNetCore.Hosting.GenericWebHostService.StartAsync(CancellationToken cancellationToken) at Microsoft.Extensions.Hosting.Internal.Host.StartAsync(CancellationToken cancellationToken) at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token) at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token) at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.Run(IHost host) at Microsoft.BotFramework.Composer.WebAppTemplates.Program.Main(String[] args) in C:\Users\peter\AppData\Roaming\BotFrameworkComposer\hostedBots\76270.46833883511\runtime\azurewebapp\Program.cs:line 16

[stevkan]

Hi @peterbozso, I'm going to start at repro'ing this issue. In the mean time, could you provide the error that is generated so I can review and compare?

[stevkan]

@peterbozso, the .zip file you attached appears to be empty. Could you please repost the file?

[peterbozso]

@stevkan I fixed the zip and added the text of the error message in the Additional context section. I also tried with 1.2.1 and this bug is still present. Please also note that sometimes you have to navigate from and back to the Design page multiple times to make the error popup show up.

[stevkan]

I was able to repro the issue getting the same generated error as reported. However, in my testing, despite a 400 error code being returned in Emulator when connecting or sending an activity, the web app/bot doesn't necessarily die with the first, second, third, etc., error. In one instance, it took as long as 8 mins.

All that being said, the Composer error only generates once the web app fails. I can confirm that it only displays after changing views and the UI updates rather than displaying as the error occurs.

@cwhitten, who would be the best person to assign this bug to?

[hcyang]

@cwhitten, please assign some dev to work on it?

[cwhitten]

@luhan2017 can you look into this and route appropriately?

[luhan2017]

@peterbozso We can separate this issue into two parts:

1. Composer should not show Test in Emulator if the bot not started successfully, we had a fix on this recently, and I tried on your bot you will get such error now, will this meet your requirement?
   

2. @feich-ms @Danieladu to confirm, is the exception expected from the sdk perspective? I think we support loading circular reference in dialogs.

[peterbozso]

@luhan2017 I've just tried with a fresh install of 1.2.1, but unfortunately the error message display behavior is still the same. Should I try with a nightly version instead? In which commit was this issue fixed exactly?

Regarding the looping itself, I agree, that's a separate thing from this one and should be tracked separately. I am sorry for not creating another issue for that.

[luhan2017]

@peterbozso it is not in 1.2.1 yet, you can try the nightly build instead, we will release that in 1.3. @feich-ms is help debugging on the object reference to null issue, will update this thread later.

[feich-ms]

After deep investigation, we found there is a minor bug in composer SDK runtime that caused the loop detection failed when loading loop dialogs. The short term fix in composer side is one line code change here #5077. The long term fix should be in SDK side. I created an issue in SDK side microsoft/botbuilder-dotnet#5021 to track this.

@peterbozso sorry for the late response. Before this is fixed in our side, you can take below work-around stpes:

1. Eject your runtime. See below screenshot to get a copy of your runtime
   
2. You will find a runtime folder generated in your bot root folder. Go into the folder and open the file ComposerBot.cs in Core subfolder. Change line 69 (var rootDialog = resourceExplorer.LoadType<AdaptiveDialog>(rootFile);) with var rootDialog = resourceExplorer.LoadType<Dialog>(rootFile);. Build the runtime project.
3. Go back to composer to start bot, you will see no exceptions and the bot can work as exptected.

Thanks,
Fei

[peterbozso]

This is great! Thank you @luhan2017 and @feich-ms for your prompt responses and quick help! It is very much appreciated.