stan/jdk-24
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

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

Browse Source 
Reviewed-by: jbachorik
This commit is contained in:
Nikolay Martynov 2020-04-29 13:27:01 +02:00 committed by Jaroslav Bachorik
parent 5bbee05c7a
commit 313758a57a
2 changed files with 82 additions and 3 deletions
src/hotspot/share/jfr/periodic
jfrThreadCPULoadEvent.cpp
test/hotspot/gtest/jfr
test_threadCpuLoad.cpp

5
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;
}
}

80
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) {