You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@netbeans.apache.org by GitBox <gi...@apache.org> on 2022/06/26 04:24:15 UTC

[GitHub] [netbeans] mbien commented on pull request #4284: php test performance

mbien commented on PR #4284:
URL: https://github.com/apache/netbeans/pull/4284#issuecomment-1166414931

   in case anyone is curious how i found this:
   1) filtered the log with a shell script to find the top 10 slowest tests, started with the slowest
   2) while looking at async-profiler flamegraphs and VisualVM GC graphs, I noticed that the CPU use was unusually low (basically idle!)
   3) now I measured setup and teardown time and found an unusual pattern:
   ```
       [junit] setup: 0.773
       [junit] teardown: 0.502
       [junit] setup: 0.828
       [junit] teardown: 0.502
       [junit] setup: 0.827
       [junit] teardown: 0.503
       [junit] setup: 0.835
       [junit] teardown: 0.503
   ...
   ```
   500 ms looked very suspicious -> it had to be an artificial delay.
   
   4) Finding it was not easy though. The integration tests are synced via keywords in loggers with the NB instance, involving multiple threads and countdown latches - so flamegraphs of locks or thread diagrams didn't help - all I saw were threads waiting for something. It did also not help that i looked in the wrong area at first (RequestProcessor itself). At some point I started to search for "500" while debugging and found this in the event system code:
   
   https://github.com/apache/netbeans/blob/c084119009d2e0f736f225d706bc1827af283501/ide/parsing.indexing/src/org/netbeans/modules/parsing/impl/indexing/PathRegistry.java#L958-L963
   
   which is used to debounce events during api call bursts (and everything waited for this event). I set it to 0 and:
   ```
       [junit] setup: 0.21
       [junit] teardown: 0.001
       [junit] setup: 0.229
       [junit] teardown: 0.001
       [junit] setup: 0.223
       [junit] teardown: 0.001
       [junit] setup: 0.229
       [junit] teardown: 0.001
   ...
   ```
   Done. -1s per test method (the test has 463 methods!). This made the test run 5x faster, and apparently reduced the total from >2h to <1h since many other tests were also affected.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@netbeans.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscribe@netbeans.apache.org
For additional commands, e-mail: notifications-help@netbeans.apache.org

For further information about the NetBeans mailing lists, visit:
https://cwiki.apache.org/confluence/display/NETBEANS/Mailing+lists