BookLore icon indicating copy to clipboard operation
BookLore copied to clipboard
verified publisher icon adityachandelgit

Fix race conditions between Bookdrop and Monitoring Service when importing multiple files

Open piffio opened this issue 4 months ago • 0 comments

Summary

Fix an annoying race condition between Bookdrop and MonitoringService that happened when uploading multiple books at a time. See #1608 for more details on the bug.

  • Guard FileMoveService.moveSingleFile with isLibraryMonitoredWhenCalled so watcher deregistration/re-registration only happens when the library is actively monitored, avoiding BookDrop races.
  • Add DEBUG logs when calling registering/unregistering library monitoring
  • Surface MonitoringService#isLibraryMonitored through MonitoringRegistrationService.
  • Add FileMoveServiceTest to cover both monitored and unmonitored flows.

Testing

  • ./gradlew test --tests com.adityachandel.booklore.service.file.FileMoveServiceTest

** Bug evidence ** Below is a log snipped showing the offending calls to re-registering the library after the successful import of the first file

backend-1  | 2025-12-01T21:17:51.012Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.s.b.BookdropMonitoringService      : Bookdrop monitoring paused.
backend-1  | 2025-12-01T21:17:51.026Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Starting finalizeImport: selectAll=true, provided file count=7, defaultLibraryId=1, defaultPathId=1
backend-1  | 2025-12-01T21:17:51.052Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : SelectAll: Total files to finalize (after exclusions): 7, Excluded IDs: [258, 257, 256, 255, 254, 252, 253]
backend-1  | 2025-12-01T21:17:51.074Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing fileId=245, fileName=buildingmicroservices2e.epub with provided metadata, libraryId=1, pathId=1
backend-1  | 2025-12-01T21:17:51.074Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing fileId=246, fileName=buildingevolutionaryarchitectures2e.pdf with provided metadata, libraryId=1, pathId=1
backend-1  | 2025-12-01T21:17:51.074Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing fileId=247, fileName=buildingmulti-tenantsaasarchitectures.epub with provided metadata, libraryId=1, pathId=1
backend-1  | 2025-12-01T21:17:51.074Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing fileId=248, fileName=buildingmulti-tenantsaasarchitectures.pdf with provided metadata, libraryId=1, pathId=1
backend-1  | 2025-12-01T21:17:51.074Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing fileId=249, fileName=buildingmicroservices2e.pdf with provided metadata, libraryId=1, pathId=1
backend-1  | 2025-12-01T21:17:51.074Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing fileId=250, fileName=architecturepatternswithpython.epub with provided metadata, libraryId=1, pathId=1
backend-1  | 2025-12-01T21:17:51.074Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing fileId=251, fileName=buildingevolutionaryarchitectures2e.epub with provided metadata, libraryId=1, pathId=1
backend-1  | 2025-12-01T21:17:51.075Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Collected 1 unique libraries for monitoring unregistration: [1]
backend-1  | 2025-12-01T21:17:51.084Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Unregistered library 1 from monitoring
backend-1  | 2025-12-01T21:17:51.084Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Unregistered 1 libraries from monitoring
backend-1  | 2025-12-01T21:17:51.084Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing chunk 1/1 (7 files): IDs=[245, 246, 247, 248, 249, 250, 251]
backend-1  | 2025-12-01T21:17:51.093Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing fileId=245, fileName=buildingmicroservices2e.epub with provided metadata, libraryId=1, pathId=1
backend-1  | 2025-12-01T21:17:51.129Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Preparing to move file id=245, name=buildingmicroservices2e.epub, source=/bookdrop/buildingmicroservices2e.epub, target=/books/test/Sam Newman/Building Microservices - Sam Newman (2015).epub, library=Test Library, path=/books/test
backend-1  | 2025-12-01T21:17:51.523Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Moved file id=245, name=buildingmicroservices2e.epub from '/bookdrop/buildingmicroservices2e.epub' to '/books/test/Sam Newman/Building Microservices - Sam Newman (2015).epub'
backend-1  | 2025-12-01T21:17:53.067Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.booklore.util.FileService            : Cover images created and saved from URL for book ID: 302
backend-1  | 2025-12-01T21:17:54.812Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.s.m.writer.EpubMetadataWriter      : Metadata updated in EPUB: Building Microservices - Sam Newman (2015).epub
backend-1  | 2025-12-01T21:17:54.827Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.file.FileMoveService       : Registering library paths for library 1 with root /books/test
backend-1  | 2025-12-01T21:17:54.828Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.file.FileMoveHelper        : Registering library paths for library 1 with root /books/test
backend-1  | 2025-12-01T21:17:54.828Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.s.m.MonitoringRegistrationService  : Registering library paths for libraryId 1 at /books/test
backend-1  | 2025-12-01T21:17:54.876Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : File import completed: id=245, name=Building Microservices - Sam Newman (2015).epub, library=Test Library, path=/books/test
backend-1  | 2025-12-01T21:17:54.886Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Successfully deleted source file '/bookdrop/buildingmicroservices2e.epub' after successful import for file id=245
backend-1  | 2025-12-01T21:17:54.886Z  WARN 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Failed to cleanup temp file: /tmp/bookdrop-finalize-14325404668049596406buildingmicroservices2e.epub
backend-1  | 
backend-1  | java.nio.file.NoSuchFileException: /tmp/bookdrop-finalize-14325404668049596406buildingmicroservices2e.epub
backend-1  |    at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[na:na]
backend-1  |    at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106) ~[na:na]
backend-1  |    at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[na:na]
backend-1  |    at java.base/sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:271) ~[na:na]
backend-1  |    at java.base/sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:105) ~[na:na]
backend-1  |    at java.base/java.nio.file.Files.delete(Files.java:1052) ~[na:na]
backend-1  |    at com.adityachandel.booklore.service.bookdrop.BookDropService.cleanupTempFile(BookDropService.java:510) ~[main/:na]
backend-1  |    at com.adityachandel.booklore.service.bookdrop.BookDropService.performFileMove(BookDropService.java:437) ~[main/:na]
backend-1  |    at com.adityachandel.booklore.service.bookdrop.BookDropService.moveFile(BookDropService.java:397) ~[main/:na]
backend-1  |    at com.adityachandel.booklore.service.bookdrop.BookDropService.processFile(BookDropService.java:320) ~[main/:na]
backend-1  |    at com.adityachandel.booklore.service.bookdrop.BookDropService.processFileChunks(BookDropService.java:244) ~[main/:na]
backend-1  |    at com.adityachandel.booklore.service.bookdrop.BookDropService.processAllFiles(BookDropService.java:192) ~[main/:na]
backend-1  |    at com.adityachandel.booklore.service.bookdrop.BookDropService.processFinalizationRequest(BookDropService.java:165) ~[main/:na]
backend-1  |    at com.adityachandel.booklore.service.bookdrop.BookDropService.finalizeImport(BookDropService.java:109) ~[main/:na]
backend-1  |    at com.adityachandel.booklore.controller.BookdropFileController.finalizeImport(BookdropFileController.java:60) ~[main/:na]
backend-1  |    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) ~[na:na]
backend-1  |    at java.base/java.lang.reflect.Method.invoke(Method.java:565) ~[na:na]
backend-1  |    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:258) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:191) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:118) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:986) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:891) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:914) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:590) ~[tomcat-embed-core-10.1.42.jar:6.0]
backend-1  |    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658) ~[tomcat-embed-core-10.1.42.jar:6.0]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:195) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51) ~[tomcat-embed-websocket-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at com.adityachandel.booklore.config.security.filter.KoreaderAuthFilter.doFilterInternal(KoreaderAuthFilter.java:33) ~[main/:na]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at com.adityachandel.booklore.config.security.filter.KoboAuthFilter.doFilterInternal(KoboAuthFilter.java:41) ~[main/:na]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at com.adityachandel.booklore.config.security.filter.JwtAuthenticationFilter.doFilterInternal(JwtAuthenticationFilter.java:52) ~[main/:na]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at com.adityachandel.booklore.config.security.filter.ImageCachingFilter.doFilterInternal(ImageCachingFilter.java:23) ~[main/:na]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:110) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:108) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:108) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.security.web.FilterChainProxy.lambda$doFilterInternal$3(FilterChainProxy.java:231) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$FilterObservation$SimpleFilterObservation.lambda$wrap$1(ObservationFilterChainDecorator.java:479) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$AroundFilterObservation$SimpleAroundFilterObservation.lambda$wrap$1(ObservationFilterChainDecorator.java:340) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator.lambda$wrapSecured$0(ObservationFilterChainDecorator.java:82) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:128) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.access.intercept.AuthorizationFilter.doFilter(AuthorizationFilter.java:101) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:125) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:119) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:131) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:85) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:100) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:179) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at com.adityachandel.booklore.config.security.filter.DualJwtAuthenticationFilter.doFilterInternal(DualJwtAuthenticationFilter.java:87) ~[main/:na]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:107) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:93) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.web.filter.CorsFilter.doFilterInternal(CorsFilter.java:91) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.context.SecurityContextHolderFilter.doFilter(SecurityContextHolderFilter.java:82) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.context.SecurityContextHolderFilter.doFilter(SecurityContextHolderFilter.java:69) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:62) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.session.DisableEncodeUrlFilter.doFilterInternal(DisableEncodeUrlFilter.java:42) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$AroundFilterObservation$SimpleAroundFilterObservation.lambda$wrap$0(ObservationFilterChainDecorator.java:323) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:224) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:233) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:191) ~[spring-security-web-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:113) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.ServletRequestPathFilter.doFilter(ServletRequestPathFilter.java:52) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:113) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.CompositeFilter.doFilter(CompositeFilter.java:74) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.security.config.annotation.web.configuration.WebSecurityConfiguration$CompositeFilterChainProxy.doFilter(WebSecurityConfiguration.java:319) ~[spring-security-config-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:113) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.servlet.handler.HandlerMappingIntrospector.lambda$createCacheFilter$4(HandlerMappingIntrospector.java:267) ~[spring-webmvc-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:113) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.CompositeFilter.doFilter(CompositeFilter.java:74) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.security.config.annotation.web.configuration.WebMvcSecurityConfiguration$CompositeFilterChainProxy.doFilter(WebMvcSecurityConfiguration.java:240) ~[spring-security-config-6.5.1.jar:6.5.1]
backend-1  |    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:362) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:278) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.springframework.web.filter.ServerHttpObservationFilter.doFilterInternal(ServerHttpObservationFilter.java:114) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.2.8.jar:6.2.8]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:483) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:116) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:732) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:398) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:903) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1769) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1189) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:658) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63) ~[tomcat-embed-core-10.1.42.jar:10.1.42]
backend-1  |    at java.base/java.lang.Thread.run(Thread.java:1474) ~[na:na]
backend-1  | 
backend-1  | 2025-12-01T21:17:54.897Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Successfully finalized file id=245, name=buildingmicroservices2e.epub
backend-1  | 2025-12-01T21:17:54.898Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Processing fileId=246, fileName=buildingevolutionaryarchitectures2e.pdf with provided metadata, libraryId=1, pathId=1
backend-1  | 2025-12-01T21:17:54.899Z DEBUG 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Preparing to move file id=246, name=buildingevolutionaryarchitectures2e.pdf, source=/bookdrop/buildingevolutionaryarchitectures2e.pdf, target=/books/test/Neal Ford/Building Evolutionary Architectures - Neal Ford (2017).pdf, library=Test Library, path=/books/test
backend-1  | 2025-12-01T21:17:54.984Z  INFO 249 --- [booklore-api] [     virtual-44] c.a.b.s.w.LibraryFileEventProcessor      : [PROCESS] 'ENTRY_CREATE' event for 'Neal Ford'
backend-1  | 2025-12-01T21:17:55.026Z  INFO 249 --- [booklore-api] [     virtual-44] c.a.b.s.w.LibraryFileEventProcessor      : [FOLDER_CREATE] '/books/test/Neal Ford'
backend-1  | 2025-12-01T21:17:55.047Z  INFO 249 --- [booklore-api] [     virtual-44] c.a.b.s.library.FileAsBookProcessor      : Processing file: Building Evolutionary Architectures - Neal Ford (2017).pdf
backend-1  | 2025-12-01T21:17:55.048Z  INFO 249 --- [booklore-api] [nio-8080-exec-2] c.a.b.service.bookdrop.BookDropService   : Moved file id=246, name=buildingevolutionaryarchitectures2e.pdf from '/bookdrop/buildingevolutionaryarchitectures2e.pdf' to '/books/test/Neal Ford/Building Evolutionary Architectures - Neal Ford (2017).pdf'
backend-1  | 2025-12-01T21:17:56.261Z  WARN 249 --- [booklore-api] [     virtual-44] o.m.jdbc.message.server.ErrorPacket      : Error: 1062-23000: Duplicate entry 'Building Evolutionary Architectures - Neal Ford (2017).pdf-1' for key 'unique_file_library'
backend-1  | 2025-12-01T21:17:56.279Z  WARN 249 --- [booklore-api] [     virtual-44] org.hibernate.orm.jdbc.error             : HHH000247: ErrorCode: 1062, SQLState: 23000
backend-1  | 2025-12-01T21:17:56.280Z  WARN 249 --- [booklore-api] [     virtual-44] org.hibernate.orm.jdbc.error             : (conn=534) Duplicate entry 'Building Evolutionary Architectures - Neal Ford (2017).pdf-1' for key 'unique_file_library'
backend-1  | 2025-12-01T21:17:56.354Z  WARN 249 --- [booklore-api] [     virtual-44] c.a.b.s.w.LibraryFileEventProcessor      : [ERROR] Processing file '/books/test/Neal Ford/Building Evolutionary Architectures - Neal Ford (2017).pdf': could not execute statement [(conn=534) Duplicate entry 'Building Evolutionary Architectures - Neal Ford (2017).pdf-1' for key 'unique_file_library'] [insert into book (added_on,book_type,current_hash,deleted,deleted_at,file_name,file_size_kb,file_sub_path,initial_hash,library_id,library_path_id,metadata_match_score,similar_books_json) values (?,?,?,?,?,?,?,?,?,?,?,?,?)]; SQL [insert into book (added_on,book_type,current_hash,deleted,deleted_at,file_name,file_size_kb,file_sub_path,initial_hash,library_id,library_path_id,metadata_match_score,similar_books_json) values (?,?,?,?,?,?,?,?,?,?,?,?,?)]; constraint [unique_file_library]
backend-1  | 2025-12-01T21:17:56.356Z  INFO 249 --- [booklore-api] [     virtual-44] c.a.b.s.w.LibraryFileEventProcessor      : [PROCESS] 'ENTRY_CREATE' event for 'Building Evolutionary Architectures - Neal Ford (2017).pdf'
backend-1  | 2025-12-01T21:17:56.368Z  INFO 249 --- [booklore-api] [     virtual-44] c.a.b.s.w.LibraryFileEventProcessor      : [FILE_CREATE] '/books/test/Neal Ford/Building Evolutionary Architectures - Neal Ford (2017).pdf'
backend-1  | 2025-12-01T21:17:56.377Z  INFO 249 --- [booklore-api] [     virtual-44] c.a.b.s.library.FileAsBookProcessor      : Processing file: Building Evolutionary Architectures - Neal Ford (2017).pdf
backend-1  | 2025-12-01T21:17:56.383Z  WARN 249 --- [booklore-api] [     virtual-44] o.m.jdbc.message.server.ErrorPacket      : Error: 1062-23000: Duplicate entry 'Building Evolutionary Architectures - Neal Ford (2017).pdf-1' for key 'unique_file_library'
backend-1  | 2025-12-01T21:17:56.384Z  WARN 249 --- [booklore-api] [     virtual-44] org.hibernate.orm.jdbc.error             : HHH000247: ErrorCode: 1062, SQLState: 23000
backend-1  | 2025-12-01T21:17:56.384Z  WARN 249 --- [booklore-api] [     virtual-44] org.hibernate.orm.jdbc.error             : (conn=534) Duplicate entry 'Building Evolutionary Architectures - Neal Ford (2017).pdf-1' for key 'unique_file_library'
backend-1  | 2025-12-01T21:17:56.387Z ERROR 249 --- [booklore-api] [     virtual-44] c.a.b.s.w.LibraryFileEventProcessor      : Error while processing file event

piffio avatar Dec 01 '25 22:12 piffio