James,
> -----Original Message----- > From: James H. H. Lampert <jam...@touchtonecorp.com> > Sent: Wednesday, February 12, 2020 12:47 PM > To: Tomcat Users List <users@tomcat.apache.org>; Java 400 List <java400- > l...@lists.midrange.com> > Subject: Re: JVM job for Tomcat taking lots and lots of CPU > > I've got some more detailed GC stats. The full report runs 600 pages for just > the last 300 GC cycles, so I've just included three cycles worth of > data: > > > GC Cycle Number : 1801 > > Basic GC Cycle Information: > > Current GC cycle time . . . . . . . : 399 > > GC reason . . . . . . . . . . . . . : Allocation Failure > > GC area . . . . . . . . . . . . . . : None specified > > GC compaction reason . . . . . . . . : None specified > > Number of internal cycles . . . . . : 1 > > Time spent in excessive GC time . . : 0 > > Number of objects moved . . . . . . : 0 > > Amount of space consumed by moved > > objects . . . . . . . . . . . . . : 0 > > Number of classes unloaded . . . . . : 0 > > GC Time Information: > > Cycle start time . . . . . . . . . . : 02/12/20 11:58:08.104 > > Cycle end time . . . . . . . . . . . : 02/12/20 11:58:08.503 > > Mark start time . . . . . . . . . . : 0 > > Mark end time . . . . . . . . . . . : 0 > > Sweep start time . . . . . . . . . . : 0 > > Sweep end time . . . . . . . . . . . : 0 > > Compact start time . . . . . . . . . : 0 > > Compact end time . . . . . . . . . . : 0 > > Nursery Area Information: > > Free space at start . . . . . . . . : 0 > > Allocated space at start . . . . . . : 1179648 > > Total size at start . . . . . . . . : 1179648 > > Free space at end . . . . . . . . . : 1140219 > > Allocated space at end . . . . . . . : 39429 > > Total size at end . . . . . . . . . : 1179648 > > Tenured Area: > > Free space at start . . . . . . . . : 1119550 > > Allocated space at start . . . . . . : 1717250 > > Total size at start . . . . . . . . : 2836800 > > Free space at end . . . . . . . . . : 1087674 > > Allocated space at end . . . . . . . : 1749126 > > Total size at end . . . . . . . . . : 2836800 > > Large Object Tenured Area: > > Free space at start . . . . . . . . : 0 > > Allocated space at start . . . . . . : 0 > > Total size at start . . . . . . . . : 0 > > Free space at end . . . . . . . . . : 0 > > Allocated space at end . . . . . . . : 0 > > Total size at end . . . . . . . . . : 0 > > Small Object Tenured Area: > > Free space at start . . . . . . . . : 1119550 > > Allocated space at start . . . . . . : 1717250 > > Total size at start . . . . . . . . : 2836800 > > Free space at end . . . . . . . . . : 1087674 > > Allocated space at end . . . . . . . : 1749126 > > Total size at end . . . . . . . . . : 2836800 > > Weak Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 0 > > Number cleared . . . . . . . . . . . : 0 > > Finalizer Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 763 > > Number cleared . . . . . . . . . . . : 4294966533 > > Soft Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 0 > > Number cleared . . . . . . . . . . . : 0 > > Phantom Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 0 > > Number cleared . . . . . . . . . . . : 0 > > > > > > GC Cycle Number : 1802 > > Basic GC Cycle Information: > > Current GC cycle time . . . . . . . : 181 > > GC reason . . . . . . . . . . . . . : Allocation Failure > > GC area . . . . . . . . . . . . . . : None specified > > GC compaction reason . . . . . . . . : None specified > > Number of internal cycles . . . . . : 1 > > Time spent in excessive GC time . . : 0 > > Number of objects moved . . . . . . : 0 > > Amount of space consumed by moved > > objects . . . . . . . . . . . . . : 0 > > Number of classes unloaded . . . . . : 0 > > GC Time Information: > > Cycle start time . . . . . . . . . . : 02/12/20 11:58:30.544 > > Cycle end time . . . . . . . . . . . : 02/12/20 11:58:30.726 > > Mark start time . . . . . . . . . . : 0 > > Mark end time . . . . . . . . . . . : 0 > > Sweep start time . . . . . . . . . . : 0 > > Sweep end time . . . . . . . . . . . : 0 > > Compact start time . . . . . . . . . : 0 > > Compact end time . . . . . . . . . . : 0 > > Nursery Area Information: > > Free space at start . . . . . . . . : 0 > > Allocated space at start . . . . . . : 1179648 > > Total size at start . . . . . . . . : 1179648 > > Free space at end . . . . . . . . . : 1153064 > > Allocated space at end . . . . . . . : 26584 > > Total size at end . . . . . . . . . : 1179648 > > Tenured Area: > > Free space at start . . . . . . . . : 1087671 > > Allocated space at start . . . . . . : 1749129 > > Total size at start . . . . . . . . : 2836800 > > Free space at end . . . . . . . . . : 1072384 > > Allocated space at end . . . . . . . : 1764416 > > Total size at end . . . . . . . . . : 2836800 > > Large Object Tenured Area: > > Free space at start . . . . . . . . : 0 > > Allocated space at start . . . . . . : 0 > > Total size at start . . . . . . . . : 0 > > Free space at end . . . . . . . . . : 0 > > Allocated space at end . . . . . . . : 0 > > Total size at end . . . . . . . . . : 0 > > Small Object Tenured Area: > > Free space at start . . . . . . . . : 1087671 > > Allocated space at start . . . . . . : 1749129 > > Total size at start . . . . . . . . : 2836800 > > Free space at end . . . . . . . . . : 1072384 > > Allocated space at end . . . . . . . : 1764416 > > Total size at end . . . . . . . . . : 2836800 > > Weak Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 2 > > Number cleared . . . . . . . . . . . : 4294967294 > > Finalizer Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 965 > > Number cleared . . . . . . . . . . . : 4294966331 > > Soft Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 0 > > Number cleared . . . . . . . . . . . : 0 > > Phantom Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 0 > > Number cleared . . . . . . . . . . . : 0 > > > > > > GC Cycle Number : 1803 > > Basic GC Cycle Information: > > Current GC cycle time . . . . . . . : 128 > > GC reason . . . . . . . . . . . . . : Allocation Failure > > GC area . . . . . . . . . . . . . . : None specified > > GC compaction reason . . . . . . . . : None specified > > Number of internal cycles . . . . . : 1 > > Time spent in excessive GC time . . : 0 > > Number of objects moved . . . . . . : 0 > > Amount of space consumed by moved > > objects . . . . . . . . . . . . . : 0 > > Number of classes unloaded . . . . . : 0 > > GC Time Information: > > Cycle start time . . . . . . . . . . : 02/12/20 11:58:51.845 > > Cycle end time . . . . . . . . . . . : 02/12/20 11:58:51.974 > > Mark start time . . . . . . . . . . : 0 > > Mark end time . . . . . . . . . . . : 0 > > Sweep start time . . . . . . . . . . : 0 > > Sweep end time . . . . . . . . . . . : 0 > > Compact start time . . . . . . . . . : 0 > > Compact end time . . . . . . . . . . : 0 > > Nursery Area Information: > > Free space at start . . . . . . . . : 0 > > Allocated space at start . . . . . . : 1179648 > > Total size at start . . . . . . . . : 1179648 > > Free space at end . . . . . . . . . : 1153882 > > Allocated space at end . . . . . . . : 25766 > > Total size at end . . . . . . . . . : 1179648 > > Tenured Area: > > Free space at start . . . . . . . . : 1072383 > > Allocated space at start . . . . . . : 1764417 > > Total size at start . . . . . . . . : 2836800 > > Free space at end . . . . . . . . . : 1070847 > > Allocated space at end . . . . . . . : 1765953 > > Total size at end . . . . . . . . . : 2836800 > > Large Object Tenured Area: > > Free space at start . . . . . . . . : 0 > > Allocated space at start . . . . . . : 0 > > Total size at start . . . . . . . . : 0 > > Free space at end . . . . . . . . . : 0 > > Allocated space at end . . . . . . . : 0 > > Total size at end . . . . . . . . . : 0 > > Small Object Tenured Area: > > Free space at start . . . . . . . . : 1072383 > > Allocated space at start . . . . . . : 1764417 > > Total size at start . . . . . . . . : 2836800 > > Free space at end . . . . . . . . . : 1070847 > > Allocated space at end . . . . . . . : 1765953 > > Total size at end . . . . . . . . . : 2836800 > > Weak Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 0 > > Number cleared . . . . . . . . . . . : 0 > > Finalizer Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 730 > > Number cleared . . . . . . . . . . . : 4294966566 > > Soft Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 0 > > Number cleared . . . . . . . . . . . : 0 > > Phantom Object References: > > Number at start . . . . . . . . . . : 0 > > Number at end . . . . . . . . . . . : 0 > > Number cleared . . . . . . . . . . . : 0 > > -- > JHHL > Looks completely normal. There are 2 periods here: from the end of the first GC to the beginning of the second and from the end of the second to the beginning of the third. The span was 43.471 seconds. The second and third GC took 309ms total. 309/43,471 is about .007, which means your app was only paused for about 0.7% of the time. That means 99.3% of the time it was available to do useful work. That's good. Furthermore, the 2 GCs almost completely cleared the nursery and the tenured area only increased slightly. Those are both normal. John
