United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
Bug ID: JDK-8000831 Heap verification output incorrect/incomplete
JDK-8000831 : Heap verification output incorrect/incomplete

Details
Type:
Bug
Submit Date:
2012-10-12
Status:
Resolved
Updated Date:
2013-04-30
Project Name:
JDK
Resolved Date:
2012-10-15
Component:
hotspot
OS:
generic
Sub-Component:
gc
CPU:
generic
Priority:
P3
Resolution:
Fixed
Affected Versions:
hs24
Fixed Versions:
hs25 (b06)

Related Reports
Backport:
Backport:
Backport:
Backport:
Backport:

Sub Tasks

Description
At some point a change was made that affected the output of VerifyBeforeGC and VerifyAfterGC. Previously it was:

[Verifying threads syms strs zone dict hand C-heap code cache ]
 VerifyBeforeGC:[Verifying threads permanent tenured eden syms strs zone dict hand C-heap code cache ]
4.818: [GC [PSYoungGen: 16896K->392K(19712K)] 16896K->396K(62720K), 0.0244147 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
 VerifyBeforeGC:[Verifying threads permanent tenured eden syms strs zone dict hand C-heap code cache ]
5.087: [GC [PSYoungGen: 17288K->392K(19712K)] 17292K->400K(62720K), 0.0597174 secs] [Times: user=0.04 sys=0.03, real=0.06 secs]
 VerifyBeforeGC:[Verifying threads permanent tenured eden syms strs zone dict hand C-heap code cache ]
5.410: [GC [PSYoungGen: 17288K->400K(19712K)] 17296K->412K(62720K), 0.0173056 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
 VerifyBeforeGC:[Verifying threads permanent tenured eden syms strs zone dict hand C-heap code cache ]
5.595: [GC [PSYoungGen: 17296K->400K(36608K)] 17308K->416K(79616K), 0.0134239 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

But is now:

[Verifying threads syms strs zone dict hand C-heap code cache ]
 VerifyBeforeGC:4.619: [GC [PSYoungGen: 16896K->416K(19712K)] 16896K->420K(62720K), 0.0170685 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
 VerifyBeforeGC:5.013: [GC [PSYoungGen: 17312K->416K(19712K)] 17316K->424K(62720K), 0.0125283 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
 VerifyBeforeGC:5.239: [GC [PSYoungGen: 17312K->400K(19712K)] 17320K->412K(62720K), 0.0586610 secs] [Times: user=0.04 sys=0.03, real=0.06 secs]
 VerifyBeforeGC:5.439: [GC [PSYoungGen: 17296K->432K(36608K)] 17308K->448K(79616K), 0.0167533 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
 VerifyBeforeGC:5.721: [GC [PSYoungGen: 34224K->392K(38144K)] 34240K->412K(81152K), 0.0909802 secs] [Times: user=0.05 sys=0.04, real=0.09 secs]
 VerifyBeforeGC:6.034: [GC [PSYoungGen: 35720K->400K(69184K)] 35740K->424K(112192K), 0.0344226 secs] [Times: user=0.04 sys=0.00, real=0.03 secs]
 VerifyBeforeGC:6.709: [GC [PSYoungGen: 69136K->64K(69184K)] 69160K->440K(112192K), 0.1976060 secs] [Times: user=0.10 sys=0.11, real=0.20 secs]

                                    

Comments
The change is behavior seems to come from changeset:

changeset:   3262:b632e80fc9dc
tag:         tip
user:        brutisso
date:        Mon Apr 16 08:57:18 2012 +0200
4988100: oop_verify_old_oop appears to be dead
Summary: removed oop_verify_old_oop and allow_dirty. Also reviewed by: alexlamsl@gmail.com

The problem is that the change removed the allow_dirty optional parameter (which had a default value of true) but did not update some call sites appropriately. Hence some calls are now passing true as the silent parameter when before they were not passing anything and thus the silent parameter would get its default value: false (meaning print the individual verification steps).
                                     
2012-10-12
URL:   http://hg.openjdk.java.net/hsx/hotspot-gc/hotspot/rev/4202510ee0fe
User:  johnc
Date:  2012-10-15 20:06:34 +0000

                                     
2012-10-15
URL:   http://hg.openjdk.java.net/hsx/hsx25/hotspot/rev/4202510ee0fe
User:  amurillo
Date:  2012-10-19 20:30:21 +0000

                                     
2012-10-19



Hardware and Software, Engineered to Work Together