_printChanges() introduces non-obvious nuances to tests

[bradleyrzeller]

Hey community! I have been learning TCA over the past few weeks and just ran into a gotcha that I wanted to discuss here. Maybe it's not a gotcha after all and it would be more obvious to me once I get more comfortable with the architecture 🤷‍♂️.

My test suite is currently 5 tests; super small. Each one is fully exhaustive and exhaustive mode is on. I'm providing a mock imp for each dependency used and there is no time-based asynchrony at play. The tests pass on my machine and there's no indication of flakiness or instability.

However, CI tells a different story. No rhyme or reason for which test fails or how many fail etc. The failure is this:

An effect returned for this action is still running. It must complete before the end of the test...

(I then found I could repro it on my machine by repeating the test suite 100 times. I'd get a handful of failures each time.)

This is impossible! I've scoured my reducer and every effect is handled and awaited on in my test. I even tried commenting out every effect of my reducer; simply return .none for every action. And still, I'd get a failure saying an effect is still running. What was this effect and who was firing it? This is the conversation I'm having to myself as I was trying to figure this out. I was able to workaround this by swallowing the pending effect with skipInFlightEffects() but I didn't feel comfortable with this as it undermines the test exhaustivity.

So as the title mentions, I'm fairly certain the issue is _printChanges(). It fires an effect to dump all the activity of the system. I haven't read this dump code too closely but it looks like it's non trivial and likely adds some latency variability to tests (exacerbated when run on different hardware like CI).

I discovered the _printChanges debugging tool early in my journey with TCA and use it both in my unit tests and in my top-level reducer in the app. I never stopped to think it could be the cause of such weird behavior.

So anyways - is this a familiar experience for anyone else? Is it a reasonable stumbling block for folks new to TCA?

At a minimum, I think it could be worth mentioning in the _printChanges() documentation. Or, potentially, add it as a reason in the failure message for the in-flight effect failure?

Thoughts? Thanks!

[mbrandonw]

Hi @bradleyrzeller, it is possible that _printChanges is causing these tests failures, though it is strange since it's just a publisher that completes immediately:

swift-composable-architecture/Sources/ComposableArchitecture/Reducer/Reducers/DebugReducer.swift

Lines 101 to 113 in 0a9d1d9

	Deferred<Empty<Action, Never>> {
	queue.async {
	continuation.yield {
	changeTracker.assert {
	printer.printChange(
	receivedAction: action.wrappedValue,
	oldState: oldState.wrappedValue,
	newState: newState.wrappedValue
	)
	}
	}
	}
	return Empty()

Typically I only use _printChanges at the app entry point so that nothing ever prints during tests. In fact, having all of those state changes print during tests seems like it could be very distracting.

One thing you could try is to cook up your own version of _printChanges that doesn't do any printing when in testing. There's the isTesting variable you can check (which is automatically available via IssueReporting), or you can check @Dependency(\.context) if it is .test. If you early out while in testing mode by returning .none it may fix the problem.