Too much safepoint logging in info level?

[Stefan Karlsson]

Hi Sundar,

FWIW, those log lines were removed in JDK 13. See:
https://bugs.openjdk.java.net/browse/JDK-8219436

According to the bug report: "All logs should use the same timestamp and 
some logs are not meaningful."

On 2019-06-22 01:03, Sundara Mohan M wrote:
> Hi All,
>      I am seeing following behavior when gc log is set at info level.
> 
> In JDK8 we used to see only Application stopped time and Time taken to stop
> time in logs.
> In JDK12 i am seeing additional lines Entering and Leaving safepoints are
> printed at info level.
> This seems to fill logs very quickly and also doesn't help much at high
> level.
> 
> Is there a compelling reason that it has to be at info level? If not can we
> look at moving it to debug level?
> 
> [2019-06-21T22:47:33.638+0000][2.495s][info][safepoint] Application time:
> 0.0092823 seconds
> 
> *[2019-06-21T22:47:33.638+0000][2.495s][info][safepoint] Entering safepoint
> region: ZOperation*[2019-06-21T22:47:33.640+0000][2.496s][info][gc,phases]
> GC(0) Pause Mark End 1.506ms
> 
> *[2019-06-21T22:47:33.640+0000][2.496s][info][safepoint] Leaving safepoint
> region*
> [2019-06-21T22:47:33.640+0000][2.496s][info][safepoint] Total time for
> which application threads were stopped: 0.0016777 seconds, Stopping threads
> took: 0.0000301 seconds
> ...
> [2019-06-21T22:47:33.656+0000][2.513s][info][safepoint] Application time:
> 0.0166108 seconds
> 
> *[2019-06-21T22:47:33.656+0000][2.513s][info][safepoint] Entering safepoint
> region: ZOperation*[2019-06-21T22:47:33.657+0000][2.513s][info][gc,phases]
> GC(0) Pause Mark End 0.264ms
> *[2019-06-21T22:47:33.657+0000][2.513s][info][safepoint] Leaving safepoint
> region*
> [2019-06-21T22:47:33.657+0000][2.513s][info][safepoint] Total time for
> which application threads were stopped: 0.0004208 seconds, Stopping threads
> took: 0.0000272 seconds
> ...
> 
> 
> Sorry if this is not the correct forum for this topic. Please point me to
> the correct forum.
> 
> TIA
> - Sundar
>