FileAlreadyExistsException when worker tries to save scenario .json from S3

[ansoncfit]

15:30:38 2781 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransportNetworkCache - Applying scenario to base network...
15:30:38 2782 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransportNetworkCache - Retrieving scenario stored separately on S3 rather than in the ProfileRequest.
15:30:38 2811 [pool-2-thread-2] ERROR com.conveyal.r5.transit.TransportNetworkCache - Error retrieving scenario 5c15608c32b98e5d92c601f9-0-3147522539 from S3: java.nio.file.FileAlreadyExistsException: cache/graphs/5c15607432b98e5d92c601f6_5c15608c32b98e5d92c601f9-0-3147522539.json
15:30:38 2811 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransportNetworkCache - Loading scenario from disk file.
15:30:38 2811 [pool-2-thread-2] ERROR com.conveyal.r5.transit.TransportNetworkCache - Could not read scenario 5c15608c32b98e5d92c601f9-0-3147522539 from disk: com.fasterxml.jackson.databind.JsonMappingException: No content to map due to end-of-input at [Source: cache/graphs/5c15607432b98e5d92c601f6_5c15608c32b98e5d92c601f9-0-3147522539.json; line: 1, column: 1]
15:30:38 2811 [pool-2-thread-2] WARN com.conveyal.r5.transit.TransportNetworkCache - No scenario provided or loaded. Replacing with empty scenario.
15:30:38 2812 [pool-2-thread-2] INFO com.conveyal.r5.analyst.scenario.Scenario - Applying scenario null
15:30:38 2812 [pool-2-thread-2] WARN com.conveyal.r5.analyst.scenario.Scenario - Scenario does not have feed checksums, not checking to ensure it is applicable to transport network.
15:30:38 2814 [pool-2-thread-2] INFO com.conveyal.r5.analyst.scenario.Scenario - Resolving modifications against TransportNetwork and sanity checking.
15:30:38 2814 [pool-2-thread-2] INFO com.conveyal.r5.analyst.scenario.Scenario - Applying modifications to TransportNetwork.
15:30:38 2815 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransitLayer - Rebuilding transient indices.
15:30:38 2816 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransitLayer - Done rebuilding transient indices.
15:30:38 2816 [pool-2-thread-2] INFO com.conveyal.r5.streets.StreetLayer - Building edge lists from edges...
15:30:38 2832 [pool-2-thread-2] INFO com.conveyal.r5.streets.StreetLayer - Done building edge lists.
15:30:38 2834 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransitLayer - Finding distances from transit stops to street vertices.
15:30:38 2834 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransitLayer - Selectively finding distances for only those stops potentially affected by scenario application.
15:30:38 2838 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransitLayer - Done. Computed distances to street vertices from 0 of 228 transit stops.
15:30:38 2838 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransferFinder - Finding transfers through the street network from 0 stops...
15:30:38 2838 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransferFinder - Done finding transfers. 0 stops are unlinked.
15:30:38 2838 [pool-2-thread-2] INFO com.conveyal.r5.transit.TransportNetworkCache - Done applying scenario. Caching the resulting network.
15:30:38 2840 [pool-2-thread-1] INFO com.conveyal.r5.transit.TransportNetworkCache - Applying scenario to base network...
15:30:38 2840 [pool-2-thread-1] INFO com.conveyal.r5.transit.TransportNetworkCache - Loading scenario from disk file.
15:30:38 2840 [pool-2-thread-1] ERROR com.conveyal.r5.transit.TransportNetworkCache - Could not read scenario 5c15608c32b98e5d92c601f9-0-3147522539 from disk: com.fasterxml.jackson.databind.JsonMappingException: No content to map due to end-of-input at [Source: cache/graphs/5c15607432b98e5d92c601f6_5c15608c32b98e5d92c601f9-0-3147522539.json; line: 1, column: 1]
15:30:38 2840 [pool-2-thread-1] WARN com.conveyal.r5.transit.TransportNetworkCache - No scenario provided or loaded. Replacing with empty scenario.
15:30:38 2841 [pool-2-thread-1] INFO com.conveyal.r5.analyst.scenario.Scenario - Applying scenario null

Note that this error will not occur if a worker has used the scenario for a single-point analysis (and therefore already has the scenario-applied network cached). Completing a regional task with one worker that ran a single-point analysis, and a second worker that was launched subsequently, can lead to striped scenario/non-scenario accessibility results:

[ansoncfit]

Perhaps this is related to the new resolveScenario method not being synchronized?

In the previous release (v4.1.1), scenario application was blocking. For example,

17:18:08 2577 [pool-1-thread-1] INFO com.conveyal.r5.transit.TransportNetworkCache - Applying scenario to base network...
...
17:18:08 2577 [pool-1-thread-1] INFO com.conveyal.r5.transit.TransportNetworkCache - Retrieving scenario stored separately on S3 rather than in the ProfileRequest
17:18:10 4319 [pool-1-thread-1] INFO com.conveyal.r5.transit.TransportNetworkCache - Done applying scenario. Caching the resulting network.
17:18:10 4319 [pool-1-thread-3] INFO com.conveyal.r5.transit.TransportNetworkCache - Reusing cached TransportNetwork for scenario 5c15608c32b98e5d92c601f9-0-3147522539.
17:18:10 4319 [pool-1-thread-4] INFO com.conveyal.r5.transit.TransportNetworkCache - Reusing cached TransportNetwork for scenario 5c15608c32b98e5d92c601f9-0-3147522539.
17:18:10 4319 [pool-1-thread-2] INFO com.conveyal.r5.transit.TransportNetworkCache - Reusing cached TransportNetwork for scenario 5c15608c32b98e5d92c601f9-0-3147522539.

[abyrd]

Just discussed this with @ansoncfit and we found the source of the problem: I had added a line to resolveScenario (current line 444) which used Files.copy() instead of ByteStreams.copy, but didn't remove ByteStreams.copy. So the file was being copied twice. I am putting it back the way it was before - the Files.copy change is probably a good idea but will need to be done in a release that will be fully tested.

[ansoncfit]

🎉 This issue has been resolved in version 4.5.1 🎉

The release is available on GitHub release

Your semantic-release bot 📦🚀