United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
Bug ID: JDK-7087969 GarbageCollectorMXBean notification contains ticks vs millis
JDK-7087969 : GarbageCollectorMXBean notification contains ticks vs millis

Details
Type:
Bug
Submit Date:
2011-09-07
Status:
Resolved
Updated Date:
2013-06-26
Project Name:
JDK
Resolved Date:
2012-04-19
Component:
hotspot
OS:
linux
Sub-Component:
svc
CPU:
x86
Priority:
P4
Resolution:
Fixed
Affected Versions:
7
Fixed Versions:
hs24 (b07)

Related Reports
Backport:
Backport:
Backport:

Sub Tasks

Description
FULL PRODUCT VERSION :
java version "1.7.0"
Java(TM) SE Runtime Environment (build 1.7.0-b147)
Java HotSpot(TM) 64-Bit Server VM (build 21.0-b17, mixed mode)


FULL OS VERSION :
ALL (OS independent issue).

A DESCRIPTION OF THE PROBLEM :
When grabbing GarbageCollectorMXBean from the ManagementFactory, it is NOW possible (in Java 7) to cast the underlying bean implementation into a NotificationBroadcaster and add a NotificationListener.  Doing this causes the JVM to report on GC events after they're done.  In the JVM, GCNotifier::pushNotification puts the "raw" GCStatInfo data (containing start/end ticks) onto the request queue.  GCNotifier::sendNotification constructs GcInfo from this data WITHOUT converting the ticks to millis.  When the listener gets access to the GcInfo object, a call to getDuration() returns elapsed ticks vs. elapsed millis (contrary to comments in the source code).

This all constrasts the notion of calling GarbageCollectorMXBean.getLastGcInfo, which under the covers DOES convert the ticks to millis prior to returning the object.


THE PROBLEM WAS REPRODUCIBLE WITH -Xint FLAG: Did not try

THE PROBLEM WAS REPRODUCIBLE WITH -server FLAG: Did not try

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
Use the provided source code.

EXPECTED VERSUS ACTUAL BEHAVIOR :
Actual results:

PS Scavenge : 7093839093246673821
PS Scavenge : 4309
PS Scavenge : 4305
PS Scavenge : 4304
PS Scavenge : 3037
PS Scavenge : 3226
PS Scavenge : 2991
PS Scavenge : 4432
PS Scavenge : 1643
PS Scavenge : 1797
PS Scavenge : 973
PS Scavenge : 863
PS Scavenge : 738
PS Scavenge : 993
PS Scavenge : 765
...


REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------
    public static void main(String[] args)
    {
        NotificationListener nl = new NotificationListener()
        {
            @Override
            public void handleNotification(Notification notification, Object name)
            {
                CompositeData cd = (CompositeData) notification.getUserData();
                cd = (CompositeData) cd.get("gcInfo");
                GcInfo gcInfo = GcInfo.from(cd);
                long ticksNotMillis = gcInfo.getDuration();
                System.out.append(String.valueOf(name)).append(" : ");
                System.out.append(Long.toString(ticksNotMillis)).append("\n");
            }
        };

        List<GarbageCollectorMXBean> list = ManagementFactory.getGarbageCollectorMXBeans();

        for (GarbageCollectorMXBean bean : list)
            ((NotificationBroadcaster) bean).addNotificationListener(nl, null, bean.getName());

        // Force garbage collection

        long start = System.currentTimeMillis();

        for (;;)
        {
            long now = System.currentTimeMillis();

            if (now - start > 5000)
                break;

            byte[] bytes = new byte[1048576];
        }
    }

---------- END SOURCE ----------

                                    

Comments
EVALUATION

http://hg.openjdk.java.net/hsx/hotspot-rt/hotspot/rev/9a5bef0481c8
                                     
2012-03-29
EVALUATION

http://hg.openjdk.java.net/hsx/hotspot-main/hotspot/rev/9a5bef0481c8
                                     
2012-04-04



Hardware and Software, Engineered to Work Together