Java – monitoring cpu and system load of multi-threaded application via OperatingSystemMXBean

1. All CPU cores busy executing busy loop (cpu intensive)

Per documentation: Java exposes java.lang.management.OperatingSystemMXBean interface with

  • double getSystemCpuLoad() returning the “recent cpu usage” for the whole system with range [0.0,1.0] where 0.0 means that all CPUs were idle, 1.0 means that all CPUs were actively running 100% of the observed time, and -1.0 when recent cpu usage is not available. The value for system load could be high not only when JVM process heavily uses that but also if other no-JVM processes generate high CPU load
  • double getProcessCpuLoad() returning “recent cpu usage” for the Java Virtual Machine process with range [0.0,1.0] value 0.0 means that none of the CPUs were running threads (application and JVM internal threads) from the JVM process, 1.0 means that all CPUs were actively running threads from the JVM 100% of the observed time, and -1.0 when recent cpu usage is not available
  • public class MonitorAllCoresCpuLoad {
    
      private static volatile boolean hasAnyWorkerFinished = false;
    
      public static void main(String[] args) throws Exception {
        OperatingSystemMXBean operatingSystemMXBean = ManagementFactory.getOperatingSystemMXBean();
        int workersCount = Runtime.getRuntime().availableProcessors();
        CyclicBarrier barrier 
                 = new CyclicBarrier(workersCount + 1); // + 1 to include main thread measuring CPU load
        for (int i = 0; i < workersCount; i++) {
          createAndStartWorker(barrier); //use barrier to start all workers at the same time as main thread
        }
        barrier.await();
        System.out.println("All workers and main thread started");
        while (!hasAnyWorkerFinished) { // stop measuring if at least one of workers finished
          getAndPrintCpuLoad(operatingSystemMXBean);
          TimeUnit.MILLISECONDS.sleep(100);
        }
        System.out.println("One of workers finished");
      }
    
        private static void createAndStartWorker(CyclicBarrier cyclicBarrier) {
            new Thread(() -> {
                try {
                    cyclicBarrier.await();
                    for (long i = 0L; i < 19999999999L; i++) { // 6s
                        // Thread 100% time as RUNNABLE, taking 1/(n cores) of JVM/System overall CPU
                    }
                    hasAnyWorkerFinished = true;
                    System.out.println(Thread.currentThread().getName() + " finished");
                } catch (Exception e) {
                    e.printStackTrace();
                }
            }).start();
    
        }
    
        private static void getAndPrintCpuLoad(OperatingSystemMXBean mxBean) {
           // need to use reflection as the impl class is not visible
           for (Method method : mxBean.getClass().getDeclaredMethods()) {
             method.setAccessible(true);
             String methodName = method.getName();
             if (methodName.startsWith("get") && methodName.contains("Cpu") && methodName.contains("Load")
                     && Modifier.isPublic(method.getModifiers())) {
    
                 Object value;
                 try {
                     value = method.invoke(mxBean);
                 } catch (Exception e) {
                     value = e;
                 }
                 System.out.println(methodName + " = " + value);
             }
          }
          System.out.println("");
        }
    }
    

    Busy loop: all cores busy
    getProcessCpuLoad = 0.9968879402893512
    getSystemCpuLoad = 1.0

    Note: The main thread responsible for printing CPU load was not able to get CPU time (no CPU load printed) when I was running more worker threads than CPU cores on my laptop (Windows 7 os).

    2. One of cores executing busy loop (cpu intensive)

    Busy loop: one of four cores busy
    getProcessCpuLoad = 0.24999679493343077
    getSystemCpuLoad = 0.2571523807692343

    Note that is my laptop was only running JVM the system and JVM process CPU usage was 1/4 = 0.25%.

    3. Sleeping loop

    getProcessCpuLoad = 0.0
    getSystemCpuLoad = 0.014311079773084212

    4. Slow network I/O
    4 core Windows 7 laptop, java program running 10 threads executing http rq over slow network:

    public class FluentFormLoginAuthorizationMultiThreadedTest {
        
        private static final Logger LOGGER = 
            LoggerFactory.getLogger(FluentFormLoginAuthorizationMultiThreadedTest.class);
        private static final int COUNT = 10;
        private static volatile boolean hasAnyThreadFinished = false;
    
        public static void main(String[] args) throws Exception {
          OperatingSystemMXBean operatingSystemMXBean = ManagementFactory.getOperatingSystemMXBean();
    
          Executor executor = Executor.newInstance()
                  .auth(new HttpHost("myhost", 8090), Settings.USERNAME, Settings.PASSWORD);
            
          TimeUnit.SECONDS.sleep(10); // give time to collect via JVisualVM
          CyclicBarrier barrier = new CyclicBarrier(COUNT + 1); // + 1 for main thread to monitor CPU load
          for (int i = 0; i < COUNT; i++) {
              new Thread(() ->  run(executor, barrier)).start();;
          }
    
          barrier.await();
          System.out.println("All threads started");
          while (!hasAnyThreadFinished) {
              printCpuLoad(operatingSystemMXBean);
              TimeUnit.MILLISECONDS.sleep(100);
          }
          System.out.println("One of thread finished");
        }
    
        private static void run(Executor executor, CyclicBarrier cyclicBarrier) {
            String content;
            try {
                cyclicBarrier.await();
                LOGGER.debug("Started");
    
                content = executor
                        .execute(Request.Get("http://myhost:8090/view?pattern=INFO&path=/apps/logs/*"))
                        .returnContent()
                        .asString();
    
                hasAnyThreadFinished = true;
                //System.err.println(content);
                LOGGER.debug("Stopped");
            } catch (Exception e) {
                e.printStackTrace();
            }
        }
    
        private static void printCpuLoad(OperatingSystemMXBean mxBean) {
          for (Method method : mxBean.getClass().getDeclaredMethods()) {
            method.setAccessible(true);
            String methodName = method.getName();
            if (methodName.startsWith("get") && methodName.contains("Cpu") && methodName.contains("Load")
                    && Modifier.isPublic(method.getModifiers())) {
    
                Object value;
                try {
                   value = method.invoke(mxBean);
                } catch (Exception e) {
                    value = e;
                }
                System.out.print(methodName + "," + value + ",");
            }
          }
          System.out.println("");
        }
    }
    

    Results:

    getProcessCpuLoad getSystemCpuLoad
    min 0.007357802 0.017761006
    max 0.022199061 0.11305298
    avg 0.017429555 0.051268221

    10-threads-calling-slow-network-IO-http-rq

    Notice that all 10 threads that executed http request are shown on JVisualVM as 100% running. That means that 100% of their time they are in RUNNABLE state. But it does not necessary mean that all of them are using all the CPU cores in 100%. In our case average process cpu load is 1.7%, system cpu load 5% (aggregate for all cores, where load of 1.0 we had when all CPU were fully used).

    “Thread-10” #24 prio=5 os_prio=0 tid=0x0000000058b0f800 nid=0x2258 runnable [0x000000005bd0e000]
    java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)

    org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:284)

    at http.client.FluentFormLoginAuthorizationMultiThreadedTest.run(FluentFormLoginAuthorizationMultiThreadedTest.java:50)
    at http.client.FluentFormLoginAuthorizationMultiThreadedTest.lambda$0(FluentFormLoginAuthorizationMultiThreadedTest.java:31)
    at http.client.FluentFormLoginAuthorizationMultiThreadedTest$$Lambda$4/152005629.run(Unknown Source)
    at java.lang.Thread.run(Thread.java:745)

    Advertisements

    Leave a Reply

    Fill in your details below or click an icon to log in:

    WordPress.com Logo

    You are commenting using your WordPress.com account. Log Out / Change )

    Twitter picture

    You are commenting using your Twitter account. Log Out / Change )

    Facebook photo

    You are commenting using your Facebook account. Log Out / Change )

    Google+ photo

    You are commenting using your Google+ account. Log Out / Change )

    Connecting to %s