8243489: Thread CPU Load event may contain wrong data for CPU time under certain conditions

Reviewed-by: jbachorik

Author: mar-kolya

src/hotspot/share/jfr/periodic/jfrThreadCPULoadEvent.cpp

@@ -87,15 +87,14 @@ bool JfrThreadCPULoadEvent::update_event(EventThreadCPULoad& event, JavaThread*
   // Avoid reporting percentages above the theoretical max
   if (user_time + system_time > wallclock_time) {
     jlong excess = user_time + system_time - wallclock_time;
+    cur_cpu_time -= excess;
     if (user_time > excess) {
       user_time -= excess;
       cur_user_time -= excess;
-      cur_cpu_time -= excess;
     } else {
-      cur_cpu_time -= excess;
       excess -= user_time;
+      cur_user_time -= user_time;
       user_time = 0;
-      cur_user_time = 0;
       system_time -= excess;
     }
   }

test/hotspot/gtest/jfr/test_threadCpuLoad.cpp

@@ -148,6 +148,12 @@ TEST_VM_F(JfrTestThreadCPULoadSingle, SingleCpu) {
   EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, 400 * NANOSECS_PER_MILLISEC, 1));
   EXPECT_FLOAT_EQ(0.25, event.user);
   EXPECT_FLOAT_EQ(0.25, event.system);
+
+  MockOs::user_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  MockOs::system_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (400 + 400) * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.125, event.user);
+  EXPECT_FLOAT_EQ(0.125, event.system);
 }
 
 TEST_VM_F(JfrTestThreadCPULoadSingle, MultipleCpus) {
@@ -177,6 +183,43 @@ TEST_VM_F(JfrTestThreadCPULoadSingle, UserAboveMaximum) {
   EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (200 + 400) * NANOSECS_PER_MILLISEC, 1));
   EXPECT_FLOAT_EQ(0.25, event.user);
   EXPECT_FLOAT_EQ(0, event.system);
+
+  // Third call: make sure there are no leftovers
+  MockOs::user_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  MockOs::system_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (200 + 400 + 400) * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.125, event.user);
+  EXPECT_FLOAT_EQ(0.125, event.system);
+}
+
+TEST_VM_F(JfrTestThreadCPULoadSingle, UserAboveMaximumNonZeroBase) {
+
+  // Setup a non zero base
+  // Previously there was a bug when cur_user_time would be reset to zero and test that uses zero base would fail to detect it
+  MockOs::user_cpu_time = 100 * NANOSECS_PER_MILLISEC;
+  MockOs::system_cpu_time = 100 * NANOSECS_PER_MILLISEC;
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, 400 * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.25, event.user);
+  EXPECT_FLOAT_EQ(0.25, event.system);
+
+  // First call will not report above 100%
+  MockOs::user_cpu_time += 200 * NANOSECS_PER_MILLISEC;
+  MockOs::system_cpu_time += 100 * NANOSECS_PER_MILLISEC;
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (400 + 200) * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.5, event.user);
+  EXPECT_FLOAT_EQ(0.5, event.system);
+
+  // Second call will see an extra 100 millisecs user time from the remainder
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (400 + 200 + 400) * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.25, event.user);
+  EXPECT_FLOAT_EQ(0, event.system);
+
+  // Third call: make sure there are no leftovers
+  MockOs::user_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  MockOs::system_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (400 + 200 + 400 + 400) * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.125, event.user);
+  EXPECT_FLOAT_EQ(0.125, event.system);
 }
 
 TEST_VM_F(JfrTestThreadCPULoadSingle, SystemAboveMaximum) {
@@ -192,6 +235,43 @@ TEST_VM_F(JfrTestThreadCPULoadSingle, SystemAboveMaximum) {
   EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (200 + 400) * NANOSECS_PER_MILLISEC, 1));
   EXPECT_FLOAT_EQ(0.25, event.user);
   EXPECT_FLOAT_EQ(0.25, event.system);
+
+  // Third call: make sure there are no leftovers
+  MockOs::user_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  MockOs::system_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (200 + 400 + 400) * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.125, event.user);
+  EXPECT_FLOAT_EQ(0.125, event.system);
+}
+
+TEST_VM_F(JfrTestThreadCPULoadSingle, SystemAboveMaximumNonZeroBase) {
+
+  // Setup a non zero base
+  // Previously there was a bug when cur_user_time would be reset to zero and test that uses zero base would fail to detect it
+  MockOs::user_cpu_time = 100 * NANOSECS_PER_MILLISEC;
+  MockOs::system_cpu_time = 100 * NANOSECS_PER_MILLISEC;
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, 400 * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.25, event.user);
+  EXPECT_FLOAT_EQ(0.25, event.system);
+
+  // First call will not report above 100%
+  MockOs::user_cpu_time += 100 * NANOSECS_PER_MILLISEC;
+  MockOs::system_cpu_time += 300 * NANOSECS_PER_MILLISEC;
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (400 + 200) * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0, event.user);
+  EXPECT_FLOAT_EQ(1, event.system);
+
+  // Second call will see an extra 100 millisecs user and system time from the remainder
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (400 + 200 + 400) * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.25, event.user);
+  EXPECT_FLOAT_EQ(0.25, event.system);
+
+  // Third call: make sure there are no leftovers
+  MockOs::user_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  MockOs::system_cpu_time += 50 * NANOSECS_PER_MILLISEC;
+  EXPECT_TRUE(JfrThreadCPULoadEvent::update_event(event, thread, (400 + 200 + 400 + 400) * NANOSECS_PER_MILLISEC, 1));
+  EXPECT_FLOAT_EQ(0.125, event.user);
+  EXPECT_FLOAT_EQ(0.125, event.system);
 }
 
 TEST_VM_F(JfrTestThreadCPULoadSingle, SystemTimeDecreasing) {