Error in TraceCPUTime in gc log

[Jon Masamitsu]

That message indicates that the call to times(2) returned a -1
instead of the values for the current time.    The linux times(2) man
page I'm reading says that it can happen when the return
value wraps.

> BUGS
>        A limitation of the Linux system call conventions on some 
> architectures
>        (notably i386) means that on Linux 2.6 there is a small time 
> window (41
>        seconds) soon after boot when times() can return -1, falsely 
> indicating
>        that an error occurred.  The same problem can  occur  when the  
> return
>        value wraps passed the maximum value that can be stored in clock_t.

Does that sound like what could be happening?

Jon

On 3/5/2014 5:25 AM, Vladimir Sitnikov wrote:
> Hello,
>
> I've installed java 1.7.0_51 to my Synology NAS (ds413j) and it turns 
> out gc log shows Error in TraceCPUTime.
>
> Can you please clarify why Error in TraceCPUTime happens and what is 
> the way to eliminate it?
> The error appear from time to time, and typically gc log prints 
> meaningful times (user, sys, real)
>
> Relevant startup arguments are: -Xms20m -Xmx384m -Xloggc:/.../gc.log 
> -XX:+PrintGCDetails -XX:+PrintGCDateStamps
>
> Here's extract from gc log:
>
> 2014-03-05T09:03:31.739+0000: 67.290: [GC2014-03-05T09:03:31.740+0000: 
> 67.290: [DefNew: 5760K->639K(6400K), 0.0391810 secs] 
> 12413K->8398K(20096K), 0.0395380 secs] [Times: user=0.04 sys=0.00, 
> real=0.04 secs]
> 2014-03-05T09:03:33.971+0000: 69.521: [GC2014-03-05T09:03:33.971+0000: 
> 69.521: [DefNew: 6399K->639K(6400K), 0.0483430 secs] 
> 14158K->10024K(20096K), 0.0486930 secs][Error in TraceCPUTime]
> 2014-03-05T09:03:36.220+0000: 71.770: [GC2014-03-05T09:03:36.220+0000: 
> 71.770: [DefNew: 6399K->639K(6400K), 0.0434850 secs] 
> 15784K->11383K(20096K), 0.0438150 secs][Error in TraceCPUTime]
> 2014-03-05T09:03:38.709+0000: 74.259: [GC2014-03-05T09:03:38.709+0000: 
> 74.259: [DefNew: 6399K->639K(6400K), 0.0485340 secs] 
> 17143K->12902K(20096K), 0.0488690 secs][Error in TraceCPUTime]
> 2014-03-05T09:03:41.089+0000: 76.639: [GC2014-03-05T09:03:41.089+0000: 
> 76.640: [DefNew: 4619K->475K(6400K), 0.0295340 secs] 
> 16882K->13280K(20096K), 0.0298930 secs][Error in TraceCPUTime]
> 2014-03-05T09:03:41.147+0000: 76.698: [GC2014-03-05T09:03:41.147+0000: 
> 76.698: [DefNew: 4871K->8K(6400K), 0.0260880 
> secs]2014-03-05T09:03:41.173+0000: 76.724: [Tenured: 
> 17299K->9531K(18056K), 0.3326210 secs] 17676K->9531K(24456K), [Perm : 
> 15271K->15271K(15360K)], 0.3594560 secs][Error in TraceCPUTime]
> 2014-03-05T09:03:42.129+0000: 77.679: [GC2014-03-05T09:03:42.129+0000: 
> 77.679: [DefNew: 6653K->677K(7424K), 0.0307960 secs] 
> 16184K->12512K(23312K), 0.0311450 secs][Error in TraceCPUTime]
> 2014-03-05T09:03:42.725+0000: 78.276: [GC2014-03-05T09:03:42.725+0000: 
> 78.276: [DefNew: 5128K->768K(7424K), 0.0334390 secs] 
> 16963K->15077K(23312K), 0.0337950 secs][Error in TraceCPUTime]
> 2014-03-05T09:03:43.519+0000: 79.069: [GC2014-03-05T09:03:43.519+0000: 
> 79.069: [DefNew: 7424K->590K(7424K), 0.0361830 
> secs]2014-03-05T09:03:43.555+0000: 79.106: [Tenured: 
> 18740K->19055K(19712K), 0.3247280 secs] 21733K->19055K(27136K), [Perm 
> : 15581K->15581K(15616K)], 0.3616160 secs][Error in TraceCPUTime]
>
> Here are the versions being used:
>
> DiskStation> uname -a
>
> Linux DiskStation 2.6.32.12 #3827 Tue Feb 11 19:48:33 CST 2014 
> armv5tel GNU/Linux
>
> DiskStation> java -version
> java version "1.7.0_51"
> Java(TM) SE Embedded Runtime Environment (build 1.7.0_51-b13, headless)
> Java HotSpot(TM) Embedded Client VM (build 24.51-b03, mixed mode)
>
> -- 
> Regards,
> Vladimir Sitnikov
>
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20140305/82ca8a7b/attachment.html