feature: emit GHC events on test start and completion

[edmundnoble]

This PR makes tasty emit events to the event log in the style expected by https://github.com/well-typed/ghc-events-analyze for the purpose of building a time profile of a test suite. I also have a patch which does this more indirectly by shoving the start time of a test into a Result, if that's preferable. One thing that's nice about events is that if the code under test also emits events, that makes for a very interesting time profile.

[Bodigrim]

I know absolutely nothing about event log profiling. @TeofilC could you possibly advise?

@edmundnoble could you please point me to a branch with an "indirect" approach to compare?

[edmundnoble]

This branch allows producing time profiles of test suites without using GHC events. It requires some extra parts to actually use; I used this patch to tasty-json.

[TeofilC]

This sounds like a great idea to me!

I would suggest making it configurable whether to emit these events to the eventlog.

• There's a small performance cost to emitting these events, and that might skew very quick tests.
• Users of tasty might already be using the eventlog and might not want these events.

I wonder as well if this could be implemented as an extension to tasty rather than in the main runner. Though I don't know a lot about tasty internals so I'm not sure if that's possible.

You might also be interested in (if you haven't seen it already) https://github.com/ethercrow/opentelemetry-haskell. This library uses a different eventlog convention, but lets you export to more types of formats (eg, chrome traces, tracy, or opentelemtry)

[edmundnoble]

Oh, I had figured the eventlog convention was agreed on. To me that seems like the biggest issue preventing this from being truly standard.

I'm not sure where exactly to implement this if it's going to live outside of the runner proper. Perhaps as an Ingredient? @Bodigrim

EDIT: I might even put this in the opentelemetry-haskell repo.

[Bodigrim]

Could it be implemented as a newtype wrapper with a custom IsTest instance?

[Bodigrim]

Could it be implemented as a newtype wrapper with a custom IsTest instance?

The biggest downside is that class IsTest does not have access to test names...

This branch allows producing time profiles of test suites without using GHC events. It requires some extra parts to actually use; I used this patch to tasty-json.

This is close in spirit to what, say, tasty-bench does. Except that it does not extend Result with a new field: instead you can encode anything into resultDescription and decode it in a test reporter.

[edmundnoble]

Could it be implemented as a newtype wrapper with a custom IsTest instance? The biggest downside is that class IsTest does not have access to test names...

Not having test names seems to be a non-starter. There's another issue with this PR too; in the spirit of distributed tracing, one would usually like a "span" for not just individual test cases, but also whole test groups. I don't think we can do that with IsTest either... I think frankly the best way to do this might be combinators wrapping testGroup and testName, unfortunately, using withResource to start and end the spans. I was hoping also that I might be able to do this by transforming a TestTree, but the constructors aren't exported.

Perhaps it makes more sense to be content with the other branch. Would you take a PR with it? Or am I breaking too much stuff by adding a field to Result?

[Bodigrim]

I was hoping also that I might be able to do this by transforming a TestTree, but the constructors aren't exported.

They are exposed: https://hackage.haskell.org/package/tasty-1.5/docs/Test-Tasty-Runners.html#t:TestTree

Would you take a PR with it? Or am I breaking too much stuff by adding a field to Result?

I'm not a fan of ad-hoc extending Result; something like #381 would be a better option. But we just released tasty-1.5 and tasty-1.6 is not in the cards for another year or two.

[edmundnoble]

Ok I will probably just write a function over TestTree then, thanks.