Hello, Oliver! I've committed a fix using your code as a test and uploaded a new Tapestry 5.6.0 snapshot to the ASF snapshot repository at https://repository.apache.org/content/groups/snapshots/. Could you please test on your end too? Thanks in advance.
On Sat, Aug 15, 2020 at 3:08 PM Thiago H. de Paula Figueiredo < thiag...@gmail.com> wrote: > Hello! > > It's a very specific corner case. Please create a JIRA ticket and I'll try > to fix it. Thanks for posting and investigating! > > On Thu, Jul 30, 2020 at 1:44 PM Oliver Kaiser <oliver.kai...@eddyson.de> > wrote: > >> Hi everyone, >> >> >> we recently found a strange deadlock problem; first seemed to be related >> to switching from 5.5.0-beta-1 to 5.5.0, at least >> in the full application it was easy to reproduce with the latter but (in >> a few manual tests) not with the beta. >> >> after trying to reduce it to a minimal test case… it can be triggered >> with either (and 5.4.x); maybe in the "real" code the calls >> take long enough to avoid the data race or at least make it unlikely. >> >> >> on to the questions: >> >> * has anyone seen something like this before? closest bug i can find is: >> https://issues.apache.org/jira/browse/TAPESTRY-2561 >> >> * is this likely related to registry startup? kinda afraid of same >> situation during normal operations, though once most/all services >> are realized everything should be fine >> >> thanks for reading & any hints you can offer >> >> Regards, >> Oliver >> >> >> it appears all of the following is required: >> >> * a builder method for a simple class (not a service); with some kind of >> call to IOC (inject anything) >> >> public static SomeClass build(@Inject @Symbol("some.symbol") String >> uri) { >> return new SomeClass(); >> } >> >> >> * this class is a dependency for a shared service: >> >> public class SharedImpl implements Shared { >> >> public SharedImpl(SomeClass iDoNothing) { >> } >> >> >> * two services marked as eager-load; both require the shared service >> >> public static void bind(ServiceBinder binder) { >> binder.bind(JobAdder.class, JobAdderImpl.class).eagerLoad(); >> binder.bind(Other.class, OtherImpl.class).eagerLoad(); >> binder.bind(Shared.class, SharedImpl.class); >> } >> >> >> * JobAdder c-tor adds Runnable(s) to PeriodicExecutor >> >> public JobAdderImpl(List<RunnableJobData> parts, PeriodicExecutor >> exec) { >> LOG.info("Blocked here?"); >> >> for (RunnableJobData p : parts) { >> exec.addJob(new ImmediateStartIntervalSchedule(1000 * 60), >> p.name, p.run); >> } >> } >> >> >> * the Runnable and OtherImpl (c-tor) call the shared service (instances >> are realized) >> >> @Contribute(JobAdder.class) >> public static void contributeJobParts(OrderedConfiguration conf, >> Shared something) { >> >> conf.add("abc", new RunnableJobData("abc", () -> { >> LOG.info("starting job"); >> something.doFoo(); >> >> >> public class OtherImpl implements Other { >> >> public OtherImpl(Shared xx) { >> xx.doFoo(); >> >> >> * the jobs start immediately (no initial delay) >> >> public class ImmediateStartIntervalSchedule extends IntervalSchedule { >> >> public ImmediateStartIntervalSchedule(final long interval) { >> super(interval); >> } >> >> @Override >> public long firstExecution() { >> return System.currentTimeMillis(); >> } >> >> >> >> probably the easiest fix (for us) is to avoid the immediate execution of >> periodic jobs while "RegistryImpl.performRegistryStartup" >> is still running on the main thread; e.g. adding the jobs from a >> @Startup method seems to work ok >> >> maybe PeriodicExecutorImpl::start should be called from @Startup instead >> of @PostInjection (assuming startup methods are called after the >> registry is done, while @PostInjection is called earlier?) >> >> >> in the trace below both threads "hold" a R-lock, one also has (upgraded >> to) W, the second blocks on W … that seems wrong >> >> >> https://github.com/apache/tapestry-5/blob/master/tapestry-ioc/src/main/java/org/apache/tapestry5/ioc/internal/util/ConcurrentBarrier.java#L54 >> maybe reentrancy; but i'm not sure about the "upgrade R to W" logic >> >> >> >> here is the test source: https://easyupload.io/xzy6j1 >> >> >> Found one Java-level deadlock: >> ============================= >> "main": >> waiting to lock monitor 0x00007f7f38008b80 (object >> 0x000000071554f4a8, a >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator), >> which is held by "Tapestry PeriodicExecutor" >> "Tapestry PeriodicExecutor": >> waiting for ownable synchronizer 0x0000000716130940, (a >> java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync), >> which is held by "main" >> >> >> "main": >> at >> >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator.obtainObjectFromCreator(JustInTimeObjectCreator.java:62) >> - waiting to lock <0x000000071554f4a8> (a >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator) >> at >> >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator.createObject(JustInTimeObjectCreator.java:55) >> at $SymbolSource_c9319bed00c.delegate(Unknown Source) >> at $SymbolSource_c9319bed00c.valueForSymbol(Unknown Source) >> at >> >> org.apache.tapestry5.ioc.internal.services.SymbolObjectProvider.provide(SymbolObjectProvider.java:50) >> … >> at >> org.apache.tapestry5.ioc.internal.ModuleImpl$1.invoke(ModuleImpl.java:198) >> at >> >> org.apache.tapestry5.ioc.internal.util.ConcurrentBarrier.withWrite(ConcurrentBarrier.java:139) >> at >> org.apache.tapestry5.ioc.internal.ModuleImpl$2.invoke(ModuleImpl.java:215) >> at >> >> org.apache.tapestry5.ioc.internal.util.ConcurrentBarrier.withRead(ConcurrentBarrier.java:83) >> at >> >> org.apache.tapestry5.ioc.internal.ModuleImpl.findOrCreate(ModuleImpl.java:221) >> at >> >> org.apache.tapestry5.ioc.internal.ModuleImpl.getService(ModuleImpl.java:112) >> >> … >> at >> >> org.apache.tapestry5.ioc.internal.AbstractReloadableObjectCreator.createObject(AbstractReloadableObjectCreator.java:118) >> - locked <0x00000007154d53f8> (a >> >> org.apache.tapestry5.ioc.internal.ReloadableServiceImplementationObjectCreator) >> at $Shared_c9319bed012.delegate(Unknown Source) >> at $Shared_c9319bed012.doFoo(Unknown Source) >> at $Shared_c9319bed00e.doFoo(Unknown Source) >> at de.eddyson.t5.deadlock.OtherImpl.<init>(OtherImpl.java:8) >> … >> at >> >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator.obtainObjectFromCreator(JustInTimeObjectCreator.java:67) >> - locked <0x00000007156584b0> (a >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator) >> at >> >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator.createObject(JustInTimeObjectCreator.java:55) >> at >> >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator.eagerLoadService(JustInTimeObjectCreator.java:88) >> at >> >> org.apache.tapestry5.ioc.internal.RegistryImpl.performRegistryStartup(RegistryImpl.java:357) >> at >> >> org.apache.tapestry5.ioc.internal.RegistryWrapper.performRegistryStartup(RegistryWrapper.java:89) >> >> >> >> "Tapestry PeriodicExecutor": >> at jdk.internal.misc.Unsafe.park(java.base@11.0.8/Native Method) >> - parking to wait for <0x0000000716130940> (a >> java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) >> at >> java.util.concurrent.locks.LockSupport.park(java.base@11.0.8 >> /LockSupport.java:194) >> at >> >> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.8 >> /AbstractQueuedSynchronizer.java:885) >> at >> >> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.base@11.0.8 >> /AbstractQueuedSynchronizer.java:917) >> at >> >> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@11.0.8 >> /AbstractQueuedSynchronizer.java:1240) >> at >> >> java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(java.base@11.0.8 >> /ReentrantReadWriteLock.java:959) >> at >> >> org.apache.tapestry5.ioc.internal.util.ConcurrentBarrier.withWrite(ConcurrentBarrier.java:135) >> at >> org.apache.tapestry5.ioc.internal.ModuleImpl$2.invoke(ModuleImpl.java:215) >> at >> >> org.apache.tapestry5.ioc.internal.util.ConcurrentBarrier.withRead(ConcurrentBarrier.java:83) >> at >> >> org.apache.tapestry5.ioc.internal.ModuleImpl.findOrCreate(ModuleImpl.java:221) >> at >> >> org.apache.tapestry5.ioc.internal.ModuleImpl.getService(ModuleImpl.java:112) >> at >> >> org.apache.tapestry5.ioc.internal.RegistryImpl.getService(RegistryImpl.java:497) >> … >> - locked <0x000000071554f4a8> (a >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator) >> at >> >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator.createObject(JustInTimeObjectCreator.java:55) >> at $SymbolSource_c9319bed00c.delegate(Unknown Source) >> at $SymbolSource_c9319bed00c.valueForSymbol(Unknown Source) >> at >> >> org.apache.tapestry5.ioc.internal.services.SymbolObjectProvider.provide(SymbolObjectProvider.java:50) >> … >> at >> >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator.obtainObjectFromCreator(JustInTimeObjectCreator.java:67) >> - locked <0x000000071548fd68> (a >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator) >> at >> >> org.apache.tapestry5.ioc.internal.services.JustInTimeObjectCreator.createObject(JustInTimeObjectCreator.java:55) >> at $ParallelExecutor_c9319bed010.delegate(Unknown Source) >> at $ParallelExecutor_c9319bed010.invoke(Unknown Source) >> at >> >> org.apache.tapestry5.ioc.internal.services.cron.PeriodicExecutorImpl$Job.start(PeriodicExecutorImpl.java:181) >> at >> >> org.apache.tapestry5.ioc.internal.services.cron.PeriodicExecutorImpl.executeCurrentBatch(PeriodicExecutorImpl.java:382) >> at >> >> org.apache.tapestry5.ioc.internal.services.cron.PeriodicExecutorImpl.run(PeriodicExecutorImpl.java:315) >> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: users-unsubscr...@tapestry.apache.org >> For additional commands, e-mail: users-h...@tapestry.apache.org >> >> > > -- > Thiago > -- Thiago
