Templates enable EF SQL command logging in development

[DamianEdwards]

Fixes #32977

[DamianEdwards]

/azp run

[azure-pipelines]

Azure Pipelines successfully started running 2 pipeline(s).

[davidfowl]

This feels so bad to do preemptively. We shouldn't do this for templates that don't use EF

[davidfowl]

I don't think this should be in the template

[DamianEdwards]

@davidfowl are you saying you don't think this should be in the templates at all, or that we should remove it from the templates that don't use Entity Framework?

[davidfowl]

I think adding it to templates that use EF is fine.

[ajcvickers]

Would it be useful to add a template/option to use EF Core without needing to also use Identity? //cc @Rick-Anderson @JeremyLikness

@davidfowl Maybe the real problem here is the setting to Warning for all Microsoft logs, which sets the logging for any Microsoft package without any knowledge of what the packages are or what is appropriate to log from them. Can the template more selectively set logging levels for only the things it actually knows about?

[Rick-Anderson]

I want to make sure customers that create a new web or API project have EF logging in debug mode enabled. See this SO thread, 55K + views, all the ridiculous answers to get SQL logging. Luckily I was able to contact the owner and have him change my answer to the correct answer.

[JeremyLikness]

Which templates use EF Core? Is it just when users choose authentication and pick identity server? Or are there templates that will scaffold general data access (not Identity) using EF Core? I thought it was the former. Either way I agree there shouldn't be EF Core settings in templates that don't use EF Core.

[DamianEdwards]

@JeremyLikness yes it's only when the identity options are enabled that EF Core is added to the templates today. The scaffolding system will add EF Core to a project but doesn't currently add the logging configuration. I've created dotnet/Scaffolding#1615 to track that.

I'll update the PR to remove EF Core logging settings if EF Core is not actually referenced.

[ajcvickers]

@DamianEdwards Do we have numbers that show scaffolding commonly used to add EF Core? (In other words, will this really address @Rick-Anderson's concerns?)

[DamianEdwards]

New idea from @davidfowl:

Instead of making everything Microsoft.* Warning, how about we configure just Microsoft.AspNetCore.* and Microsoft.Extensions.* as Warning?

[DamianEdwards]

Just tried this out locally and if we want this change to only apply for development then this is what the logging section of appsettings.Development.json has to contain to get the desired configuration:

  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft": "Information",
      "Microsoft.AspNetCore": "Warning",
      "Microsoft.Extensions": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  }

This is because these settings are merged with those in appsettings.json which explicitly configures "Microsoft": "Warning" so we have to override it.

Alternatively we update both configuration files with the same settings like so:

"Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft.AspNetCore": "Warning",
      "Microsoft.Extensions": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  }

This will potentially result in more logs by default in Production (i.e. anything from Microsoft.* that isn't Microsoft.AspNetCore or Microsoft.Extensions) but I think we're OK with that on a major release.

[DamianEdwards]

FYI here's some example output from an app using auth with the suggested configuration after starting it then navigating to the profile page (already logged in):

❯ dotnet run
Building...
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: https://localhost:7151
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: http://localhost:5057
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\src\GitHub\dotnet\aspnetcore\src\ProjectTemplates\scripts\webapp
info: Microsoft.EntityFrameworkCore.Infrastructure[10403]
      Entity Framework Core 6.0.0-rc.1.21406.1 initialized 'ApplicationDbContext' using provider 'Microsoft.EntityFrameworkCore.Sqlite' with options: None
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (11ms) [Parameters=[@__p_0='?' (Size = 36)], CommandType='Text', CommandTimeout='30']
      SELECT "a"."Id", "a"."AccessFailedCount", "a"."ConcurrencyStamp", "a"."Email", "a"."EmailConfirmed", "a"."LockoutEnabled", "a"."LockoutEnd", "a"."NormalizedEmail", "a"."NormalizedUserName", "a"."PasswordHash", "a"."PhoneNumber", "a"."PhoneNumberConfirmed", "a"."SecurityStamp", "a"."TwoFactorEnabled", "a"."UserName"
      FROM "AspNetUsers" AS "a"
      WHERE "a"."Id" = @__p_0
      LIMIT 1

[davidfowl]

Remove "Microsoft.Extensions": "Warning", and see what happens?

[DamianEdwards]

@davidfowl sorry I already had, so what you're seeing above is the output from both settings files having:

  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft.AspNetCore": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  }

[DamianEdwards]

I guess we can remove the specific config for Microsoft.Hosting.Lifetime too then...

[DamianEdwards]

Confirmed that we can update both settings files with following and get the same output:

  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft.AspNetCore": "Warning"
    }
  }

[davidfowl]

cc @Tratcher