Garbage collection notification?

Question

I'd like to register a callback with the JVM so I know when garbage collection is happening. Is there any way to do this?

EDIT: I want to do this so I can log out when garbage collection happens in my application log, so I can see if it correlates to problems I'm seeing. Turning on -Xloggc is helpful, but it is a little tricky to integrate the times from the GC log (which use seconds since app start) into my main application log.

EDIT April 2012: As of Java7u4, you can get notifications from the GarbageCollectorMXBean (a nice example).

Answer 1

As of Java7u4, you can get notifications from the GarbageCollectorMXBean. See http://docs.oracle.com/javase/7/docs/jre/api/management/extension/com/sun/management/GarbageCollectionNotificationInfo.html

Answer 2

I think that the standard way is to use the JVM Tool Interface (JVM TI) to write an agent with a GC start callback and to log the time from it (see GetTime). Note that a Garbage Collection Start event is sent for full GCs only.

Sample JVM TI agents is available in the demo directory of the JDK 5.0 or the JDK 6 download. The tech article The JVM Tool Interface (JVM TI): How VM Agents Work is another very good resource. Also have a look at Creating a Debugging and Profiling Agent with JVMTI.

Answer 3

Java code sample using the GarbageCollectorMXBean referred to in the accepted answer:

static
{
    // notification listener. is notified whenever a gc finishes.
    NotificationListener notificationListener = new NotificationListener()
    {
        @Override
        public void handleNotification(Notification notification,Object handback)
        {
            if (notification.getType().equals(GarbageCollectionNotificationInfo.GARBAGE_COLLECTION_NOTIFICATION))
            {
                // extract garbage collection information from notification.
                GarbageCollectionNotificationInfo gcInfo = GarbageCollectionNotificationInfo.from((CompositeData) notification.getUserData());

                // access garbage collection information...
            }
        }
    };

    // register our listener with all gc beans
    for (GarbageCollectorMXBean gcBean : ManagementFactory.getGarbageCollectorMXBeans())
    {
        NotificationEmitter emitter = (NotificationEmitter) gcBean;
        emitter.addNotificationListener(notificationListener,null,null);
    }
}

site that has detailed sample code that uses the GarbageCollectorMXBean.

Answer 4

It looks like you could use the MemoryPoolMXBean and set the collection usage threshold to 1. This should give you a notification any time the gc runs and there is still at least a byte of memory in use.

http://java.sun.com/j2se/1.5.0/docs/api/java/lang/management/MemoryPoolMXBean.html

It looks like this doesn't work with all garbage collectors, though.

Answer 5

I know this is very late but I hope it might help someone someday.

You can receive such events this by using the using the library that i am developing called gcRadar. It provides information about exactly when an object was garbage collected.

Any suggestions for improvements in the library are welcome.

Answer 6

When receiving the JVMTI event for Garbage Collection the JVM is technically stopped so it's unable to call back a Java listener via JNI.... this agent prints out the time at GC start and finish with a higher resolution than the verbose GC on the Sun JVM.

#include <stdlib.h>
#include <time.h>
#include <sys/time.h>
#include "jvmti.h"

void printGCTime(const char* type) {

  struct timeval tv;
  gettimeofday(&tv, NULL);

  struct tm localTime;
  localtime_r(&tv.tv_sec, &localTime);

  char *startTime = calloc(1, 128);

  strftime(startTime, (size_t) 128, "%a %b %d %Y %H:%M:%S", &localTime);

  fprintf(stderr, "GC %s: %s.%06d\n", type, startTime, (int)tv.tv_usec );
  fflush(stderr);

  if(startTime) free(startTime);

}

void JNICALL
garbageCollectionStart(jvmtiEnv *jvmti_env) {

  printGCTime("Start ");

}

void JNICALL
garbageCollectionFinish(jvmtiEnv *jvmti_env) {

  printGCTime("Finish");

}


JNIEXPORT jint JNICALL
Agent_OnLoad(JavaVM * jvm, char *options, void *reserved)
{
  jvmtiEnv *jvmti_env;

  jint returnCode = (*jvm)->GetEnv(jvm, (void **) &jvmti_env,
      JVMTI_VERSION_1_0);



  if (returnCode != JNI_OK)
    {
      fprintf(stderr,
          "The version of JVMTI requested (1.0) is not supported by this JVM.\n");
      return JVMTI_ERROR_UNSUPPORTED_VERSION;
    }


  jvmtiCapabilities *requiredCapabilities;

  requiredCapabilities = (jvmtiCapabilities*) calloc(1, sizeof(jvmtiCapabilities));
  if (!requiredCapabilities)
      {
        fprintf(stderr, "Unable to allocate memory\n");
        return JVMTI_ERROR_OUT_OF_MEMORY;
      }

  requiredCapabilities->can_generate_garbage_collection_events = 1;

  if (returnCode != JNI_OK)
    {
      fprintf(stderr, "C:\tJVM does not have the required capabilities (%d)\n",
          returnCode);
      exit(-1);
    }



  returnCode = (*jvmti_env)->AddCapabilities(jvmti_env, requiredCapabilities);


  jvmtiEventCallbacks *eventCallbacks;

  eventCallbacks = calloc(1, sizeof(jvmtiEventCallbacks));
  if (!eventCallbacks)
    {
      fprintf(stderr, "Unable to allocate memory\n");
      return JVMTI_ERROR_OUT_OF_MEMORY;
    }

  eventCallbacks->GarbageCollectionStart = &garbageCollectionStart;
  eventCallbacks->GarbageCollectionFinish = &garbageCollectionFinish;


  returnCode = (*jvmti_env)->SetEventCallbacks(jvmti_env,
      eventCallbacks, (jint) sizeof(*eventCallbacks));


  if (returnCode != JNI_OK)
    {
      fprintf(stderr, "C:\tError setting event callbacks (%d)\n",
          returnCode);
      exit(-1);
    }

  returnCode = (*jvmti_env)->SetEventNotificationMode(
      jvmti_env, JVMTI_ENABLE, JVMTI_EVENT_GARBAGE_COLLECTION_START, (jthread) NULL);

  if (returnCode != JNI_OK)
    {
      fprintf(
          stderr,
          "C:\tJVM does not have the required capabilities, JVMTI_ENABLE, JVMTI_EVENT_GARBAGE_COLLECTION_START (%d)\n",
          returnCode);
      exit(-1);
    }


  returnCode = (*jvmti_env)->SetEventNotificationMode(
      jvmti_env, JVMTI_ENABLE, JVMTI_EVENT_GARBAGE_COLLECTION_FINISH, (jthread) NULL);

  if (returnCode != JNI_OK)
    {
      fprintf(
          stderr,
          "C:\tJVM does not have the required capabilities, JVMTI_ENABLE, JVMTI_EVENT_GARBAGE_COLLECTION_FINISH (%d)\n",
          returnCode);
      exit(-1);
    }


  if(requiredCapabilities) free(requiredCapabilities);
  if(eventCallbacks) free(eventCallbacks);

  return JVMTI_ERROR_NONE;
}

Answer 7

Another use case for getting impending GC notifications: if your app is load balanced then you can then notify the load balancer to take your node out of the pool when a GC is about to start to that it does not receive requests that would have to wait for a full GC to get dealt with.

That doesn't help in-flight requests that arrived just before the GC kicked in but, in my case at least, most requests are subsecond and major GCs are 5-10s, every few minutes. We can tweak the NewGen ratios etc but the general point still applies: major GC may be much longer than typical response times so you may want to premptively stop a node starting a major GC from receiving requests.

When GC is over, a thread in the JVM can send a notification to the load balancer to let it know its back in business or the LB can rely on its usual keepalive.

Answer 8

There's an interesting article on Javalobby discussing one method of doing this.

Answer 9

There is no standard way for your own program to get information from the JVM about garbage collection. Any such API is vendor specific.

Why is the facility you found insufficient?

Answer 10

Regarding -Xloggc: As of jdk1.6 update 4 you can get the Sun/Oracle JVM to print out the date and time using -XX:+PrintGCDateStamps. This makes the logs much more useful, especially if you add a log scanner / monitor that can notify you of any GC issues.

• http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6517301
• http://www.oracle.com/technetwork/java/javase/6u4-140071.html

Answer 11

If you're looking at this as a diagnostic tool, I recommend redirecting your application log to StdOut and then redirecting both StdOut and StdErr into a file. This will give you the detail of JVM logging, without forcing you to change your application code.