Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

STM - File System Exception #6553

Closed
cescoffier opened this issue Jan 14, 2020 · 1 comment · Fixed by #6555
Closed

STM - File System Exception #6553

cescoffier opened this issue Jan 14, 2020 · 1 comment · Fixed by #6555
Assignees
@gastaldi
Labels
area/narayana Transactions / Narayana kind/bug Something isn't working
Milestone
1.2.0.CR1

Comments

@cescoffier
Copy link
Member

I've an issue when running the STM quickstart in native mode on Github Actions:

2020-01-14T16:08:07.2666634Z [INFO] Running org.acme.quickstart.stm.STMResourceIT
2020-01-14T16:08:07.3460934Z Executing [/home/runner/work/quarkus-quickstarts/quarkus-quickstarts/software-transactional-memory-quickstart/target/software-transactional-memory-quickstart-1.0-SNAPSHOT-runner, -Dquarkus.http.port=8081, -Dtest.url=http://localhost:8081, -Dquarkus.log.file.path=target/quarkus.log]
2020-01-14T16:08:07.3762594Z 16:08:07 INFO  [io.quarkus] (main) software-transactional-memory-quickstart 1.0-SNAPSHOT (running on Quarkus 999-SNAPSHOT) started in 0.018s. Listening on: http://0.0.0.0:8081
2020-01-14T16:08:07.3763529Z 16:08:07 INFO  [io.quarkus] (main) Profile prod activated. 
2020-01-14T16:08:07.3764425Z 16:08:07 INFO  [io.quarkus] (main) Installed features: [cdi, narayana-stm, resteasy]
2020-01-14T16:08:18.2552451Z 16:08:18 WARN  [co.ar.at.common] (pool-2-thread-1) ARJUNA048006: cannot create new instance of com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore: java.lang.reflect.InvocationTargetException
2020-01-14T16:08:18.2626719Z 	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
2020-01-14T16:08:18.2627248Z 	at com.arjuna.common.internal.util.ClassloadingUtility.loadAndInstantiateClass(ClassloadingUtility.java:129)
2020-01-14T16:08:18.2627431Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.initStore(StoreManager.java:152)
2020-01-14T16:08:18.2627614Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.getActionStore(StoreManager.java:111)
2020-01-14T16:08:18.2628919Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.getParticipantStore(StoreManager.java:81)
2020-01-14T16:08:18.2629607Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.getStore(BasicAction.java:403)
2020-01-14T16:08:18.2630059Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2116)
2020-01-14T16:08:18.2630239Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1503)
2020-01-14T16:08:18.2630581Z 	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
2020-01-14T16:08:18.2630945Z 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
2020-01-14T16:08:18.2668507Z 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:147)
2020-01-14T16:08:18.2669210Z 	at org.jboss.stm.internal.reflect.InvocationHandler.<init>(InvocationHandler.java:212)
2020-01-14T16:08:18.2669686Z 	at org.jboss.stm.internal.reflect.InvocationHandler.<init>(InvocationHandler.java:109)
2020-01-14T16:08:18.2670097Z 	at org.jboss.stm.internal.RecoverableContainer.createHandle(RecoverableContainer.java:207)
2020-01-14T16:08:18.2670846Z 	at org.jboss.stm.internal.RecoverableContainer.enlist(RecoverableContainer.java:136)
2020-01-14T16:08:18.2671338Z 	at org.jboss.stm.Container.create(Container.java:206)
2020-01-14T16:08:18.2671791Z 	at org.acme.quickstart.stm.FlightServiceFactory.initFlightServiceFactory(FlightServiceFactory.java:13)
2020-01-14T16:08:18.2672212Z 	at org.acme.quickstart.stm.FlightServiceFactory.getInstance(FlightServiceFactory.java:18)
2020-01-14T16:08:18.2672638Z 	at org.acme.quickstart.stm.FlightServiceFactory_ClientProxy.getInstance(FlightServiceFactory_ClientProxy.zig:157)
2020-01-14T16:08:18.2673180Z 	at org.acme.quickstart.stm.FlightResource.lambda$bookingCount$0(FlightResource.java:44)
2020-01-14T16:08:18.2673628Z 	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1604)
2020-01-14T16:08:18.2674043Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2020-01-14T16:08:18.2674541Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-01-14T16:08:18.2674971Z 	at java.lang.Thread.run(Thread.java:748)
2020-01-14T16:08:18.2675418Z 	at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:479)
2020-01-14T16:08:18.2676676Z 	at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
2020-01-14T16:08:18.2820187Z Caused by: com.arjuna.ats.arjuna.exceptions.ObjectStoreException: ARJUNA012225: FileSystemStore::setupStore - cannot access root of object store: /project/ObjectStore/ShadowNoFileLockStore/defaultStore/
2020-01-14T16:08:18.2820489Z 	at com.arjuna.ats.internal.arjuna.objectstore.FileSystemStore.<init>(FileSystemStore.java:633)
2020-01-14T16:08:18.2820643Z 	at com.arjuna.ats.internal.arjuna.objectstore.ShadowingStore.<init>(ShadowingStore.java:652)
2020-01-14T16:08:18.2820789Z 	at com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore.<init>(ShadowNoFileLockStore.java:53)
2020-01-14T16:08:18.2820903Z 	... 26 more
2020-01-14T16:08:18.2820985Z 
2020-01-14T16:08:18.2821664Z 16:08:18 ERROR [or.jb.re.re.i18n] (pool-2-thread-1) RESTEASY002020: Unhandled asynchronous exception, sending back 500: com.arjuna.ats.arjuna.exceptions.FatalError: ARJUNA012391: Could not initialize object store {0} of type {1}
2020-01-14T16:08:18.2821849Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.initStore(StoreManager.java:160)
2020-01-14T16:08:18.2821973Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.getActionStore(StoreManager.java:111)
2020-01-14T16:08:18.2822118Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.getParticipantStore(StoreManager.java:81)
2020-01-14T16:08:18.2822257Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.getStore(BasicAction.java:403)
2020-01-14T16:08:18.2822394Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2116)
2020-01-14T16:08:18.2822507Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1503)
2020-01-14T16:08:18.2822649Z 	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
2020-01-14T16:08:18.2823252Z 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
2020-01-14T16:08:18.2823442Z 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:147)
2020-01-14T16:08:18.2823568Z 	at org.jboss.stm.internal.reflect.InvocationHandler.<init>(InvocationHandler.java:212)
2020-01-14T16:08:18.2823713Z 	at org.jboss.stm.internal.reflect.InvocationHandler.<init>(InvocationHandler.java:109)
2020-01-14T16:08:18.2823856Z 	at org.jboss.stm.internal.RecoverableContainer.createHandle(RecoverableContainer.java:207)
2020-01-14T16:08:18.2823999Z 	at org.jboss.stm.internal.RecoverableContainer.enlist(RecoverableContainer.java:136)
2020-01-14T16:08:18.2824133Z 	at org.jboss.stm.Container.create(Container.java:206)
2020-01-14T16:08:18.2824251Z 	at org.acme.quickstart.stm.FlightServiceFactory.initFlightServiceFactory(FlightServiceFactory.java:13)
2020-01-14T16:08:18.2824399Z 	at org.acme.quickstart.stm.FlightServiceFactory.getInstance(FlightServiceFactory.java:18)
2020-01-14T16:08:18.2824557Z 	at org.acme.quickstart.stm.FlightServiceFactory_ClientProxy.getInstance(FlightServiceFactory_ClientProxy.zig:157)
2020-01-14T16:08:18.2824703Z 	at org.acme.quickstart.stm.FlightResource.lambda$bookingCount$0(FlightResource.java:44)
2020-01-14T16:08:18.2824851Z 	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1604)
2020-01-14T16:08:18.2824968Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2020-01-14T16:08:18.2825108Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-01-14T16:08:18.2825238Z 	at java.lang.Thread.run(Thread.java:748)
2020-01-14T16:08:18.2825372Z 	at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:479)
2020-01-14T16:08:18.2825494Z 	at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
2020-01-14T16:08:18.2825591Z 
2020-01-14T16:08:28.4129499Z 16:08:28 WARN  [co.ar.at.common] (pool-3-thread-1) ARJUNA048006: cannot create new instance of com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore: java.lang.reflect.InvocationTargetException
2020-01-14T16:08:28.4130804Z 	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
2020-01-14T16:08:28.4131691Z 	at com.arjuna.common.internal.util.ClassloadingUtility.loadAndInstantiateClass(ClassloadingUtility.java:129)
2020-01-14T16:08:28.4131883Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.initStore(StoreManager.java:152)
2020-01-14T16:08:28.4132053Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.getActionStore(StoreManager.java:111)
2020-01-14T16:08:28.4132212Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.getParticipantStore(StoreManager.java:81)
2020-01-14T16:08:28.4132343Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.getStore(BasicAction.java:403)
2020-01-14T16:08:28.4132494Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2116)
2020-01-14T16:08:28.4132656Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1503)
2020-01-14T16:08:28.4132811Z 	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
2020-01-14T16:08:28.4132970Z 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
2020-01-14T16:08:28.4133122Z 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:147)
2020-01-14T16:08:28.4133253Z 	at org.jboss.stm.internal.reflect.InvocationHandler.<init>(InvocationHandler.java:212)
2020-01-14T16:08:28.4133410Z 	at org.jboss.stm.internal.reflect.InvocationHandler.<init>(InvocationHandler.java:109)
2020-01-14T16:08:28.4133566Z 	at org.jboss.stm.internal.RecoverableContainer.createHandle(RecoverableContainer.java:207)
2020-01-14T16:08:28.4133721Z 	at org.jboss.stm.internal.RecoverableContainer.enlist(RecoverableContainer.java:136)
2020-01-14T16:08:28.4133867Z 	at org.jboss.stm.Container.create(Container.java:206)
2020-01-14T16:08:28.4134180Z 	at org.acme.quickstart.stm.FlightServiceFactory.initFlightServiceFactory(FlightServiceFactory.java:13)
2020-01-14T16:08:28.4154458Z 	at org.acme.quickstart.stm.FlightServiceFactory.getInstance(FlightServiceFactory.java:18)
2020-01-14T16:08:28.4157437Z 	at org.acme.quickstart.stm.FlightServiceFactory_ClientProxy.getInstance(FlightServiceFactory_ClientProxy.zig:157)
2020-01-14T16:08:28.4160700Z 	at org.acme.quickstart.stm.FlightResource.lambda$asynBook$1(FlightResource.java:53)
2020-01-14T16:08:28.4173501Z 	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1604)
2020-01-14T16:08:28.4176514Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2020-01-14T16:08:28.4189219Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-01-14T16:08:28.4192960Z 	at java.lang.Thread.run(Thread.java:748)
2020-01-14T16:08:28.4208732Z 	at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:479)
2020-01-14T16:08:28.4215973Z 	at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
2020-01-14T16:08:28.4231341Z Caused by: com.arjuna.ats.arjuna.exceptions.ObjectStoreException: ARJUNA012225: FileSystemStore::setupStore - cannot access root of object store: /project/ObjectStore/ShadowNoFileLockStore/defaultStore/
2020-01-14T16:08:28.4236240Z 	at com.arjuna.ats.internal.arjuna.objectstore.FileSystemStore.<init>(FileSystemStore.java:633)
2020-01-14T16:08:28.4242692Z 	at com.arjuna.ats.internal.arjuna.objectstore.ShadowingStore.<init>(ShadowingStore.java:652)
2020-01-14T16:08:28.4250057Z 	at com.arjuna.ats.internal.arjuna.objectstore.ShadowNoFileLockStore.<init>(ShadowNoFileLockStore.java:53)
2020-01-14T16:08:28.4254772Z 	... 26 more
2020-01-14T16:08:28.4254906Z 
2020-01-14T16:08:28.4271345Z 16:08:28 ERROR [or.jb.re.re.i18n] (pool-3-thread-1) RESTEASY002020: Unhandled asynchronous exception, sending back 500: com.arjuna.ats.arjuna.exceptions.FatalError: ARJUNA012391: Could not initialize object store {0} of type {1}
2020-01-14T16:08:28.4276541Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.initStore(StoreManager.java:160)
2020-01-14T16:08:28.4283541Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.getActionStore(StoreManager.java:111)
2020-01-14T16:08:28.4288228Z 	at com.arjuna.ats.arjuna.objectstore.StoreManager.getParticipantStore(StoreManager.java:81)
2020-01-14T16:08:28.4293769Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.getStore(BasicAction.java:403)
2020-01-14T16:08:28.4299183Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2116)
2020-01-14T16:08:28.4304558Z 	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1503)
2020-01-14T16:08:28.4337901Z 	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
2020-01-14T16:08:28.4342910Z 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
2020-01-14T16:08:28.4347679Z 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:147)
2020-01-14T16:08:28.4360001Z 	at org.jboss.stm.internal.reflect.InvocationHandler.<init>(InvocationHandler.java:212)
2020-01-14T16:08:28.4366456Z 	at org.jboss.stm.internal.reflect.InvocationHandler.<init>(InvocationHandler.java:109)
2020-01-14T16:08:28.4372789Z 	at org.jboss.stm.internal.RecoverableContainer.createHandle(RecoverableContainer.java:207)
2020-01-14T16:08:28.4382930Z 	at org.jboss.stm.internal.RecoverableContainer.enlist(RecoverableContainer.java:136)
2020-01-14T16:08:28.4386134Z 	at org.jboss.stm.Container.create(Container.java:206)
2020-01-14T16:08:28.4393649Z 	at org.acme.quickstart.stm.FlightServiceFactory.initFlightServiceFactory(FlightServiceFactory.java:13)
2020-01-14T16:08:28.4400297Z 	at org.acme.quickstart.stm.FlightServiceFactory.getInstance(FlightServiceFactory.java:18)
2020-01-14T16:08:28.4408291Z 	at org.acme.quickstart.stm.FlightServiceFactory_ClientProxy.getInstance(FlightServiceFactory_ClientProxy.zig:157)
2020-01-14T16:08:28.4414307Z 	at org.acme.quickstart.stm.FlightResource.lambda$asynBook$1(FlightResource.java:53)
2020-01-14T16:08:28.4420830Z 	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1604)
2020-01-14T16:08:28.4428629Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2020-01-14T16:08:28.4474691Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-01-14T16:08:28.4475670Z 	at java.lang.Thread.run(Thread.java:748)
2020-01-14T16:08:28.4476694Z 	at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:479)
2020-01-14T16:08:28.4480414Z 	at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
2020-01-14T16:08:28.4481189Z 
2020-01-14T16:08:28.4605331Z [ERROR] Tests run: 2, Failures: 2, Errors: 0, Skipped: 0, Time elapsed: 21.184 s <<< FAILURE! - in org.acme.quickstart.stm.STMResourceIT
2020-01-14T16:08:28.4606836Z [ERROR] testGet  Time elapsed: 10.964 s  <<< FAILURE!
2020-01-14T16:08:28.4608066Z java.lang.AssertionError: 
2020-01-14T16:08:28.4609290Z 1 expectation failed.
2020-01-14T16:08:28.4610447Z Expected status code <200> but was <500>.
2020-01-14T16:08:28.4611560Z 
2020-01-14T16:08:28.4612027Z 
2020-01-14T16:08:28.4612289Z [ERROR] testPost  Time elapsed: 9.999 s  <<< FAILURE!
2020-01-14T16:08:28.4613319Z java.lang.AssertionError: 
2020-01-14T16:08:28.4614450Z 1 expectation failed.
2020-01-14T16:08:28.4615879Z Expected status code <200> but was <500>.
2020-01-14T16:08:28.4616171Z 
2020-01-14T16:08:28.4616418Z 
2020-01-14T16:08:28.7940920Z [INFO] 
2020-01-14T16:08:28.7941635Z [INFO] Results:
2020-01-14T16:08:28.7941931Z [INFO] 
2020-01-14T16:08:28.7942195Z [ERROR] Failures: 
2020-01-14T16:08:28.7953640Z [ERROR]   STMResourceIT>STMResourceTest.testGet:20 1 expectation failed.
2020-01-14T16:08:28.7956335Z Expected status code <200> but was <500>.
2020-01-14T16:08:28.7958086Z 
2020-01-14T16:08:28.7959478Z [ERROR]   STMResourceIT>STMResourceTest.testPost:27->STMResourceTest.makeBooking:36 1 expectation failed.
2020-01-14T16:08:28.7959907Z Expected status code <200> but was <500>.
2020-01-14T16:08:28.7960173Z 
2020-01-14T16:08:28.7960413Z [INFO] 
2020-01-14T16:08:28.7960687Z [ERROR] Tests run: 2, Failures: 2, Errors: 0, Skipped: 0
@cescoffier cescoffier added the kind/bug Something isn't working label Jan 14, 2020
@gastaldi
Copy link
Contributor

gastaldi commented Jan 14, 2020 •
edited
Loading

It looks like this is caused by a call to System.getProperty("user.home") in a class initialized during build time when the Docker build is used instead of a local GraalVM.

My investigation points to the constructor of com.arjuna.ats.arjuna.common.ObjectStoreEnvironmentBean, where it does: this.objectStoreDir = System.getProperty("user.dir") + File.separator + "ObjectStore"

@gastaldi gastaldi self-assigned this Jan 14, 2020
@gastaldi gastaldi added the area/narayana Transactions / Narayana label Jan 14, 2020
@gastaldi gastaldi mentioned this issue Jan 14, 2020
Merged
@cescoffier cescoffier mentioned this issue Jan 15, 2020
Merged
@gsmet gsmet added this to the 1.2.0 milestone Jan 15, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@gastaldi gastaldi

Labels
area/narayana Transactions / Narayana kind/bug Something isn't working
Projects
None yet
Milestone
1.2.0.CR1
Development

Successfully merging a pull request may close this issue.

ObjectStoreEnvironmentBean.getObjectStore should not cache the user.home during build-time
3 participants
@gastaldi @cescoffier @gsmet