Strange STW pauses

[Kirk Pepperdine]

Hi Nick,

Is this a regular occurrence? The pauses can come from many sources including the OS. They are generally a result of a build up of maintenance work recycling a non-shareable resource and thus if you can understand what that resource is, you can understand how your application is putting undo pressure in it and possibly make adjustments. Common sources of long pauses are garbage collection in the JVM and page reclamation at the OS level. GC logs can speak to the GC issue where as you’ll need the OS performance counters to help you understand paging behavior. But do be careful as more often than not, the garbage collector takes the blame for the page reclamation activity. Do collect the GC logs with PrintGCDetails and PrintGCApplicationStoppedTime turned on and post it here or send it to me off list if you like

Kind regards,
Kirk

> On Aug 23, 2017, at 12:52 AM, Nick Chadwick <nick.chadwick at nichesolutions.co.uk> wrote:
> 
> Hi,
> 
> My Java application is suffering from long (5s+) STW pauses. Latency is a
> priority for the application, so I need to get to the bottom of what's going
> on.
> 
> With all the usual JVM options on, I see the following in the logs:
> 
> [deflating idle monitors, 0.0000102 secs]
> [updating inline caches, 0.0000149 secs]
> [compilation policy safepoint handler, 0.0000005 secs]
> [mark nmethods, 0.0000549 secs]
> [purging class loader data graph, 0.0000002 secs]
>         vmop                    [threads: total initially_running
> wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
> 915.696: no vm operation                  [      24          1             
> 1    ]      [     0     0  7303     0     0    ]  1
> Total time for which application threads were stopped: 0.0002608 seconds,
> Stopping threads took: 0.0001250 seconds
> 
> [deflating idle monitors, 0.0000110 secs]
> [updating inline caches, 0.0000706 secs]
> [compilation policy safepoint handler, 0.0000006 secs]
> [mark nmethods, 0.0000576 secs]
> [purging class loader data graph, 0.0000003 secs]
>         vmop                    [threads: total initially_running
> wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
> 1051.564: no vm operation                  [      24          0             
> 1    ]      [     0     0  1652     0     0    ]  0
> Total time for which application threads were stopped: 0.0002285 seconds,
> Stopping threads took: 0.0000414 seconds
> 
> [deflating idle monitors, 0.0000135 secs]
> [updating inline caches, 0.0000083 secs]
> [compilation policy safepoint handler, 0.0000005 secs]
> [mark nmethods, 0.0000894 secs]
> [purging class loader data graph, 0.0000002 secs]
>         vmop                    [threads: total initially_running
> wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
> 1056.223: no vm operation                  [      24          0             
> 0    ]      [     0     0     0  5704     0    ]  0
> Total time for which application threads were stopped: 5.7042454 seconds,
> Stopping threads took: 0.0000270 seconds
> 
> [deflating idle monitors, 0.0000116 secs]
> [updating inline caches, 0.0000093 secs]
> [compilation policy safepoint handler, 0.0000005 secs]
> [mark nmethods, 0.0000540 secs]
> [purging class loader data graph, 0.0000001 secs]
>         vmop                    [threads: total initially_running
> wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
> 1756.475: no vm operation                  [      24          0             
> 0    ]      [     0     0     0  4402     0    ]  0
> Total time for which application threads were stopped: 4.4023833 seconds,
> Stopping threads took: 0.0000268 seconds
> 
> I've done some reading up, here and elsewhere, on "guaranteed safepoints"
> etc, but am stumped as to what it's spending its time doing.
> 
> Please can anyone give me a clue?
> 
> Thanks,
> Nick
> 
> 
> 
> --
> View this message in context: http://openjdk.5641.n7.nabble.com/Strange-STW-pauses-tp312324.html
> Sent from the OpenJDK Hotspot Runtime System mailing list archive at Nabble.com.