Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8351359

OperatingSystemMXBean stops reporting cpuLoad and processCpuLoad after 24.8 days

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: P4 P4
    • 25
    • 23.0.2
    • core-svc

      ADDITIONAL SYSTEM INFORMATION :
      Windows 11, 10 & Server
      Tested Java runtimes:
      - OpenJDK 64-Bit Server VM Temurin-23.0.1+11 (build 23.0.1+11, mixed mode, sharing)
      - OpenJDK 64-Bit Server VM Corretto-17.0.10.7.1 (build 17.0.10+7-LTS, mixed mode, sharing)

      A DESCRIPTION OF THE PROBLEM :
      On Windows, a JVM that has run for more than 2,147,483.647 seconds (or Integer.MAX_VALUE milliseconds) will no longer report any new values for OperatingSystemMXBean::getCpuLoad or OperatingSystemMXBean::getProcessCpuLoad.

      The underlying native operating system implementation for Windows (OperatingSystemImpl.c#L997) limits requests to avoid too frequent querying of system information. This implementation uses clock_t clock( void ); for tracking the lastUpdate time. To query new system information, at least 500 ticks must have passed since the last query. Unfortunately the Windows clock() call is not suitable for long running processes. As stated in the documentation (https://learn.microsoft.com/en-us/cpp/c-runtime-library/reference/clock?view=msvc-170)

      > Given enough time, the value returned by clock can exceed the maximum positive value of clock_t.
      > When the process has run longer, the value returned by clock is always (clock_t)(-1)
      > ...
      > This macro gives a maximum clock function return value of 2147483.647 seconds, or about 24.8 days.

      For the Windows implementation of OperatingSystemImpl.c this means that the 500 ticks between queries can no longer be fulfilled once the the clock call starts reporting (clock_t)(-1). Thereafter, no new queries will ever be made and the metrics will be stuck on the previous value that was retrieved prior to clock exceeding the maximum positive value.

      I have patched a forked JDK, replacing clock() call with _ftime(), to verify that it is indeed the usage of clock() that is the problematic area of the current implementation. See patch here https://github.com/openjdk/jdk/commit/4486e38029a3247e39346d78715f47e39be5f020 and for further details on reproducing this issue on https://github.com/pontusp/os-perf-logger/

      STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
      Run "Test Case Code" on Windows for at least 25 days, outputting performance metrics to a CSV file. E.g.
      java.exe -jar target/os-perf-logger-1.0-SNAPSHOT.jar metrics.csv

      EXPECTED VERSUS ACTUAL BEHAVIOR :
      EXPECTED -
      OperatingSystemMXBean shall be able to report cpuLoad and processCpuLoad for as long as the JVM is running.
      ACTUAL -
      OperatingSystemMXBean stops reporting cpuLoad and processCpuLoad after 24.8 days

      ---------- BEGIN SOURCE ----------
      package se.pontus.osperf;

      import static java.util.Map.entry;

      import java.io.File;
      import java.io.FileNotFoundException;
      import java.io.PrintWriter;
      import java.lang.management.ManagementFactory;
      import java.lang.management.RuntimeMXBean;
      import java.text.DecimalFormat;
      import java.util.Collections;
      import java.util.LinkedHashMap;
      import java.util.Map;
      import java.util.Map.Entry;
      import java.util.concurrent.Executors;
      import java.util.concurrent.ScheduledExecutorService;
      import java.util.concurrent.TimeUnit;
      import java.util.function.Supplier;
      import java.util.stream.Collectors;

      import com.sun.management.OperatingSystemMXBean;


      public class OsPerformanceLogger implements Runnable {
          private static final String CSV_DEFAULT_FILE = "osPerformanceLogger.csv";
          private static final DecimalFormat DECIMAL_FORMAT = new DecimalFormat("#.####");
          private final PrintWriter csvWriter;
          private final Map<String, Supplier<String>> csvMetrics;


          public OsPerformanceLogger(String logFile) throws FileNotFoundException {
              File csvLogFile = new File(logFile != null ? logFile : CSV_DEFAULT_FILE);
              csvWriter = new PrintWriter(csvLogFile);

              final OperatingSystemMXBean osMxBean = (OperatingSystemMXBean) ManagementFactory.getOperatingSystemMXBean();
              final RuntimeMXBean runtimeMxBean = ManagementFactory.getRuntimeMXBean();

              csvMetrics = orderedMapOf(
                      entry("vmUptime", () -> Long.toString(runtimeMxBean.getUptime())),
                      entry("cpuLoad", () -> DECIMAL_FORMAT.format(osMxBean.getCpuLoad())),
                      entry("processCpuLoad", () -> DECIMAL_FORMAT.format(osMxBean.getProcessCpuLoad())),
                      entry("osName", osMxBean::getName),
                      entry("vmName", runtimeMxBean::getVmName),
                      entry("vmVendor", runtimeMxBean::getVmVendor),
                      entry("vmVersion", runtimeMxBean::getVmVersion));

              csvWriter.println(csvMetrics.keySet().stream().collect(Collectors.joining(",")));
          }

          @SafeVarargs
          private static <K, V> Map<K, V> orderedMapOf(Entry<? extends K, ? extends V>... entries) {
              LinkedHashMap<K, V> map = new LinkedHashMap<>();
              for (Entry<? extends K, ? extends V> entry : entries ) {
                  map.put(entry.getKey(), entry.getValue());
              }
              return Collections.unmodifiableMap(map);
          }

          @Override
          public void run() {
              csvWriter.println(csvMetrics.values().stream().map(Supplier::get).collect(Collectors.joining(",")));
              csvWriter.flush();
          }

          public static void main(String[] args) {
              try {
                  String logFile = args.length > 0 ? args[0] : CSV_DEFAULT_FILE;
                  System.out.println("Starting OS Performance Logger to file: " + logFile);
                  OsPerformanceLogger perfLogger = new OsPerformanceLogger(logFile);
                  ScheduledExecutorService executor = Executors.newScheduledThreadPool(1);
                  executor.scheduleAtFixedRate(perfLogger, 0, 1, TimeUnit.SECONDS);

                  while (true) {
                      try {
                          Thread.sleep(1000);
                      } catch (InterruptedException e) {
                          Thread.currentThread().interrupt();
                      }
                  }
              } catch (FileNotFoundException e) {
                  System.err.println("Error: " + e.getMessage());
              }
          }
      }
      ---------- END SOURCE ----------

            kevinw Kevin Walls
            webbuggrp Webbug Group
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

              Created:
              Updated: