aspnet / Hosting

[Archived] Code for hosting and starting up an ASP.NET Core application. Project moved to https://github.com/aspnet/Extensions and https://github.com/aspnet/AspNetCore
Apache License 2.0
553 stars 312 forks source link

dotnet myAspNetCoreApp.dll fails with no error message #1500

Closed mkArtakMSFT closed 5 years ago

mkArtakMSFT commented 6 years ago

From @LeslieMurphy on July 20, 2018 18:22

Is this a Bug or Feature request?:

Bug

Steps to reproduce (preferably a link to a GitHub repo with a repro project):

I deployed an ASP.NET Core 2.0 app (using EF) to a user's desktop for testing, using Folder deploy to create a framework dependent set of files.

Edited the appsettings.json to change our DB connection string. I mistakenly placed in code like this:

"ConnectionStrings": { "DefaultConnection": "Server=(.\SQLEXPRESS;Database=xxx;Trusted_Connection=True;MultipleActiveResultSets=true", },

The use of a single backslash in the default connection string caused asp.net core to fail to start up and not issue any error messages. use of two slashes \ \SQLEXPRESS allowed the app to startup just fine

I was using dotnet myApp.dll from the commandline

No log files were generated

Description of the problem:

Invalid entry in appsettings.json causes dotnet command to fail without any error message

Version of Microsoft.AspNetCore.Mvc or Microsoft.AspNetCore.App or Microsoft.AspNetCore.All:

Microsoft.AspNetCore.All 2.0.0 Microsoft.EntityFrameworkCore.Toolsl 2.0.0

Copied from original issue: aspnet/Mvc#8122

mkArtakMSFT commented 6 years ago

From @Eilon on July 20, 2018 18:36

Hi @LeslieMurphy , can you show what the Program.cs and Startup.cs look like? Then we can try to reproduce this and get to the bottom of it. Thanks!

mkArtakMSFT commented 6 years ago

From @LeslieMurphy on July 20, 2018 18:44

Sure, thanks!

Program.cs

using System;
using Microsoft.AspNetCore;
using Microsoft.AspNetCore.Hosting;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using HCM_Xpert.Data;
using Microsoft.AspNetCore.Identity;
using HCM_Xpert.Models;
using NLog.Web;

namespace HCM_Xpert
{
    public class Program
    {

        public static void Main(string[] args)
        {
            // NLog: setup the logger first to catch all errors
            var logger = NLogBuilder.ConfigureNLog("nlog.config").GetCurrentClassLogger();
            try
            {
                var host = BuildWebHost(args);
                using (var scope = host.Services.CreateScope())
                {
                    var services = scope.ServiceProvider;
                    try
                    {
                        var appDBcontext = services.GetRequiredService<ApplicationDbContext>();
                        DbInitializer.Initialize(appDBcontext, services.GetRequiredService<UserManager<ApplicationUser>>());
                    }
                    catch (Exception ex)
                    {
                       logger.Error(ex, "An error occurred while seeding the database.");
                    }
                }
                host.Run();
                logger.Debug("Host stated");
            }catch (Exception e)
            {
                logger.Error(e, "Startup failed with fatal error: " + e.Message);
            }
        }

        public static IWebHost BuildWebHost(string[] args) =>
            WebHost.CreateDefaultBuilder(args)
                .UseStartup<Startup>()
             .ConfigureAppConfiguration((builderContext, config) =>
             {
                 IHostingEnvironment env = builderContext.HostingEnvironment;

                 config.AddJsonFile("appsettings.json", optional: false, reloadOnChange: true)
                     .AddJsonFile($"appsettings.{env.EnvironmentName}.json", optional: true, reloadOnChange: true);
             })
               .UseNLog()
                .Build();
    }
}

Startup.cs

using System;
using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Identity;
using Microsoft.EntityFrameworkCore;
using Microsoft.AspNetCore.Hosting;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using HCM_Xpert.Data;
using HCM_Xpert.Models;
using HCM_Xpert.Services;
using Newtonsoft.Json.Serialization;

namespace HCM_Xpert
{
    public class Startup
    {
        public Startup(IConfiguration configuration)
        {
            Configuration = configuration;
        }

        public IConfiguration Configuration { get; }

        // This method gets called by the runtime. Use this method to add services to the container.
        public void ConfigureServices(IServiceCollection services)
        {
            //Configure Email sender
            services.Configure<EmailSettings>(Configuration.GetSection("EmailSettings"));
            services.AddDbContext<ApplicationDbContext>(options =>
                options.UseSqlServer(Configuration.GetConnectionString("DefaultConnection")));

            services.AddIdentity<ApplicationUser, IdentityRole>()
                .AddEntityFrameworkStores<ApplicationDbContext>()
                .AddDefaultTokenProviders();

            // Add application services.
            services.AddTransient<IEmailSender, EmailSender>();
            services.AddTransient<IProjectActivityLogger, ProjectActivityLogger>();
            services.AddTransient<IProjectDBManager,ProjectMSSDBManager>();
            services.AddTransient<IHCMEngineServices, HCMEngineServices>();
            services.AddMvc().AddJsonOptions(options => options.SerializerSettings.ContractResolver = new DefaultContractResolver());
            // Adds a default in-memory implementation of IDistributedCache.
            services.AddDistributedMemoryCache();

            services.AddSession(options =>
            {
                options.IdleTimeout = TimeSpan.FromMinutes(20);
                options.Cookie.HttpOnly = true;
            });
            services.AddAuthentication().Services.ConfigureApplicationCookie(options =>
            {
            options.SlidingExpiration = true;
            options.ExpireTimeSpan = TimeSpan.FromMinutes(20);

            });

        }

        // This method gets called by the runtime. Use this method to configure the HTTP request pipeline.
        public void Configure(IApplicationBuilder app, IHostingEnvironment env)
        {

            if (env.IsDevelopment())
            {
                app.UseDeveloperExceptionPage();
                app.UseBrowserLink();
                app.UseDatabaseErrorPage();
            }
            else
            {
                app.UseExceptionHandler("/Home/Error");
            }

            app.UseSession();

            app.UseStaticFiles();

            app.UseAuthentication();

            app.UseMvc(routes =>
            {
                routes.MapRoute(
                    name: "default",
                    template: "{controller=Home}/{action=Index}/{id?}");
            });
        }
    }
}

nlog.config

<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
      autoReload="true"
      internalLogLevel="info"
      throwExceptions="true"
      internalLogFile="c:\logs\internal-nlog.txt">

  <extensions>
    <add assembly="NLog.MailKit"/>
</extensions>

    <!-- async="true" causes all logging to take place on a separate thread - that way our main thread does not get blocked as we log.-->
    <!-- might not be necessary when wired to .Net Core, but including it in case it is. -->
    <targets async="true">
       <!-- write all logs to file.  Just to see if we want any of the Microsoft stuff.    -->
    <target xsi:type="File" name="alllogs" fileName="c:\logs\microsoftLogs-${shortdate}.log"
            layout="${longdate}|${event-properties:item=EventId.Id}|${uppercase:${level}}|${logger}|${message} ${exception}" />

    <!-- another file log, only own logs. Uses some ASP.NET core renderers -->
    <target xsi:type="File" name="hcmxpert" fileName="c:\logs\hcmexpertLogs-${shortdate}.log"
            layout="${longdate}|${event-properties:item=EventId.Id}|${uppercase:${level}}|${logger}|${message} ${exception}|url: ${aspnet-request-url}|action: {aspnet-mvc-action}| user: ${aspnet-user-identity:}" />
      <!--   Target to email severe errors to Dev/Support-->
      <target name="supportMail" xsi:type="Mail"
            smtpServer="smtp.gmail.com"
            smtpPort="465"
            enableSsl="true"
            smtpAuthentication="Basic"
            smtpUserName="xxxxx@xxx.com"
            smtpPassword="xxxxxx"
            from="xxx@xxx.com"
            to="xxxxxx@outlook.com"
            subject="xxxx Critical Error"
            body="
                    Time: ${longdate}${newline}
                    EventID: ${event-properties:item=EventId.Id}${newline}
                    url: ${aspnet-request-url}${newline}
                    action: ${aspnet-mvc-action}${newline}
                    user: ${aspnet-user-identity:}
                    Level: ${uppercase:${level}}${newline}
                    Message:${message} ${exception}${newline}             
             "
          />

    <!-- Throw away logs written to this target - like the overly chatty Microsoft ones -->
    <target xsi:type="Null" name="blackhole" />
  </targets>

  <!-- rules to map from logger name to target -->
  <rules>
    <!--All logs, including from Microsoft-->
    <logger name="*" minlevel="Trace" writeTo="alllogs" />

    <!--Skip Microsoft logs and so log only own logs-->
    <logger name="Microsoft.*" minlevel="Trace" writeTo="blackhole" final="true" />
    <logger name="*" minlevel="Trace" writeTo="hcmxpert" />
    <!-- MAIL IS NOT WORKING
    <logger name="*"  minlevel="Error" writeTo="supportMail" />
    -->
  </rules>  

  </nlog>
mkArtakMSFT commented 6 years ago

From @Eilon on July 20, 2018 20:18

Thank you @LeslieMurphy .

@divega / @ajcvickers - do you know if calling EF's options.UseSqlServer(Configuration.GetConnectionString("DefaultConnection"))); with some slightly invalid data for the ConnectionString would cause some fatal exception at startup time?

@LeslieMurphy - perhaps you can also help try to debug this by wrapping that line of code in a try/catch and see if that throws an exception? (E.g. print it out to the console.)

mkArtakMSFT commented 6 years ago

From @LeslieMurphy on July 20, 2018 20:53

Thanks.

Adding that try/catch does not catch anything.

But running in the debugger, I can now see that the issue is related somehow to flushing logger buffers. The “Startup failed with fatal” message does not get logged when I use dotnet xxx.dll:

The message that is generated is actually a very good one – it just never made it to the console, grrrr:

"Could not parse the JSON file. Error on line number '3': '\"ConnectionStrings\": {\r\n\"DefaultConnection\": \"Server=(localdb)\mssqllocaldb;Database=aspnet-HCM_Xpert-116458AF-DBAC-4175-BECB-CAEED9AC23FF;Trusted_Connection=True;MultipleActiveResultSets=true\ file:///\\mssqllocaldb;Database=aspnet-HCM_Xpert-116458AF-DBAC-4175-BECB-CAEED9AC23FF;Trusted_Connection=True;MultipleActiveResultSets=true\ ",'."

try { var host = BuildWebHost(args); using (var scope = host.Services.CreateScope()) { var services = scope.ServiceProvider; try { var appDBcontext = services.GetRequiredService(); DbInitializer.Initialize(appDBcontext, services.GetRequiredService<UserManager>()); } catch (Exception ex) { logger.Error(ex, "An error occurred while seeding the database."); } } host.Run(); logger.Debug("Host stated"); }catch (Exception e) { logger.Error(e, "Startup failed with fatal error: " + e.Message); }

mkArtakMSFT commented 6 years ago

From @Eilon on July 21, 2018 0:2

Ah, interesting. Any chance you can paste the full stack trace for it? That will help me redirect this issue to the right part of the team.

mkArtakMSFT commented 6 years ago

From @Eilon on July 21, 2018 0:2

Tagging @HaoK because this might end up for you to investigate.

mkArtakMSFT commented 6 years ago

Moving this to the aspnet/hosting repo to find out why no exceptions are logged before crashing the app.

Tratcher commented 6 years ago

Dotnet should write uncaught exceptions to the console when the app crashes. The code above catches all exceptions in Main and logs them, but as they said there's not enough time for the logger to flush it's buffer before the app exits. There should be an NLog specific setting about actively flushing data to the log file so it doesn't get lost.

ispadoto commented 6 years ago

I'm facing the same error. JSON file structure is valid, but startup does not reconize...

LeslieMurphy commented 6 years ago

Does it make sense to perhaps always log startup exceptions to the Console, regardless of whether the exception was caught?

On Tue, Jul 24, 2018 at 8:47 AM, Chris Ross notifications@github.com wrote:

Dotnet should write uncaught exceptions to the console when the app crashes. The code above catches all exceptions in Main and logs them, but as they said there's not enough time for the logger to flush it's buffer before the app exits. There should be an NLog specific setting about actively flushing data to the log file so it doesn't get lost.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/aspnet/Hosting/issues/1500#issuecomment-407433664, or mute the thread https://github.com/notifications/unsubscribe-auth/AEQfIBBkmPzpXvREFfoESAY0bKj7GQw5ks5uJzN4gaJpZM4VbUew .

LeslieMurphy commented 6 years ago

That is a different issue, Ibere. Mine was something I messed up in the appsettings.json (did not use a double back-slash) causing a parse error. If your Json is valid but not being read in during startup, you have a different issue.

On Tue, Jul 24, 2018 at 9:49 AM, Ibere Spadoto notifications@github.com wrote:

I'm facing the same error. JSON file structure is valid, but startup does not reconize...

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/aspnet/Hosting/issues/1500#issuecomment-407455796, or mute the thread https://github.com/notifications/unsubscribe-auth/AEQfIF2hSZFb7G534lq0S5HeEpjlhgiCks5uJ0IegaJpZM4VbUew .

Tratcher commented 6 years ago

It already does for most exceptions: https://github.com/aspnet/Hosting/blob/a934c42fe142f2448dbfd31f1780d050b3a2ca87/src/Microsoft.AspNetCore.Hosting/Internal/WebHost.cs#L226

Have you found the stack trace for the exception that wasn't logged to console?

LeslieMurphy commented 6 years ago

Here is the stack trace that occurs when I put an invalid string (a single backslash instead of the double backslash) into the appsettings.json.

Is it something we are doing wrong in our startup logic? I added a Console.WriteLine into my Program.cs for the time being.

line 23 is var host = BuildWebHost(args);

line 52 is WebHost.CreateDefaultBuilder(args)

System.FormatException: Could not parse the JSON file. Error on line number '3': '"ConnectionStrings": {

"DefaultConnection": "Server=(localdb)\mssqllocaldb;Database=aspnet-HCM_Xpert-116458AF-DBAC-4175-BECB-CAEED9AC23FF;Trusted_Connection=True;MultipleActiveResultSets=true",'. ---> Newtonsoft.Json.JsonReaderException: Bad JSON escape sequence: \m. Path 'ConnectionStrings.DefaultConnection', line 3, position 44.

   at Newtonsoft.Json.JsonTextReader.ReadStringIntoBuffer(Char quote)

   at Newtonsoft.Json.JsonTextReader.ParseString(Char quote, ReadType readType)

   at Newtonsoft.Json.JsonTextReader.ParseValue()

   at Newtonsoft.Json.JsonTextReader.Read()

   at Newtonsoft.Json.Linq.JContainer.ReadContentFrom(JsonReader r, JsonLoadSettings settings)

   at Newtonsoft.Json.Linq.JContainer.ReadTokenFrom(JsonReader reader, JsonLoadSettings options)

   at Newtonsoft.Json.Linq.JObject.Load(JsonReader reader, JsonLoadSettings settings)

   at Newtonsoft.Json.Linq.JObject.Load(JsonReader reader)

   at Microsoft.Extensions.Configuration.Json.JsonConfigurationFileParser.Parse(Stream input)

   at Microsoft.Extensions.Configuration.Json.JsonConfigurationProvider.Load(Stream stream)

   --- End of inner exception stack trace ---

   at Microsoft.Extensions.Configuration.FileConfigurationProvider.Load(Boolean reload)

   at Microsoft.Extensions.Configuration.FileConfigurationProvider.Load()

   at Microsoft.Extensions.Configuration.ConfigurationRoot..ctor(IList`1 providers)

   at Microsoft.Extensions.Configuration.ConfigurationBuilder.Build()

   at Microsoft.AspNetCore.Hosting.WebHostBuilder.BuildCommonServices(AggregateException& hostingStartupErrors)

   at Microsoft.AspNetCore.Hosting.WebHostBuilder.Build()

   at HCM_Xpert.Program.BuildWebHost(String[] args) in E:\Providence\Workspaces\HCMXpert\HCM_Xpert\HCM_Xpert\Program.cs:line 52

   at HCM_Xpert.Program.Main(String[] args) in E:\Providence\Workspaces\HCMXpert\HCM_Xpert\HCM_Xpert\Program.cs:line 23
var logger = NLogBuilder.ConfigureNLog("nlog.config").GetCurrentClassLogger();

            try

            {

                var host = BuildWebHost(args);

                using (var scope = host.Services.CreateScope())

                {

                    var services = scope.ServiceProvider;

                    try

                    {

                        var appDBcontext = services.GetRequiredService<ApplicationDbContext>();

                        DbInitializer.Initialize(appDBcontext, services.GetRequiredService<UserManager<ApplicationUser>>());

                    }

                    catch (Exception ex)

                    {

                        logger.Error(ex, "An error occurred while seeding the database.");

                    }

                }

                host.Run();

                logger.Debug("Host started");

            }catch (Exception e)

            {

                Console.WriteLine("excp " + e.ToString());  // Nlog writes to file in c:\log -- write this to console, too

                logger.Fatal(e, "Startup failed with fatal error: " + e.Message);

            }

            finally

            {

                // Ensure to flush and stop internal timers/threads before application-exit(Avoid segmentation fault on Linux)

                 NLog.LogManager.Shutdown();

public static IWebHost BuildWebHost(string[] args) =>

            WebHost.CreateDefaultBuilder(args)

                .UseStartup<Startup>()

             .ConfigureAppConfiguration((builderContext, config) =>

             {

                 IHostingEnvironment env = builderContext.HostingEnvironment;

                 config.AddJsonFile("appsettings.json", optional: false, reloadOnChange: true)

                     .AddJsonFile($"appsettings.{env.EnvironmentName}.json", optional: true, reloadOnChange: true);

             })

               .UseNLog()

                .Build();

    }
Tratcher commented 6 years ago

That error is happening in the Build code path. We don't even try to handle exceptions until the Start/Run code path. Your try/catch in Main is just fine if you want to capture those, otherwise the runtime should write them to std.out or sdt.error when the process crashes.

muratg commented 6 years ago

Just catching up with this bug. @LeslieMurphy, are there still any open questions on your side? Any actual bugs you think we should fix?

LeslieMurphy commented 6 years ago

Thanks for checking in. No open questions.

It's not a bug, but it would be nice if a failed configuration build would always log a message to the console, before generating the exception. Would that fit with your overall philosophy during startup? It's relatively easy to mess up the appsettings, and its quite possible that the application is logging to an external file - where the end user might not immediately know where to look. A console message would immediately alert the user to what is going wrong.

Regards, Les

On Tue, Aug 28, 2018 at 11:45 AM Murat Girgin notifications@github.com wrote:

Just catching up with this bug. @LeslieMurphy https://github.com/LeslieMurphy, are there still any open questions on your side? Any actual bugs you think we should fix?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/aspnet/Hosting/issues/1500#issuecomment-416678127, or mute the thread https://github.com/notifications/unsubscribe-auth/AEQfIKFx3qyRMHpmY6n81hhjqlo_qL36ks5uVYG6gaJpZM4VbUew .

vnextcoder commented 6 years ago

Well in my case, i had some user-secrets stored in user-secrets.json .. that file was still there but just a blank one. So JSON formatter was not able to inject the UserSecrets.json properly hence, dotnet run was failing to start the MVC app..

aspnet-hello commented 5 years ago

We periodically close 'discussion' issues that have not been updated in a long period of time.

We apologize if this causes any inconvenience. We ask that if you are still encountering an issue, please log a new issue with updated information and we will investigate.