apple
Add a testing log handler proposal
Proposal for implementing a testing log handler which is provided by swift-log. For additional context, please see this github issue: https://github.com/apple/swift-log/issues/242
So, I started putting together an example implementation, and in the process I'm refactoring the existing swift-log tests so they don't use LoggingSystem.bootstrapInternal() since multiple calls to LoggingSystem.boostrap() triggers the "Logging.swift:617: Precondition failed: logging system can only be initialized once per process." error.
...and low and behold, the LoggingTest testMultiplex test is failing due to the fact that some extra medatadata (["example": example-value]) is getting injected as a side-effect of another concurrently executing test.
So, whatever solution we come up with needs to be a bit less fragile in the face of concurrent test execution than the current solution. Note that I intend to do minimal changes to the current test solution so we can be assured that a bug in our test logger doesn't get hidden. Additionally, it will allow us to iterate on the test logger implementation provided by this proposal without impacting the other unit tests. Longer term we can see about removing that redundancy, but I'd rather do that as a separate PR.
I'll update this PR with my proposal soon.
PR has been updated with a proposed implementation. I also refactored the tests so they rely on bootstrapInternal() a bit less, although I couldn't completely remove the usage of this since some of the tests are testing the interactions at a "global" level.
Overall, I'd suggest that we minimize the usage of bootstrapInternal() though.
@FranzBusch I have been thinking over your comment over the course of the last week:
I am still not convinced this is the right thing to do in tests here. IMO if developers want to test their logs I don't think they should use bootstrapping of a test log handler but rather they should accept a Logger and we can create a Logger(handler: TestLogerHandler(). This would make this proposal a lot simpler since we don't need containers anymore.
Furthermore, it would push developers into the right pattern which is to accept a Logger at their APIs and potentially fallback to create a Logger if none is passed.
Although I agree with your sentiment (everyone should allow a Logger to be "injected" into their public APIs), I don't think this is a realistic requirement that we should be hoisting on anyone that wants to add some rigor to their logs by testing that the desired log output is achieved.
Therefore, I would rather "embrace the genius of the and" and encourage users of the library to inject in their log handler manually, but still allow bootstrapping to a singular test log handler instance.
So, the way I take your feedback is that we need an easy way to inject the test log handler without requiring a bootstrap. Let me see if I can come up with a good solution to this problem.
@brimworks said: So, the way I take your feedback is that we need an easy way to inject the test log handler without requiring a bootstrap. Let me see if I can come up with a good solution to this problem.
BTW, I changed the test case to use the "easily inject a TestLogHandler instance" way which avoids bootstrapping. Let me know if this addresses your concern.
Thanks!
For anyone else following along, the fate of this proposal is in limbo due to an open question about how to pass loggers around (should we be using task locals?). Based on the outcome of that decision, we may want to take a different tactic for testing (aka use task local logger handlers).
For anyone else following along, the fate of this proposal is in limbo due to an open question about how to pass loggers around (should we be using task locals?). Based on the outcome of that decision, we may want to take a different tactic for testing (aka use task local logger handlers).
That's right but I think we could scope this down and still make progress with the PR. In my opinion, just creating one log handler that is recording all logged messages and allows us to easily assert what is recorded is valuable regardless of how we move forward with the logger passing. I would recommend that we focus on that for now to make this PR easier to move forward.
Unfortunately, it seems that this is not the direction that swift-log wants to go in, so closing this PR.
Ultimately, my goal with this PR has always been to support validating log messages in a context where the Logger could not be "injected". However, it seems that proper usage of the Logger library requires it to be "injectable".
Additionally, I wanted to make sure tests ran in parallel have a lower chance of interfering with each other, and to avoid intercepting all error messages, since tests are often ran in a CI system where you may have to rely on stderr logs to diagnose failures. To that end, I suggested more of a "mockito" approach where you state up-front what log messages you are expecting, and then you check those log messages against that expectation after the expected log messages are emitted. Unfortunately, that approach doesn't mesh well with the swift-testing #expect() macro, since the expectation has to be set in advance.
Anyways, just adding context here in case anyone stumbles upon this PR in the future.