[
https://issues.apache.org/jira/browse/LUCENE-9185?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17025116#comment-17025116
]
Robert Muir commented on LUCENE-9185:
-------------------------------------
{quote}
Maybe we should make the latter optional as well?
{quote}
Do you mean the whole {{slowest-test-at-end}}? Given how insanely slow some of
these tests are, I feel it should be mandatory to see it? :)
But if i had to ask for a wishlist of improvements to {{slowest-tests-at-end}},
they would be:
* option (or change behavior) to print them always, even if a test sporadically
failed.
* property to increase the count (e.g. from 10 to 100) and threshold (e.g. from
500ms to 250ms, yes we may get there soon in lucene!)
* some way to show or count beforeclass/afterclass time. I'm not sure it is
currently considered, only time for each method (i assume that includes
setup+teardown)
* some way to see the slowest suites, too. Even if we fix all the tests to be
100ms, it can cause bottlenecks if a suite has a TON of tests, because of bad
gradle load balancing.
> 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
