Timer effect still running

[johankool]

With the release of TCA version 0.33.1 my tests started failing with this error:

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

To fix, inspect any effects the reducer returns for this action and ensure that all of them complete by the end of the test. There are a few reasons why an effect may not have completed:

• If an effect uses a scheduler (via "receive(on:)", "delay", "debounce", etc.), make sure that you wait enough time for the scheduler to perform the effect. If you are using a test scheduler, advance the scheduler so that the effects may complete, or consider using an immediate scheduler to immediately perform the effect instead.

• If you are returning a long-living effect (timers, notifications, subjects, etc.), then make sure those effects are torn down by marking the effect ".cancellable" and returning a corresponding cancellation effect ("Effect.cancel") from another action, or, if your effect is driven by a Combine subject, send it a completion.

That this could happen was pointed out in the release notes, but I had a hard time figuring out what I did wrong.

It seemed to me that I was making all effects ".cancellable" as per the last point in the error message.

struct TimerId: Hashable {}

…

let startTimerEffect = Effect.timer(
    id: TimerId(),
    every: 1,
    tolerance: .zero,
    on: environment.mainQueue
  )
  .map { _ in TimeLimitAction.timerTicked }
  .map(MainAction.timeLimit)
  .cancellable(id: TimerId(), cancelInFlight: true) // << Don't do this! Removing this line fixed it.

return .merge([startTimerEffect, …])

It turns out the timer effect uses its id to be cancellable, but if you then make it cancellable again and reuse the same id, it doesn't get cancelled at all.

I don't think this is an issue with TCA, though perhaps the wording can be a bit confusing as it talks about timer effects and making them ".cancellable", whereas you shouldn't. I figured mentioning it here in case anybody else runs into this too.

Another potentially useful improvement would be if the id of the effect that still runs is mentioned in the message. This action merged a couple of effects, so it would be great to know which one was the culprit.

[stephencelis]

@johankool Can you share a snippet of the test in question and explain what the expectation was? E.g. was your test sending later actions that should have cancelled the effect but the effect was still not cancelled?

The hope with the change was that cancellation should be more reliable, and a consequence of that change was Effect.timer would no longer drop emissions in tests when emissions were to be expected. But I'm a little surprised that merely omitting the nested cancellable call would change things for you.

I mainly want to figure out if this behavior is a bug or not, so if you have time to isolate the behavior in a test, that would be super helpful!

[johankool]

@stephencelis I have created a small version of my code that shows the issue. MainFeature.zip

[shawnkoh]

I'm experiencing the same issues since updating, while using a variant of your _presents and _pullback function.

public extension Reducer {
    func _presents<LocalState, LocalAction, LocalEnvironment, StatePath, ActionPath>(
        _ localReducer: Reducer<LocalState, LocalAction, LocalEnvironment>,
        cancelEffectsOnDismiss: Bool,
        state toLocalState: StatePath,
        action toLocalAction: ActionPath,
        environment toLocalEnvironment: @escaping (Environment) -> LocalEnvironment
    ) -> Self where
        StatePath: Path, StatePath.Root == State, StatePath.Value == LocalState,
        ActionPath: Path, ActionPath.Root == Action, ActionPath.Value == LocalAction
    {
        let id = UUID()
        return Self { state, action, environment in
            let hadLocalState = toLocalState.extract(from: state) != nil
            let localEffects = localReducer
                ._pullback(
                    state: toLocalState,
                    action: toLocalAction,
                    environment: toLocalEnvironment,
                    breakpointOnNil: false
                )
                .run(&state, action, environment)
                .cancellable(id: id)
            let globalEffects = self.run(&state, action, environment)
            let hasLocalState = toLocalState.extract(from: state) != nil
            return .merge(
                localEffects,
                globalEffects,
                cancelEffectsOnDismiss && hadLocalState && !hasLocalState ? .cancel(id: id) : .none
            )
        }
    }

    func _pullback<GlobalState, GlobalAction, GlobalEnvironment, StatePath, ActionPath>(
        state toLocalState: StatePath,
        action toLocalAction: ActionPath,
        environment toLocalEnvironment: @escaping (GlobalEnvironment) -> Environment,
        breakpointOnNil: Bool = true,
        file: StaticString = #file,
        line: UInt = #line
    ) -> Reducer<GlobalState, GlobalAction, GlobalEnvironment>
        where
        StatePath: Path, StatePath.Root == GlobalState, StatePath.Value == State,
        ActionPath: Path, ActionPath.Root == GlobalAction, ActionPath.Value == Action
    {
        .init { globalState, globalAction, globalEnvironment in

            guard let localAction = toLocalAction.extract(from: globalAction) else {
                return .none
            }

            guard var localState = toLocalState.extract(from: globalState) else {
                #if DEBUG
                    if breakpointOnNil {
                        fputs(
                            """
                            ---
                            Warning: Reducer._pullback@\(file):\(line)
                            "\(globalAction)" was received by an optional reducer when its state was \
                            "nil". This can happen for a few reasons:
                            * The optional reducer was combined with or run from another reducer that set \
                            "\(State.self)" to "nil" before the optional reducer ran. Combine or run optional \
                            reducers before reducers that can set their state to "nil". This ensures that \
                            optional reducers can handle their actions while their state is still non-"nil".
                            * An active effect emitted this action while state was "nil". Make sure that effects
                            for this optional reducer are canceled when optional state is set to "nil".
                            * This action was sent to the store while state was "nil". Make sure that actions \
                            for this reducer can only be sent to a view store when state is non-"nil". In \
                            SwiftUI applications, use "IfLetStore".
                            ---
                            """,
                            stderr
                        )
                        raise(SIGTRAP)
                    }
                #endif
                return .none
            }

            let effect =
                self.run(&localState, localAction, toLocalEnvironment(globalEnvironment))
                    .map { localAction -> GlobalAction in
                        var globalAction = globalAction
                        toLocalAction.set(into: &globalAction, localAction)
                        return globalAction
                    }
            toLocalState.set(into: &globalState, localState)
            return effect
        }
    }
}

[iampatbrown]

This is essentially what is happening

func testDoubleCancelInFlight() {
  var result: Int?

  _ = Just(42)
    .eraseToEffect()
    .cancellable(id: "id", cancelInFlight: true)
    .cancellable(id: "id", cancelInFlight: true)
    .sink { result = $0 }

  XCTAssertNil(result)
  //  XCTAssertEqual(result, 42) <- previous implementation
}

Removing cancelInFlight: true from the second cancellable would also get @johankool's tests passing.

The previous implementation experienced the same behaviour with 3+ nested cancellables sharing the same id.

Not exactly sure how to approach this. Could potentially create a warning when an id used by a timer is also passed to .cancellable(id:).

I've tried a few different implementations but would normally be able to write a test with undesirable behaviour. The above example is similar to the below:

func testSharedIdCancelInFlight() {
  let subject = PassthroughSubject<Int, Never>()

  let effect1 = Effect(subject)
    .cancellable(id: "id", cancelInFlight: true)

  let effect2 = effect1
    .cancellable(id: "id", cancelInFlight: true)
  
  var expectedOutput: [Int] = []
  effect1
    .sink { expectedOutput.append($0) }
    .store(in: &self.cancellables)
  effect2
    .sink { expectedOutput.append($0) }
    .store(in: &self.cancellables)
  
  subject.send(1)
  XCTAssertNoDifference(expectedOutput, [])
  // XCTAssertNoDifference(expectedOutput, [1]) <- previous implementation
}