data-api-builder icon indicating copy to clipboard operation
data-api-builder copied to clipboard

🥕[Bug]: Remove/Fix uninformative INFO logs/messages

Open JerryNixon opened this issue 2 years ago • 1 comments

What happened?

Standard dab start results in the following:

  1. Information: Microsoft.DataApiBuilder 0.9.5-rc+73a02dcd3b85a73ac36a5675432a45b7a3cc4a7d
  2. Information: Config not provided. Trying to get default config based on DAB_ENVIRONMENT...
  3. Information: Environment variable DAB_ENVIRONMENT is (null)
  4. Loading config file from dab-config.json.
  5. Information: Loaded config file: dab-config.json
  6. Information: Setting default minimum LogLevel: Debug for Development mode.
  7. Starting the runtime engine...
  8. Loading config file from dab-config.json.
  9. info: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[63]
  10. User profile is available. Using 'C:\Users\jerry\AppData\Local\ASP.NET\DataProtection-Keys' as key repository and Windows DPAPI to encrypt keys at rest.
  11. ...entities...
  12. info: Azure.DataApiBuilder.Service.Startup[0] Successfully completed runtime initialization.
  13. info: Microsoft.Hosting.Lifetime[14] Now listening on: http://localhost:5000
  14. info: Microsoft.Hosting.Lifetime[14] Now listening on: https://localhost:5001
  15. info: Microsoft.Hosting.Lifetime[0] Application started. Press Ctrl+C to shut down.
  16. info: Microsoft.Hosting.Lifetime[0] Hosting environment: Production
  17. info: Microsoft.Hosting.Lifetime[0] Content root path: C:\Temp\dab

First, there are three types of console output here. Which is confusing.

  1. Information: ...
  2. Free text...
  3. info: ...

Can we ensure our output consistently uses logging and emits the same output? Probably info:

Second, many lines convey nothing to the user. It is not info at all! These are FOR the developer.

Line 2 Information: Config not provided. Trying to get default config based on DAB_ENVIRONMENT...

This comment should communicate what the correct environment variable to use is. We already do this with DAB-ENVIRONMENT. A message like this:

  1. INFO: Environment variable DAB_CONFIG is (null), using argument -c/--config instead.
  2. INFO: Argument -c/--config is (null), using default "dab-config.json" instead.

Line 3 Information: Environment variable DAB_ENVIRONMENT is (null)

This output implies an error when there is none. (I realize it is INFO). It implies that a value that was expected is (null) and could be a problem when it is not. We can correct this with the following new message

  1. INFO: Environment variable DAB_ENVIRONMENT is (null), using value in config file instead.

Line 4 Loading config file from dab-config.json.

This should be an INFO log. This line tells the file name but not the parent: reference #1791

Line 5 Information: Loaded config file: dab-config.json

Remove this line. Move to Debug. Ideally, just remove it.

⚠️ This post-event is not useful in any way other than to debug.

Line 6 Information: Setting default minimum LogLevel: Debug for Development mode.

This line is written in such a way that could be misunderstood.

  1. INFO: Setting LogLevel to Debug because Runtime Mode is set to Development.
  2. INFO: Setting LogLevel to Information because Runtime Mode is set Production.

Line 7 Starting the runtime engine...

This is another line that should be an INFO log. Otherwise OKAY

  1. INFO: Starting Data API builder runtime engine

Line 8 Loading config file from dab-config.json.

Remove this line!

⚠️ This line is an error. This has already occurred. #1792

Line 9 info: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[63]

Remove this line. Move to Debug. Ideally, just remove it.

⚠️ This cryptic event is not useful in any way other than to debug.

Line 10 User profile is available. Using 'C:\Users\jerry\AppData\Local\ASP.NET\DataProtection-Keys' as key repository and Windows DPAPI to encrypt keys at rest.

Remove this line. Move to Debug. Ideally, just remove it.

⚠️ This cryptic event is not useful in any way other than to debug.

Line 12 info: Azure.DataApiBuilder.Service.Startup[0] Successfully completed runtime initialization.

Remove this line. Move to Debug. Ideally, just remove it.

⚠️ This post-event is not useful in any way other than to debug.

Line 16 info: Microsoft.Hosting.Lifetime[0] Hosting environment: Production

Remove this line. Move to Debug. Ideally, just remove it.

⚠️ This useless event is not useful in any way other than MAYBE to debug.

Line 17 info: Microsoft.Hosting.Lifetime[0] Content root path: C:\Temp\dab

Remove this line. Move to Debug. Ideally, just remove it.

⚠️ This useless event is not useful in any way other than MAYBE to debug.

If you want to leave line 17 in, it should be the FIRST log in this list, not the last.

Version

Microsoft.DataApiBuilder 0.9.5-rc+73a02dcd3b85a73ac36a5675432a45b7a3cc4a7d

What database are you using?

Azure SQL

What hosting model are you using?

Local (including CLI)

Which API approach are you accessing DAB through?

REST, GraphQL

Relevant log output

No response

Code of Conduct

  • [X] I agree to follow this project's Code of Conduct

JerryNixon avatar Oct 10 '23 01:10 JerryNixon

Some extra context:

The default settings file AppSettings.json and its contents are generated automatically when creating an ASP.NET project. The files contents result in seeing the logging events with source:

  • Microsoft
  • Microsoft.Hosting.Lifetime
{
  "Logging": {
    "LogLevel": {
      "Default": "Error",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  },
  "AllowedHosts": "*"
}

removing the following lines results in relatively less verbose logs:

      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"

image

seantleonard avatar Oct 12 '23 19:10 seantleonard