SwiftPackageIndex / SwiftPackageIndex-Server

The Swift Package Index is the place to find Swift packages!
https://swiftpackageindex.com
Apache License 2.0
552 stars 44 forks source link

Partially fulfilled futures #29

Closed finestructure closed 4 years ago

finestructure commented 4 years ago

I've posted this as a question in the Vapor Discord but I wanted to record this here as well, both for tracking and as a call for help, in case someone is coming across this issue here :)

I’m pasting the message I posted on Discord at the end but since it generalises away some of the specifics I wanted to mention these here as well.

To reproduce the issue, check out revision cfd91685a1e641f3d414502ce3efbad426191b5c and run test AnalyzserTests.test_basic_analysis. It should fail around ~75% of the time with errors like the following:

/Users/sas/Projects/SPI-Server/Tests/AppTests/AnalyzerTests.swift:76: error: -[AppTests.AnalyzerTests test_basic_analysis] : XCTAssertEqual failed: ("[]") is not equal to ("[Optional("foo-2"), Optional("foo-2")]")
/Users/sas/Projects/SPI-Server/Tests/AppTests/AnalyzerTests.swift:77: error: -[AppTests.AnalyzerTests test_basic_analysis] : XCTAssertEqual failed: ("[]") is not equal to ("[Optional("2.0"), Optional("2.1")]")
Test Case '-[AppTests.AnalyzerTests test_basic_analysis]' failed (0.314 seconds).

i.e. the version updates for the second package are not flushed out to the db. The issue seems to be nested futures. I’ve tried to solve this in various ways (see the Discord message below) but in the end the only way to work around it was to introduce an explicit wait for the updates (revision 2098f12297eef3411fa825a65941b4637bea4959):

    let fulfilledUpdates = try updates.wait()
    let setStatus = fulfilledUpdates.map { (pkg, updates) -> EventLoopFuture<[Void]> in
        EventLoopFuture.whenAllComplete(updates, on: application.db.eventLoop)
            .flatMapEach(on: application.db.eventLoop) { result -> EventLoopFuture<Void> in
                switch result {
                    case .success:
                        pkg.status = .ok
                    case .failure(let error):
                        application.logger.error("Analysis error: \(error.localizedDescription)")
                        pkg.status = .analysisFailed
                }
                return pkg.save(on: application.db)
        }
    }.flatten(on: application.db.eventLoop)

Here’s the Discord post, for reference:

I've gotten myself into a bit of a bind with nested Futures in that I can't quite figure out how to ensure they all complete by the time a wait returns. (The wait is required for it to be run from a Command - or a test.)

At the start, I'm pulling a set of items from a table, yielding

let items: Future<[Item]> = ... fetch ...

(just going to call EventLoopFuture Future for brevity).

I then do some processing which yields a set up db saves per item, such that I'm left with

let updates: Future<[(Item, [Future<Void>])]> = ... update ...

i.e. a set of pairs of one Item with N Future<Void>s for the saves. If I stop here and

try updates.transform(to: ()).wait()

the saves flush out reliably - but that's just luck, right? The transform deals with the outermost future only and the inner ones just happen to be done before. I've run a test for this many, many times and it never failed.

As soon as I now stack on futher steps, even as simple as doing nothing and even completely disregarding the new status:

let status: Future<[Void]> = updates.flatMapEach(on: application.db.eventLoop) { _ in
    application.db.eventLoop.makeSucceededFuture(())
}
try updates.transform(to: ()).wait()  // NB: still just looking at updates

the cracks are beginning to show and some updates don't flush out to the db. (Test now fails ~75% of the time.) I've taken a few stabs at unnesting the inner futures but the result is the same:

let unnested: Future<[Void]> = updates
    .flatMapEach(on: application.db.eventLoop) { (item, updates) -> Future<Void> in
        updates.flatten(on: application.db.eventLoop)
}
try unnested.transform(to: ()).wait()

or

let unnested = updates.flatMap { (r: [(Item, [Future<Void>])]) -> Future<Void> in
    let s = r.map { (item, updates) in
        updates.flatten(on: application.db.eventLoop)
    }
    return s.flatten(on: application.db.eventLoop)
}

and Future<Void>.andAllComplete(...) instead of flatten but the result is the same: often, some of the inner futures do not complete by the time the wait returns.

Where am I going wrong? How can I reliably unnest the futures such that every update has flushed when the final wait returns?

finestructure commented 4 years ago

Interesting observation: The new assert added here: c2fbf2d8c62642d3fb626c7a7b5daa4df649acb6

XCTAssertEqual(try Version.query(on: app.db).count().wait(), 4)

failed 4 out of 10 runs when run via make test in VS Code's terminal.

It didn't fail a single time over more than 20 runs in iTerm and another 20+ runs in Terminal.

What's notable is that Terminal and iTerm are almost twice as fast logging the test output (which is considerable) - they take 9-11s vs 16-20s for VS Code's terminal.

I'm not sure why this is happening and what it means but I don't think it's a coincidence.

PS: This also isn't failing in Xcode, over many more runs than 20.

daveverwer commented 4 years ago

Timing issues 😬 At least it's not failing in Xcode, and Terminal.