FWD » Core Development » Conversion Tools

While testing the latest trunk with changes from #3211, I saw several times threads blocking on public static synchronized int lookupTokenType(String tokenName) from ProgressParser. This is quite important as it is called by BinaryAstCodec.readNode. When I did a thread dump for a conversion with 16 threads, most of them were loading ASTs with BinaryAstCodec. As loading means looking up token types, the lookupTokenType made the threads constantly wait for the monitor at each token read.

Why would lookupTokenType be syncrhonized. I understand that tokenLookup is lazily computed, but it is computed only once, as it is a static collection. After that, all threads need to read from that map without contention. Currently they block each other when reading from tokenLookup.

Can we compute lookupTokenType only once at the bootstrap time and eliminate the synchronized when looking up token type? It is the only synchronization inside ProgressParser AFAIK.

I would expect to be a quick fix for a large gain.

I've committed the change in 11317a/16735.

Alex, please review. I have tested it with Hotel_GUI so far.

Review of 11317a:

• I am OK with the changes.

Please run a large customer application to check if there is any visible performance improvement and regression test at the same time. IMHO, it is a (very) safe change, so one large application test should be enough.

Please merge 11317a to trunk now.

Branch 11317a was merged into trunk as rev. 16753 and archived.

Moved back to WIP and 0% Done for the rest of the work that needs to be done.

Octavian, I am still running trunk/16749, but I found a similar problem that might not be assessed by 11317a:

I am not entirely sure what was the phase the is being run when this was captured. On a thread dump, I see:

"Conversion-Thread-2" #36 prio=5 os_prio=0 cpu=74657,68ms elapsed=169,18s tid=0x00007542d5f87e30 nid=0xe4a2 waiting on condition  [0x00007542363f2000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base@17.0.20/Native Method)
        - parking to wait for  <0x000000042080fec8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(java.base@17.0.20/LockSupport.java:211)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@17.0.20/AbstractQueuedSynchronizer.java:715)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@17.0.20/AbstractQueuedSynchronizer.java:938)
        at java.util.concurrent.locks.ReentrantLock$Sync.lock(java.base@17.0.20/ReentrantLock.java:153)
        at java.util.concurrent.locks.ReentrantLock.lock(java.base@17.0.20/ReentrantLock.java:322)
        at com.goldencode.ast.XmlFilePlugin.loadTree(XmlFilePlugin.java:287)
        at com.goldencode.ast.AstManager.loadTree(AstManager.java:373)
        at com.goldencode.p2j.pattern.AstSymbolResolver.loadTree(AstSymbolResolver.java:362)
        at com.goldencode.p2j.pattern.AstSymbolResolver.getAst(AstSymbolResolver.java:417)
        at com.goldencode.p2j.pattern.CommonAstSupport$Library.getAst(CommonAstSupport.java:1653)
        at com.goldencode.p2j.pattern.CommonAstSupport$Library.getAst(CommonAstSupport.java:1635)
        at com.goldencode.expr.CE904.execute(Unknown Source)
        at com.goldencode.expr.Expression.execute(Expression.java:410)
        at com.goldencode.p2j.pattern.Rule.apply(Rule.java:501)
        at com.goldencode.p2j.pattern.Rule.executeActions(Rule.java:792)
        at com.goldencode.p2j.pattern.Rule.coreProcessing(Rule.java:758)
        at com.goldencode.p2j.pattern.Rule.apply(Rule.java:538)
        at com.goldencode.p2j.pattern.RuleContainer.apply(RuleContainer.java:665)
        at com.goldencode.p2j.pattern.AstWalker.walk(AstWalker.java:262)
        at com.goldencode.p2j.pattern.AstWalker.walk(AstWalker.java:210)
        at com.goldencode.p2j.pattern.PatternEngine.apply(PatternEngine.java:1834)
        at com.goldencode.p2j.pattern.PatternEngine.processAst(PatternEngine.java:1718)
        at com.goldencode.p2j.pattern.AstProcessorJob.run(AstProcessorJob.java:255)
        at com.goldencode.p2j.pattern.AstProcessorThread.run(AstProcessorThread.java:140)

   Locked ownable synchronizers:
        - None

"Conversion-Thread-3" #37 prio=5 os_prio=0 cpu=75887,58ms elapsed=169,18s tid=0x00007542d5f07cb0 nid=0xe4a3 waiting on condition  [0x00007542888f4000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base@17.0.20/Native Method)
        - parking to wait for  <0x000000042080fec8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(java.base@17.0.20/LockSupport.java:211)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@17.0.20/AbstractQueuedSynchronizer.java:715)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@17.0.20/AbstractQueuedSynchronizer.java:938)
        at java.util.concurrent.locks.ReentrantLock$Sync.lock(java.base@17.0.20/ReentrantLock.java:153)
        at java.util.concurrent.locks.ReentrantLock.lock(java.base@17.0.20/ReentrantLock.java:322)
        at com.goldencode.ast.XmlFilePlugin.loadTree(XmlFilePlugin.java:287)
        at com.goldencode.ast.AstManager.loadTree(AstManager.java:373)
        at com.goldencode.p2j.pattern.AstSymbolResolver.loadTree(AstSymbolResolver.java:362)
        at com.goldencode.p2j.pattern.AstSymbolResolver.getAst(AstSymbolResolver.java:417)
        at com.goldencode.p2j.pattern.CommonAstSupport$Library.getAst(CommonAstSupport.java:1653)
        at com.goldencode.p2j.pattern.CommonAstSupport$Library.getAst(CommonAstSupport.java:1635)
        at com.goldencode.expr.CE904.execute(Unknown Source)
        at com.goldencode.expr.Expression.execute(Expression.java:410)
        at com.goldencode.p2j.pattern.Rule.apply(Rule.java:501)
        at com.goldencode.p2j.pattern.Rule.executeActions(Rule.java:792)
        at com.goldencode.p2j.pattern.Rule.coreProcessing(Rule.java:758)
        at com.goldencode.p2j.pattern.Rule.apply(Rule.java:538)
        at com.goldencode.p2j.pattern.RuleContainer.apply(RuleContainer.java:665)
        at com.goldencode.p2j.pattern.AstWalker.walk(AstWalker.java:262)
        at com.goldencode.p2j.pattern.AstWalker.walk(AstWalker.java:210)
        at com.goldencode.p2j.pattern.PatternEngine.apply(PatternEngine.java:1834)
        at com.goldencode.p2j.pattern.PatternEngine.processAst(PatternEngine.java:1718)
        at com.goldencode.p2j.pattern.AstProcessorJob.run(AstProcessorJob.java:255)
        at com.goldencode.p2j.pattern.AstProcessorThread.run(AstProcessorThread.java:140)

   Locked ownable synchronizers:
        - None

So, again, there seems to be a contention on AST loading. The locks are delivered by:

 ReentrantLock lock = LOCK_CACHE.computeIfAbsent(artifact.getRelativePath(), k -> new ReentrantLock());

• It is weird why all threads want the same artifact almost at the same time. Maybe they require schema p2o (that are only very few).
• The whole situation takes ~4 minutes in a conversion of 20 minutes. After these 4 minutes, another phase kicks in and it works fast again.

However, after around 10 minutes in which all threads are working in parallel, I face this issue again:

On thread dumps I see the same stack traces.

I was wondering why we would need to synchronize the loading of these ASTs? From the looks of it, the process is immutable so it doesn't need synchronization. The same locks are shared indeed with saveTree and persist, but I guess we can use a ReadWriteReentrantLock instead to allow concurrent reads.

As a side idea, I wonder if we can keep a static cache of ASTs to be reused directly from memory. So, instead of flushing to disk and reading again, to have a small cache in-memory to keep the most used ASTs (schema ASTs I suppose are one of them, but super-classes used anywhere can fit as well). We need to avoid thrashing such cache with one-time asts, so maybe we can also persist a "hit count" and if the hit count exceeds a threshold to also save the ASTs in a memory registry.