[ https://issues.apache.org/jira/browse/LUCENE-9185?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17025074#comment-17025074 ]
Dawid Weiss commented on LUCENE-9185: ------------------------------------- Great beyond words. I never had a chance to use jfr but I'll surely want to dig. A few nitpicks: {code} +allprojects { + tasks.withType(Test) { + def profileMode = propertyOrDefault("tests.profile", false) + if (profileMode) { {code} you can apply the if outside and only do allprojects closure if tests.profile is true at the root project level (I assume we won't have to enable it for individual projects within a larger build). {code} +gradlew -p lucene/core test -Dtests.profile=true {code} It will work but -Ptests.profile=true would be more gradle-sque (it sets a project property as opposed to system property). {code} +gradle.buildFinished { + if (!recordings.isEmpty()) { + def args = ["ProfileResults"] + for (file in recordings.getFiles()) { + args += file.toString() + } + ProfileResults.main(args as String[]) + } +} {code} If you pull up the if then this thing can go underneath so that it's not adding any closure if it's not enabled. Also: it'll always display the profile, even on a failed build. Look at slowest-tests-at-end.gradle - this one only displays the slowest tests if the build is successful. Finally you may want to simplify to something like (didn't check but should work): {code} def args = ["ProfileResults"] args += recordings.getFiles().collect { it.toString() } {code} > add "tests.profile" to gradle build to aid fixing slow tests > ------------------------------------------------------------ > > Key: LUCENE-9185 > URL: https://issues.apache.org/jira/browse/LUCENE-9185 > Project: Lucene - Core > Issue Type: Task > Reporter: Robert Muir > Priority: Major > Attachments: LUCENE-9185.patch > > > It is kind of a hassle to profile slow tests to fix the bottlenecks > The idea here is to make it dead easy to profile (just) the tests, capturing > samples at a very low granularity, reducing noise as much as possible (e.g. > not profiling entire gradle build or anything) and print a simple report for > quick iterating. > Here's a prototype of what I hacked together: > All of lucene core: {{./gradlew -p lucene/core test -Dtests.profile=true}} > {noformat} > ... > PROFILE SUMMARY from 122464 samples > tests.profile.count=10 > tests.profile.stacksize=1 > tests.profile.linenumbers=false > PERCENT SAMPLES STACK > 2.59% 3170 > org.apache.lucene.util.compress.LZ4$HighCompressionHashTable#assertReset() > 2.26% 2762 java.util.Arrays#fill() > 1.59% 1953 com.carrotsearch.randomizedtesting.RandomizedContext#context() > 1.24% 1523 java.util.Random#nextInt() > 1.19% 1456 java.lang.StringUTF16#compress() > 1.08% 1319 java.lang.StringLatin1#inflate() > 1.00% 1228 java.lang.Integer#getChars() > 0.99% 1214 java.util.Arrays#compareUnsigned() > 0.96% 1179 java.util.zip.Inflater#inflateBytesBytes() > 0.91% 1114 java.util.concurrent.atomic.AtomicLong#compareAndSet() > BUILD SUCCESSFUL in 3m 59s > {noformat} > If you look at this LZ4 assertReset method, you can see its indeed way too > expensive, checking 64K items every time. > To dig deeper into potential problems you can pass additional parameters (all > of them used here for demonstration): > {{./gradlew -p solr/core test --tests TestLRUStatsCache -Dtests.profile=true > -Dtests.profile.count=8 -Dtests.profile.stacksize=20 > -Dtests.profile.linenumbers=true}} > This clearly finds SOLR-14223 (expensive RSA key generation in CryptoKeys) ... > {noformat} > ... > PROFILE SUMMARY from 21355 samples > tests.profile.count=8 > tests.profile.stacksize=20 > tests.profile.linenumbers=true > PERCENT SAMPLES STACK > 26.30% 5617 sun.nio.ch.EPoll#wait():(Native code) > at sun.nio.ch.EPollSelectorImpl#doSelect():120 > at sun.nio.ch.SelectorImpl#lockAndDoSelect():124 > at sun.nio.ch.SelectorImpl#select():141 > at > org.eclipse.jetty.io.ManagedSelector$SelectorProducer#select():472 > at > org.eclipse.jetty.io.ManagedSelector$SelectorProducer#produce():409 > at > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill#produceTask():360 > at > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill#doProduce():184 > at > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill#tryProduce():171 > at > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill#produce():135 > at > org.eclipse.jetty.io.ManagedSelector$$Lambda$235.1914126144#run():(Interpreted > code) > at > org.eclipse.jetty.util.thread.QueuedThreadPool#runJob():806 > at > org.eclipse.jetty.util.thread.QueuedThreadPool$Runner#run():938 > at java.lang.Thread#run():830 > 16.19% 3458 sun.nio.ch.EPoll#wait():(Native code) > at sun.nio.ch.EPollSelectorImpl#doSelect():120 > at sun.nio.ch.SelectorImpl#lockAndDoSelect():124 > at sun.nio.ch.SelectorImpl#select():141 > at > org.eclipse.jetty.io.ManagedSelector$SelectorProducer#select():472 > at > org.eclipse.jetty.io.ManagedSelector$SelectorProducer#produce():409 > at > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill#produceTask():360 > at > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill#doProduce():184 > at > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill#tryProduce():171 > at > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill#produce():135 > at > org.eclipse.jetty.io.ManagedSelector$$Lambda$235.1914126144#run():(Interpreted > code) > at > org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor#lambda$execute$0():210 > at > org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$$Lambda$270.1779693615#run():(Interpreted > code) > at > java.util.concurrent.ThreadPoolExecutor#runWorker():1128 > at > java.util.concurrent.ThreadPoolExecutor$Worker#run():628 > at java.lang.Thread#run():830 > 13.15% 2808 sun.nio.ch.Net#accept():(Native code) > at sun.nio.ch.ServerSocketChannelImpl#accept():276 > at > org.eclipse.jetty.server.ServerConnector#accept():385 > at > org.eclipse.jetty.server.AbstractConnector$Acceptor#run():701 > at > org.eclipse.jetty.util.thread.QueuedThreadPool#runJob():806 > at > org.eclipse.jetty.util.thread.QueuedThreadPool$Runner#run():938 > at java.lang.Thread#run():830 > 2.95% 630 java.math.BigInteger#implMulAdd():3191 > at java.math.BigInteger#mulAdd():3161 > at java.math.BigInteger#montReduce():3110 > at java.math.BigInteger#implMontgomerySquare():2857 > at java.math.BigInteger#montgomerySquare():2813 > at java.math.BigInteger#oddModPow():3083 > at java.math.BigInteger#modPow():2744 > at java.math.BigInteger#passesMillerRabin():1103 > at java.math.BigInteger#primeToCertainty():959 > at java.math.BitSieve#retrieve():203 > at java.math.BigInteger#largePrime():828 > at java.math.BigInteger#probablePrime():766 > at > sun.security.rsa.RSAKeyPairGenerator#generateKeyPair():140 > at > java.security.KeyPairGenerator$Delegate#generateKeyPair():728 > at java.security.KeyPairGenerator#genKeyPair():495 > at > org.apache.solr.util.CryptoKeys$RSAKeyPair#<init>():342 > at > org.apache.solr.security.PublicKeyHandler#<init>():27 > at org.apache.solr.core.CoreContainer#<init>():336 > at org.apache.solr.core.CoreContainer#<init>():326 > at > org.apache.solr.servlet.SolrDispatchFilter#createCoreContainer():261 > 2.74% 586 java.math.BigInteger#implMulAdd():3194 > at java.math.BigInteger#mulAdd():3161 > at java.math.BigInteger#montReduce():3110 > at java.math.BigInteger#implMontgomerySquare():2857 > at java.math.BigInteger#montgomerySquare():2813 > at java.math.BigInteger#oddModPow():3083 > at java.math.BigInteger#modPow():2744 > at java.math.BigInteger#passesMillerRabin():1103 > at java.math.BigInteger#primeToCertainty():959 > at java.math.BitSieve#retrieve():203 > at java.math.BigInteger#largePrime():828 > at java.math.BigInteger#probablePrime():766 > at > sun.security.rsa.RSAKeyPairGenerator#generateKeyPair():140 > at > java.security.KeyPairGenerator$Delegate#generateKeyPair():728 > at java.security.KeyPairGenerator#genKeyPair():495 > at > org.apache.solr.util.CryptoKeys$RSAKeyPair#<init>():342 > at > org.apache.solr.security.PublicKeyHandler#<init>():27 > at org.apache.solr.core.CoreContainer#<init>():336 > at org.apache.solr.core.CoreContainer#<init>():326 > at > org.apache.solr.servlet.SolrDispatchFilter#createCoreContainer():261 > 2.21% 472 java.math.BigInteger#implMulAdd():3191 > at java.math.BigInteger#mulAdd():3161 > at java.math.BigInteger#montReduce():3110 > at java.math.BigInteger#implMontgomerySquare():2857 > at java.math.BigInteger#montgomerySquare():2813 > at java.math.BigInteger#oddModPow():3083 > at java.math.BigInteger#modPow():2744 > at java.math.BigInteger#passesMillerRabin():1103 > at java.math.BigInteger#primeToCertainty():959 > at java.math.BitSieve#retrieve():203 > at java.math.BigInteger#largePrime():828 > at java.math.BigInteger#probablePrime():766 > at > sun.security.rsa.RSAKeyPairGenerator#generateKeyPair():137 > at > java.security.KeyPairGenerator$Delegate#generateKeyPair():728 > at java.security.KeyPairGenerator#genKeyPair():495 > at > org.apache.solr.util.CryptoKeys$RSAKeyPair#<init>():342 > at > org.apache.solr.security.PublicKeyHandler#<init>():27 > at org.apache.solr.core.CoreContainer#<init>():336 > at org.apache.solr.core.CoreContainer#<init>():326 > at > org.apache.solr.servlet.SolrDispatchFilter#createCoreContainer():261 > 1.93% 412 java.math.BigInteger#implMulAdd():3194 > at java.math.BigInteger#mulAdd():3161 > at java.math.BigInteger#montReduce():3110 > at java.math.BigInteger#implMontgomerySquare():2857 > at java.math.BigInteger#montgomerySquare():2813 > at java.math.BigInteger#oddModPow():3083 > at java.math.BigInteger#modPow():2744 > at java.math.BigInteger#passesMillerRabin():1103 > at java.math.BigInteger#primeToCertainty():959 > at java.math.BitSieve#retrieve():203 > at java.math.BigInteger#largePrime():828 > at java.math.BigInteger#probablePrime():766 > at > sun.security.rsa.RSAKeyPairGenerator#generateKeyPair():137 > at > java.security.KeyPairGenerator$Delegate#generateKeyPair():728 > at java.security.KeyPairGenerator#genKeyPair():495 > at > org.apache.solr.util.CryptoKeys$RSAKeyPair#<init>():342 > at > org.apache.solr.security.PublicKeyHandler#<init>():27 > at org.apache.solr.core.CoreContainer#<init>():336 > at org.apache.solr.core.CoreContainer#<init>():326 > at > org.apache.solr.servlet.SolrDispatchFilter#createCoreContainer():261 > 1.40% 299 java.math.BigInteger#implMulAdd():3194 > at java.math.BigInteger#mulAdd():3161 > at java.math.BigInteger#implSquareToLen():2185 > at java.math.BigInteger#squareToLen():2105 > at java.math.BigInteger#implMontgomerySquare():2856 > at java.math.BigInteger#montgomerySquare():2813 > at java.math.BigInteger#oddModPow():3083 > at java.math.BigInteger#modPow():2744 > at java.math.BigInteger#passesMillerRabin():1103 > at java.math.BigInteger#primeToCertainty():959 > at java.math.BitSieve#retrieve():203 > at java.math.BigInteger#largePrime():828 > at java.math.BigInteger#probablePrime():766 > at > sun.security.rsa.RSAKeyPairGenerator#generateKeyPair():140 > at > java.security.KeyPairGenerator$Delegate#generateKeyPair():728 > at java.security.KeyPairGenerator#genKeyPair():495 > at > org.apache.solr.util.CryptoKeys$RSAKeyPair#<init>():342 > at > org.apache.solr.security.PublicKeyHandler#<init>():27 > at org.apache.solr.core.CoreContainer#<init>():336 > at org.apache.solr.core.CoreContainer#<init>():326 > BUILD SUCCESSFUL in 39s > {noformat} -- This message was sent by Atlassian Jira (v8.3.4#803005) --------------------------------------------------------------------- To unsubscribe, e-mail: issues-unsubscr...@lucene.apache.org For additional commands, e-mail: issues-h...@lucene.apache.org