Concurrency issues with package cache in validator

[dehall]

Concurrency issues with package cache in validator

[grahamegrieve]

The information in this file is only used when displaying the cache to a user and advising when an entry in the cache was last used. There is a tool that does this, but not all tools set the usage date, so it's not reliable.

We should surround this code with a try..catch and ignore any errors from it; they simply don't matter.

[dehall]

Update: there is one other error we've seen multiple times, looks like it's related to one thread trying to read a file while another is trying to delete it. I haven't had time to try to replicate this yet but this is the log snippet.

Installing fhir.dicom#2022.4.202210062024-06-07 17:50:20.380 [ktor-jetty-3500-2] ERROR ktor.application - 1 exception(s): [org.apache.commons.io.IOIndexedException: IOException #0: Cannot delete file: /home/ktor/.fhir/packages/44eb56b7-82f4-4808-b3d8-6df033b81f72/package]
 done.
Clean up package /home/ktor/.fhir/packages/fhir.dicom#2022.4.20221006 because installation failed: File /home/ktor/.fhir/packages/fhir.dicom#2022.4.20221006/package/package.json not found
java.io.IOException: File /home/ktor/.fhir/packages/fhir.dicom#2022.4.20221006/package/package.json not found
2024-06-07 17:50:20.383 [ktor-jetty-3500-3] INFO  ktor.application - 500 Internal Server Error: POST - /validate
	at org.hl7.fhir.utilities.TextFile.fileToString(TextFile.java:117)
	at org.hl7.fhir.utilities.npm.NpmPackage.loadFiles(NpmPackage.java:401)
	at org.hl7.fhir.utilities.npm.NpmPackage.fromFolder(NpmPackage.java:360)
	at org.hl7.fhir.utilities.npm.FilesystemPackageCacheManager.loadPackageInfo(FilesystemPackageCacheManager.java:265)
	at org.hl7.fhir.utilities.npm.FilesystemPackageCacheManager.lambda$addPackageToCache$2(FilesystemPackageCacheManager.java:546)
	at org.hl7.fhir.utilities.npm.FilesystemPackageCacheLock.doWriteWithLock(FilesystemPackageCacheLock.java:37)
	at org.hl7.fhir.utilities.npm.FilesystemPackageCacheManager.addPackageToCache(FilesystemPackageCacheManager.java:508)
	at org.hl7.fhir.utilities.npm.FilesystemPackageCacheManager.loadPackage(FilesystemPackageCacheManager.java:651)
	at org.hl7.fhir.validation.IgLoader.loadIg(IgLoader.java:107)
	at org.hl7.fhir.validation.IgLoader.loadIg(IgLoader.java:120)
	at org.hl7.fhir.validation.cli.services.ValidationService.loadIgsAndExtensions(ValidationService.java:553)
	at org.hl7.fhir.validation.cli.services.ValidationService.buildValidationEngine(ValidationService.java:494)
	at org.hl7.fhir.validation.cli.services.ValidationService.initializeValidator(ValidationService.java:475)
	at org.hl7.fhir.validation.cli.services.ValidationService.validateSources(ValidationService.java:95)
	at controller.validation.ValidationControllerImpl.validateRequest(ValidationControllerImpl.kt:18)
	at controller.validation.ValidationModuleKt$validationModule$1.invokeSuspend(ValidationModule.kt:43)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at io.ktor.util.pipeline.SuspendFunctionGun.resumeRootWith(SuspendFunctionGun.kt:138)
	at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.kt:112)
	at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(SuspendFunctionGun.kt:14)
	at io.ktor.util.pipeline.SuspendFunctionGun$continuation$1.resumeWith(SuspendFunctionGun.kt:62)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)
2024-06-07 17:50:20.393 [ktor-jetty-3500-4] ERROR ktor.application - File /home/ktor/.fhir/packages/fhir.dicom#2022.4.20221006/package/package.json not found
2024-06-07 17:50:20.394 [ktor-jetty-3500-1] INFO  ktor.application - Received Validation Request. FHIR Version: 4.0.1 IGs: [hl7.fhir.us.core#5.0.1] Memory (free/max): 4921594968/8283750400
No such cached session exists for session id 008b523b-bb4c-44ae-8a0e-44ac1bcd5599, re-instantiating validator.
  Load FHIR v4.0.1 from hl7.fhir.r4.core#4.0.12024-06-07 17:50:20.395 [ktor-jetty-3500-4] INFO  ktor.application - 500 Internal Server Error: POST - /validate

[grahamegrieve]

Yes this is. big concurrency issue. scheduled to look at next week