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

Reply via email to