Skip to content
This repository has been archived by the owner on Dec 13, 2018. It is now read-only.

Console logger from DI doesn't produce console output #631

Closed
natemcmaster opened this issue Jun 5, 2017 · 15 comments
Closed

Console logger from DI doesn't produce console output #631

natemcmaster opened this issue Jun 5, 2017 · 15 comments
Labels
Milestone

Comments

@natemcmaster
Copy link
Contributor

Console logger does not produce output when using 2.0.0-preview3-25445.

using System;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;

namespace Sample
{
    public class Program
    {
        public static void Main(string[] args)
        {
            var services = new ServiceCollection()
                .AddLogging(config => config.AddConsole())
                .BuildServiceProvider();

            services.GetRequiredService<ILogger<Program>>()
                .LogCritical("Hello");
        }
    }
}
<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>netcoreapp2.0</TargetFramework>
  </PropertyGroup>
  <ItemGroup>
    <PackageReference Include="Microsoft.Extensions.DependencyInjection" Version="2.0.0-preview3-*" />
    <PackageReference Include="Microsoft.Extensions.Logging.Console" Version="2.0.0-preview3-*" />
  </ItemGroup>
</Project>

cc @pakrym @BrennanConroy

@BrennanConroy
Copy link
Member

After a short investigation, it seems like logging a couple times wont output, but more logs causes the output to be flushed. Looking to see if CoreFX made any changes in the area recently.

@BrennanConroy
Copy link
Member

So this is because we do console logging on a background thread. So if the application exits too fast then the logger doesn't have time to log.

@muratg muratg added this to the 2.1.0 milestone Jun 14, 2017
@muratg
Copy link

muratg commented Jun 14, 2017

We'll investigate further.

@muratg muratg removed this from the 2.1.0 milestone Jun 14, 2017
@pakrym
Copy link
Contributor

pakrym commented Jun 14, 2017

This should be fixed if you dispose service provider before exiting (services as IDisposible)?.Dispose();

@natemcmaster
Copy link
Contributor Author

Yes, disposing flushes the message queue. Could we also add a ProcessExit event to flush the queue, in the event the service provider isn't disposed correctly?

@pakrym
Copy link
Contributor

pakrym commented Jun 15, 2017

Does it work well crossplat?

@natemcmaster
Copy link
Contributor Author

This API is in ns2.0: AppDomain.CurrentDomain.ProcessExit

@muratg
Copy link

muratg commented Sep 15, 2017

Is this still a problem?

@pakrym
Copy link
Contributor

pakrym commented Sep 15, 2017

Depends if we count not disposing logging provider as a valid usage. I it not worth to overcomplicate logger code to fix invalid usage.

@muratg muratg added this to the Backlog milestone Sep 15, 2017
@per-samuelsson
Copy link

per-samuelsson commented Apr 19, 2018

Is this still a problem?

At least it stole some hour or so from me trying to understand why my simple test didn't produce any result, and quite frankly, I was surprised how immature this story seem.

Having a multi-targeting app (net461 and netcoreapp2.0), I just don't see anything running this code (under none of those two workloads):

void Main() {
  var factory = new LoggerFactory().AddConsole(LogLevel.Trace);
  var logger = factory.CreateLogger("Test");
  logger.LogTrace("Hello!");
}

Running with simply dotnet run --framework=net461 (or netcoreapp2.0).

Even logging 100 of those showed nothing (as someone suggested could be an idea).

Not until I yielded the main thread (doing System.Threading.Thread.Sleep(1000); after .LogTrace(...)), those hellos appeared on my console. 😕

Edit: used these references:

<PackageReference Include="Microsoft.Extensions.Logging" Version="2.1.0-preview2-final" />
<PackageReference Include="Microsoft.Extensions.Logging.Console" Version="2.1.0-preview2-final" />

@AceHack
Copy link

AceHack commented Apr 20, 2018

Any update on fixing this? Just tried in mstest, in any short test all the logs are lost and never captured. I have not services to dispose in the unit test, please fix or give me a flush method.

@AceHack
Copy link

AceHack commented Apr 20, 2018

Okay I was able to dispose of the ConsoleLoggerProvider to force a flush in my unit test, wish I could configure this background thread thing off for tests. Also seems like disposing of LoggerFactory should also dispose of any connected loggers but it does not.

@keithn
Copy link

keithn commented Jun 7, 2018

@AceHack I would think for unit testing you could add your own test logging provider, no need to tie in with the console logger.

@pakrym
Copy link
Contributor

pakrym commented Jun 7, 2018

Also seems like disposing of LoggerFactory should also dispose of any connected loggers but it does not.

Are you sure? There is a test that checks exactly that https://github.com/aspnet/Logging/blob/dev/test/Microsoft.Extensions.Logging.Test/LoggerFactoryTest.cs#L46

johnkors added a commit to RetireNet/dotnet-retire that referenced this issue Aug 22, 2018
* Fixes #18,  https://github.com/RetireNet/dotnet-retire/issue/18
* Fixes the issue with loglevel=error not working
* Reference: aspnet/Logging#631
johnkors added a commit to RetireNet/dotnet-retire that referenced this issue Aug 22, 2018
* Fixes #18,  https://github.com/RetireNet/dotnet-retire/issue/18
* Fixes the issue with loglevel=error not working
* Reference: aspnet/Logging#631
@pakrym pakrym added the wontfix label Nov 1, 2018
@pakrym
Copy link
Contributor

pakrym commented Nov 1, 2018

When IDisposable objects are disposed things are working correctly. No plans to improve anything in this area.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

7 participants