Fw: throwing static exceptions sometimes VERY slow!

Thu Mar 2 00:04:41 UTC 2017

+hotspot dev as it got dropped

On Wed, Mar 1, 2017 at 7:03 PM Vitaly Davidovich <vitalyd at gmail.com> wrote:

> Instead of overriding fillInStacktrace, which is a synchronized method and
> you're sharing those instances between threads, can you construct the
> Continue and Break exceptions telling base class that you don't want
> writable stacktrace?
>
> The jitter you're seeing could be lock contention due to above, biased
> lock revocation, JIT deoptimizations (although in your Test I'm not sure if
> it'll deoptimize since the throws are not uncommon).
>
> You can add -XX:+PrintSafepointStatistics
> -XX:PrintSafepointStatisticsCount=1 to get reasons for  safepoints printed
> to stdout.
>
> As mentioned, run your test with -XX:+PrintCompilation to see if JIT is
> doing something.
>
> On Wed, Mar 1, 2017 at 7:52 AM Wieland, Jacob <Jacob.Wieland at spirent.com>
> wrote:
>
>
>
>
> sorry, forgot the attachment
>
>
> BR
>
>
>
> *Dr. Jacob Wieland*
>
> *Senior Software Engineer*
>
> main    +49.30.7261919.34
>
> mobile +49.173.6446443
>
>
> jacob.wieland at spirent.com
>
>
> www.spirent.com
>
>
>
>
> Follow us on:
>
>
> Spirent Communications
>
> <https://www.linkedin.com/company/spirent-communications>
> <https://www.linkedin.com/company/spirent-communications>|
> <https://twitter.com/Spirent> <https://twitter.com/Spirent>|
> <https://www.facebook.com/spirent> <https://www.facebook.com/spirent>
>
>
> Michaelkirchstraße 17/18
>
> 10179 Berlin, Germany
>
>
>
> *+++++  N E W S F L A S H  +++++*
>
>
>
> Spirent Communications and Testing Technologies join forces to become your
> test automation power-house. Read more at http://conta.cc/1S62BEY.
>
> ------------------------------
> *From:* Wieland, Jacob
> *Sent:* Wednesday, March 1, 2017 1:47:52 PM
> *To:* Vitaly Davidovich; David Holmes
> *Cc:* hotspot-dev at openjdk.java.net
>
> *Subject:* Re: throwing static exceptions sometimes VERY slow!
>
> Hi,
>
>
> here are the general system infos:
>
>
> uname -a:
>
>
> Linux ber-28753 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u3
> (2016-01-17) x86_64 GNU/Linux
>
>
> lscpu:
>
>
> Architecture:          x86_64
> CPU op-mode(s):        32-bit, 64-bit
> Byte Order:            Little Endian
> CPU(s):                4
> On-line CPU(s) list:   0-3
> Thread(s) per core:    1
> Core(s) per socket:    4
> Socket(s):             1
> NUMA node(s):          1
> Vendor ID:             GenuineIntel
> CPU family:            6
> Model:                 58
> Model name:            Intel(R) Core(TM) i5-3450 CPU @ 3.10GHz
> Stepping:              9
> CPU MHz:               2094.558
> CPU max MHz:           3500.0000
> CPU min MHz:           1600.0000
> BogoMIPS:              6186.30
> Virtualization:        VT-x
> L1d cache:             32K
> L1i cache:             32K
> L2 cache:              256K
> L3 cache:              6144K
> NUMA node0 CPU(s):     0-3
>
> java -version:
>
>
> java version "1.8.0_102"
> Java(TM) SE Runtime Environment (build 1.8.0_102-b14)
> Java HotSpot(TM) 64-Bit Server VM (build 25.102-b14, mixed mode)
>
> Rest of the answers inline.
>
> BR
>
>
>
> *Dr. Jacob Wieland*
>
> *Senior Software Engineer*
>
> main    +49.30.7261919.34
>
> mobile +49.173.6446443
>
>
> jacob.wieland at spirent.com
>
>
> www.spirent.com
>
>
>
>
> Follow us on:
>
>
> Spirent Communications
>
> <https://www.linkedin.com/company/spirent-communications>
> <https://www.linkedin.com/company/spirent-communications>|
> <https://twitter.com/Spirent> <https://twitter.com/Spirent>|
> <https://www.facebook.com/spirent> <https://www.facebook.com/spirent>
>
>
> Michaelkirchstraße 17/18
>
> 10179 Berlin, Germany
>
>
>
> *+++++  N E W S F L A S H  +++++*
>
>
>
> Spirent Communications and Testing Technologies join forces to become your
> test automation power-house. Read more at http://conta.cc/1S62BEY.
>
> ------------------------------
> *From:* Vitaly Davidovich <vitalyd at gmail.com>
> *Sent:* Tuesday, February 28, 2017 1:46:09 PM
> *To:* David Holmes
> *Cc:* Wieland, Jacob; hotspot-dev at openjdk.java.net
> *Subject:* Re: throwing static exceptions sometimes VERY slow!
>
>
>
> On Tue, Feb 28, 2017 at 7:37 AM, David Holmes <david.holmes at oracle.com>
> wrote:
>
> Hi,
>
> On 28/02/2017 9:02 PM, Wieland, Jacob wrote:
>
> Hi,
>
> I am observing a very strange behavior.
>
> In our generated code (due to various reasons I won't go into here unless
> I have to, but trust me, they are legit), we throw static exceptions for
> control flow purposes, This seems to work fine and without performance loss
> most of the time. However, we are observing now that every few seconds, a
> throw sometimes takes up between 1,5 and 2.5 seconds! (in contrast to the
> normal almost non-measurable time).
>
> Update: it seems that the observed behavior was kind of related with some
> extraneous circumstances (the computer seems to have been more lagged than
> usual at that point). By now, I can only observe throws that take up to 20
> milliseconds (which opposed to the normal time still seems slow).
>
> It does not seem to be GC related, the only idea that I have is the jitter.
>
>
> What jitter?
>
> I'm assuming Jacob is referring to the JIT.  But yes, he needs to provide
> more information.
>
> In particular, it would be good to know the following, as David mentioned,
> (off the top of my head):
> 1) JVM cmdline flags
>
> -Xdebug -Xrunjdwp:transport=dt_socket,address=8001,server=y,suspend=y
>
> 2) Type of exception thrown (with a stacktrace or not)
>
> Exception class derived from java.lang.Error that overrides
> fillInStackTrace() with 'return this', so stackless. Same instances stored
> in static final fields are always thrown.
>
> 3) Is the call stack depth about the same during the slow and fast throws?
>
> It is always exactly the same stack, as it happens in a loop.
>
> 4) Is the exception thrown frequently or infrequently?
>
> In the test where this was observed, the exception was thrown every 40ms,
> so, I guess, frequently.
>
> 5) Is there -XX:+PrintCompilation output available around the time when
> the slowdown is observed
>
> Unfortunately not, and at the moment, I cannot reproduce the behavior.
>
> I made a mockup-test (see attachment) that mimicks kind of what my
> generated code does and adds measurements before throw and after catch.
> Mostly, in my experiments with this, the throw takes on average 20 ns,
> but between a 1 and 3 per million iterations take longer than 1 ms, on
> average around 7 ms. It can be observed that doing a garbage collection in
> a different java process (namely my eclipse that started the test) greatly
> influences the frequency of the > 1 ms throws, so maybe it is simply a load
> issue. Using multiple threads in parallel also seems to heighten the
>
> Also, when introducing an additional sleep between iterations (like in my
> original scenario where I was waiting for a timer to timeout before
> executing the construct that used the throw), I cannot reproduce such
> outliers at all.
>
>
>
> So, my question is. Is this a known (and for some strange reason maybe
> even accepted) behavior or is this a bug that I should file with Oracle (or
> you guys).
>
>
> You really are not giving us anything to go on here. How are you observing
> this slowness? Exactly how do you throw? What exactly are you measuring?
> What's the execution context, the machine, processors etc etc etc.
>
>
> I was observing the slowness in a testcase where I wanted regular
> intervals of 40 ms between sending a message via UDP but frequently (every
> few seconds) got a lag of around 1.5 seconds (and a few days later 0.5
> seconds) before the timer which timed out at the correct time was noted.
>
>
> When eliminating one kind of such thrown control exception, the next kind
> of thrown control exception (from a surrounding construct) was having the
> same effect which actually led me to the slow-throw-hypothesis. Eliminating
> all exceptions in the small example confirmed this hypothesis, but going
> that route would take a lot of effort for all cases and introduce other
> additional imperformances (as I basically have to mock the exception
> throwing via cascading return and if-checks on every level) which I would
> like to avoid.
>
> Regards,
> David
>
>
>
>
>
> Spirent Communications e-mail confidentiality.
> ------------------------------------------------------------------------
> This e-mail contains confidential and / or privileged information
> belonging to Spirent Communications plc, its affiliates and / or
> subsidiaries. If you are not the intended recipient, you are hereby
> notified that any disclosure, copying, distribution and / or the taking of
> any action based upon reliance on the contents of this transmission is
> strictly forbidden. If you have received this message in error please
> notify the sender by return e-mail and delete it from your system.
>
> Spirent Communications plc
> Northwood Park, Gatwick Road, Crawley, West Sussex, RH10 9XN, United
> Kingdom.
> Tel No. +44 (0) 1293 767676
> Fax No. +44 (0) 1293 767677
>
> Registered in England Number 470893
> Registered at Northwood Park, Gatwick Road, Crawley, West Sussex, RH10
> 9XN, United Kingdom.
>
> Or if within the US,
>
> Spirent Communications,
> 27349 Agoura Road, Calabasas, CA, 91301, USA.
> Tel No. 1-818-676- 2300
>
> --
> Sent from my phone
>
-- 
Sent from my phone