Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Custom console logging: is there any way to suppress all vstest console output? #3930

Closed
fluffynuts opened this issue Aug 8, 2022 · 9 comments

Comments

@fluffynuts
Copy link

Description

I'm building a customised console logger (https://www.nuget.org/packages/quackers.testlogger) with a few aims that the built-in console logger doesn't seem to support (easily, if at all)

  • configurable pass/fail/skip markers
  • fully-qualified test names **
  • failure summary at the end of the test run including the thrown error & stack trace **
    • this was actually the main reason I started down this road: scrolling back through thousands of tests to find the one failure
      referenced in the original console output is untenable
  • the ability to toggle coloration
  • some "porcelain" markers to make it easier to consume the output stream with other tools

** These are to support easier diagnostics for the dev reading test output

I notice that even when I only include my own logger (-l quackers) I still seem to get some of the vstest console output, namely:

  • immediate failure information (eg stack trace):
    image

  • skipped tests
    image

  • final summary
    image

So it looks like the console logger is included at minimal verbosity even when not explicitly requested - is there some way to disable it completely?

I also don't seem to get the test discovery events, but I have a feeling that's up to the test framework (in this case, nunit) to call - and it's not catastrophic - just odd.

It would also be really nice if there was an event raised as a test was started, (eg TestStarted) - when there's a long-running test, it would be great to know what is holding up the test session (and one of the original intents of Quackers was to provide this information, but I can't without the starting event).

Steps to reproduce

  • enable another logger

Expected behavior

I expect to see no console logging from the test framework

Actual behavior

I see some of the original console logging bleeding through

Environment

Environment: windows 11, x64
Testing with dotnet test, dotnet version is 6.0.302

@Anton-V-K
Copy link

May be related to #3525

@nohwnd
Copy link
Member

nohwnd commented Jul 8, 2024

This is a new feature and won't be implemented, we are focusing on adding new features to Testing.Platform instead. https://aka.ms/testingplatform

@nohwnd nohwnd closed this as not planned Won't fix, can't repro, duplicate, stale Jul 8, 2024
@fluffynuts
Copy link
Author

fluffynuts commented Jul 9, 2024

@nohwnd I completely disagree that this is a "new feature" - dotnet has had the ability to set whatever loggers I can ask for since the get-go, so if I explicitly tell dotnet to use only one logger, that's what should happen.

I think you've simply read "vstest" in the title and dismissed the issue.

@nohwnd nohwnd reopened this Jul 9, 2024
@nohwnd nohwnd self-assigned this Jul 9, 2024
@nohwnd
Copy link
Member

nohwnd commented Jul 9, 2024

Re-opened will give it another look. Sorry I made you angry.

@fluffynuts
Copy link
Author

fluffynuts commented Jul 10, 2024

@nohwnd thanks for re-opening - I'm not so much angry as frustrated (though often the latter is the precursor to the former, so I understand if it comes across that way).

I've had to write hacks to get around the fact that some console logging leaks out of the test process despite me disabling it. This may sound trivial, but it's because I've written a (imo, easier-to-grok) console outputter which includes colors and timing for tests as well as a summary at the end (overall results, run time and reporting of slow tests).

I'd like to be able to use it without the output-suppression hacks in my runner project (zarro) - and, right now, because the test system is still emitting some outputs, it means that my logger is not 100% useful to anyone not using my runner. Add to this frustration the fact that this issue is nearly 2 years old without any feedback until it was suddenly closed.

I believe that @Anton-V-K is correct: this issue is related to #3525 - which I see you've also closed out, with similar reasoning as above 😢

@nohwnd
Copy link
Member

nohwnd commented Jul 11, 2024

I've investigated it again, and it is not easily achievable, there are console writes all over. The VSTest banner is written very early when we don't even know about loggers, and we always include the console or msbuild logger into the execution.

This would to me be the best implemented as configuration to your logger that would suppress the default logger, but for that I would have to change public api, the registration order, propagate the options to all the places where we write directly to console, and replace them with callbacks, and also move where we write the banner.

I am sorry but at this point this would be a new feature, and I cannot commit to that.

@nohwnd
Copy link
Member

nohwnd commented Jul 11, 2024

I think our new testing platform either already supports this, or will support completely replacing the screen writing, we would be happy to see you there :)

Update: there is no public extension point for this yet, but we internally wrote our default UX as an extension, so it is replaceable.

e.g. https://github.com/microsoft/testfx/blob/main/src/Platform/Microsoft.Testing.Platform/OutputDevice/IPlatformOutputDevice.cs

@fluffynuts
Copy link
Author

Ok, it sounds like a lot of cheese is moving; I'll have to watch this issue because it will affect a lot of stuff I work on. Thanks for the feedback.

@fluffynuts
Copy link
Author

fluffynuts commented Jul 12, 2024

I've investigated it again, and it is not easily achievable, there are console writes all over. The VSTest banner is written very early when we don't even know about loggers, and we always include the console or msbuild logger into the execution.

This would to me be the best implemented as configuration to your logger that would suppress the default logger, but for that I would have to change public api, the registration order, propagate the options to all the places where we write directly to console, and replace them with callbacks, and also move where we write the banner.

I am sorry but at this point this would be a new feature, and I cannot commit to that.

just fyi, the only outputs that are a problem are repeated test results - iirc the default logger still reports errors, even when disabled. I don't mind about banners and such - that's not a deal-breaker. What I mind is seeing double output because my logger is producing a pretty output and the built-in one is also still reporting as before. At the normal verbosity, the logger only reports errors. So even if just that could be looked at, I'd really appreciate it.

I currently suppress this duplicated logging by running through my own gulp-based tasking system (zarro), and telling my logger to prepend all lines with something like ::::: - and then I strip out all lines which don't have this prepended value.

For any other arbitrary person who picks up my logger and perhaps uses dotnet test to run tests, they will see duplicated output. So they can't have the advantages of my logger (icons, colors, summaries, timings, slow test warnings, etc) without also getting a double-up on test results.

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

No branches or pull requests

4 participants