Handle concurrent mirror requests via a resilient queue to avoid inefficient race condition on fs files

[dzikoysk]

Request details

Current implementation of FS storage is focused on mitigating side effects from concurrent put operations, but it's simply inefficient. Related issues:

• Make S3 upload operation more reliable #1985
• FileSystemStorageProvider throws FileAlreadyExistsException during concurrent put operation #2027
• FileSystemStorageProvider throws FileAlreadyExistsException during concurrent put operation #2027
• FileSystemStorageProvider#putFile hangs infinitely #2046
• I still get the FileAlreadyExistsException even with Reposilite 3.5.5. #2047

[ivy-cst]

Nice the FileAlreadyExistsException are fixed with release 3.5.6. But I sill get the NoSuchFileException. So I can still not use the mirror with concurrent requests.

20:05:55.957 INFO | Reposilite 3.5.6 Status
20:05:55.958 INFO |   Active: true
20:05:55.958 INFO |   Uptime: 1s
20:05:55.959 INFO |   Memory usage of process: 27.84M
20:05:55.959 INFO |   Active threads in group: 40
20:05:55.960 INFO |   Recorded failures: 0
20:05:55.960 INFO |   Latest version of Reposilite: 3.5.6
20:05:55.960 INFO | 
20:05:55.960 INFO | For help, type 'help' or '?'
20:08:05.275 ERROR | /central/org/apache/commons/commons-parent/64/commons-parent-64.pom
20:08:05.282 ERROR | java.nio.file.NoSuchFileException: /app/data/repositories/central/org/apache/commons/commons-parent/64/commons-parent-64.pom
20:08:05.284 ERROR |    at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92)
20:08:05.285 ERROR |    at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106)
20:08:05.286 ERROR |    at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111)
20:08:05.286 ERROR |    at java.base/sun.nio.fs.UnixFileSystemProvider.newByteChannel(UnixFileSystemProvider.java:261)
20:08:05.286 ERROR |    at java.base/java.nio.file.Files.newByteChannel(Files.java:379)
20:08:05.287 ERROR |    at java.base/java.nio.file.Files.newByteChannel(Files.java:431)
20:08:05.287 ERROR |    at java.base/java.nio.file.spi.FileSystemProvider.newInputStream(FileSystemProvider.java:420)
20:08:05.287 ERROR |    at java.base/java.nio.file.Files.newInputStream(Files.java:159)
20:08:05.287 ERROR |    at com.reposilite.storage.PathsKt.inputStream$lambda$2(Paths.kt:38)
20:08:05.288 ERROR |    at panda.std.Result.map(Result.java:152)
20:08:05.288 ERROR |    at com.reposilite.storage.PathsKt.inputStream(Paths.kt:38)
20:08:05.288 ERROR |    at com.reposilite.storage.filesystem.FileSystemStorageProvider.getFile$lambda$5(FileSystemStorageProvider.kt:106)
20:08:05.289 ERROR |    at panda.std.Result.flatMap(Result.java:170)
20:08:05.290 ERROR |    at com.reposilite.storage.filesystem.FileSystemStorageProvider.getFile(FileSystemStorageProvider.kt:106)
20:08:05.290 ERROR |    at com.reposilite.maven.MirrorService.storeFile$lambda$2(MirrorService.kt:70)
20:08:05.290 ERROR |    at panda.std.Result.flatMap(Result.java:170)
20:08:05.291 ERROR |    at com.reposilite.maven.MirrorService.storeFile(MirrorService.kt:70)
20:08:05.291 ERROR |    at com.reposilite.maven.MirrorService.access$storeFile(MirrorService.kt:37)
20:08:05.291 ERROR |    at com.reposilite.maven.MirrorService$findRemoteFile$1.invoke$lambda$0(MirrorService.kt:63)
20:08:05.291 ERROR |    at panda.std.Result.flatMap(Result.java:170)
20:08:05.292 ERROR |    at com.reposilite.maven.MirrorService$findRemoteFile$1.invoke(MirrorService.kt:63)
20:08:05.292 ERROR |    at com.reposilite.maven.MirrorService$findRemoteFile$1.invoke(MirrorService.kt:61)
20:08:05.292 ERROR |    at com.reposilite.maven.MirrorService$searchInRemoteRepositories$2.invoke(MirrorService.kt:83)
20:08:05.293 ERROR |    at com.reposilite.maven.MirrorService$searchInRemoteRepositories$2.invoke(MirrorService.kt:83)
20:08:05.293 ERROR |    at kotlin.sequences.TransformingSequence$iterator$1.next(Sequences.kt:210)
20:08:05.293 ERROR |    at com.reposilite.maven.MirrorService.searchInRemoteRepositories(MirrorService.kt:114)
20:08:05.293 ERROR |    at com.reposilite.maven.MirrorService.findRemoteFile(MirrorService.kt:61)
20:08:05.293 ERROR |    at com.reposilite.maven.RepositoryService.findInputStream(RepositoryService.kt:161)
20:08:05.294 ERROR |    at com.reposilite.maven.RepositoryService.findFile$lambda$14(RepositoryService.kt:144)
20:08:05.294 ERROR |    at panda.std.Result.flatMap(Result.java:170)
20:08:05.294 ERROR |    at com.reposilite.maven.RepositoryService.findFile(RepositoryService.kt:144)
20:08:05.295 ERROR |    at com.reposilite.maven.RepositoryService.access$findFile(RepositoryService.kt:50)
20:08:05.295 ERROR |    at com.reposilite.maven.RepositoryService$findFile$1.invoke(RepositoryService.kt:117)
20:08:05.295 ERROR |    at com.reposilite.maven.RepositoryService$findFile$1.invoke(RepositoryService.kt:116)
20:08:05.295 ERROR |    at com.reposilite.maven.RepositoryService.resolve$lambda$10(RepositoryService.kt:134)
20:08:05.296 ERROR |    at panda.std.Result.flatMap(Result.java:170)
20:08:05.296 ERROR |    at com.reposilite.maven.RepositoryService.resolve(RepositoryService.kt:134)
20:08:05.296 ERROR |    at com.reposilite.maven.RepositoryService.findFile(RepositoryService.kt:116)
20:08:05.297 ERROR |    at com.reposilite.maven.MavenFacade.findFile(MavenFacade.kt:55)
20:08:05.297 ERROR |    at com.reposilite.maven.infrastructure.MavenEndpoints$findFile$1$1$1.invoke(MavenEndpoints.kt:65)
20:08:05.297 ERROR |    at com.reposilite.maven.infrastructure.MavenEndpoints$findFile$1$1$1.invoke(MavenEndpoints.kt:63)
20:08:05.297 ERROR |    at com.reposilite.maven.infrastructure.MavenRoutes.requireGav(MavenRoutes.kt:48)
20:08:05.298 ERROR |    at com.reposilite.maven.infrastructure.MavenEndpoints$findFile$1$1.invoke(MavenEndpoints.kt:63)
20:08:05.298 ERROR |    at com.reposilite.maven.infrastructure.MavenEndpoints$findFile$1$1.invoke(MavenEndpoints.kt:62)
20:08:05.298 ERROR |    at com.reposilite.shared.ContextDsl.accessed(ContextDsl.kt:60)
20:08:05.298 ERROR |    at com.reposilite.maven.infrastructure.MavenEndpoints$findFile$1.invoke(MavenEndpoints.kt:62)
20:08:05.299 ERROR |    at com.reposilite.maven.infrastructure.MavenEndpoints$findFile$1.invoke(MavenEndpoints.kt:61)
20:08:05.299 ERROR |    at com.reposilite.web.infrastructure.ReposiliteRoutingKt$createReposiliteDsl$dsl$1.invoke$lambda$0(ReposiliteRouting.kt:78)
20:08:05.299 ERROR |    at io.javalin.router.Endpoint.handle(Endpoint.kt:29)
20:08:05.299 ERROR |    at io.javalin.router.ParsedEndpoint.handle(ParsedEndpoint.kt:15)
20:08:05.300 ERROR |    at io.javalin.http.servlet.DefaultTasks.HTTP$lambda$8$lambda$6$lambda$5(DefaultTasks.kt:41)
20:08:05.300 ERROR |    at io.javalin.http.servlet.JavalinServlet.handleTask(JavalinServlet.kt:99)
20:08:05.300 ERROR |    at io.javalin.http.servlet.JavalinServlet.handleSync(JavalinServlet.kt:64)
20:08:05.301 ERROR |    at io.javalin.http.servlet.JavalinServlet.handle(JavalinServlet.kt:50)
20:08:05.301 ERROR |    at io.javalin.http.servlet.JavalinServlet.service(JavalinServlet.kt:30)
20:08:05.301 ERROR |    at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:587)
20:08:05.301 ERROR |    at io.javalin.jetty.JavalinJettyServlet.service(JavalinJettyServlet.kt:52)
20:08:05.301 ERROR |    at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:587)
20:08:05.301 ERROR |    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)
20:08:05.302 ERROR |    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:529)
20:08:05.302 ERROR |    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
20:08:05.302 ERROR |    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1580)
20:08:05.302 ERROR |    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
20:08:05.303 ERROR |    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1381)
20:08:05.303 ERROR |    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
20:08:05.303 ERROR |    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
20:08:05.304 ERROR |    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1553)
20:08:05.304 ERROR |    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
20:08:05.304 ERROR |    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1303)
20:08:05.304 ERROR |    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
20:08:05.305 ERROR |    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
20:08:05.305 ERROR |    at org.eclipse.jetty.server.Server.handle(Server.java:563)
20:08:05.305 ERROR |    at org.eclipse.jetty.server.HttpChannel$RequestDispatchable.dispatch(HttpChannel.java:1598)
20:08:05.305 ERROR |    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:753)
20:08:05.305 ERROR |    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:501)
20:08:05.306 ERROR |    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:287)
20:08:05.306 ERROR |    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314)
20:08:05.306 ERROR |    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
20:08:05.306 ERROR |    at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
20:08:05.306 ERROR |    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:421)
20:08:05.307 ERROR |    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:390)
20:08:05.307 ERROR |    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:277)
20:08:05.307 ERROR |    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:199)
20:08:05.307 ERROR |    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411)
20:08:05.307 ERROR |    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:969)
20:08:05.308 ERROR |    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1194)
20:08:05.308 ERROR |    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1149)
20:08:05.308 ERROR |    at java.base/java.lang.Thread.run(Thread.java:1583)
20:08:05.309 ERROR | 

[dzikoysk]

That's a new one - it's not related to NoSuchFileException we cover in the put operation, but it occurs in FileSystemStorageProvider.getFile(), so probably during delete -> move procedure. Synchronizing other methods that depend on the put operation is a little bit more complicated tho, but let me check if we can supply some sort of quick fix that will let us sleep this night :)

[ivy-cst]

It was not new to me. That is what I tried to explain here: #2027 (comment)
But no hurry! It is not urgent, as soon as the mirror cache is up do date this exception should not happen.

[dzikoysk]

Let's try with this until I won't find more time for this:

• 1b1cad0

The idea behind this is to lock access to the same file via single-thread executor service, but in opposite to classic locking mechanisms, we can continue content processing (like e.g. handling file inputstream) from different threads (the caller thread). This is far from an ideal solution, because if one file is accessed by multiple requests, it starts locking all requests. To improve this and implement a valid queue, we'd need to move to CompletableFutures.

In the meantime, if you'd like to give it a try, you can try to use snapshot jar/docker nightly build.

[dzikoysk]

@ivy-cst I'm done for today, and not sure if I'll be here tomorrow since I'm a bit sick since a few days, so feel free to submit a PR if you'd like to continue working on this :)