Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

8254758: Change G1ServiceThread to be task based #734

Closed
wants to merge 14 commits into from
@@ -182,6 +182,9 @@ G1ServiceThread::G1ServiceThread() :
}

void G1ServiceThread::register_task(G1ServiceTask* task, jlong delay) {
guarantee(!task->is_registered(), "Task already registered");
guarantee(task->next() == NULL, "Task already in queue");

log_debug(gc, task)("G1 Service Thread (%s) (register)", task->name());

// Associate the task with the service thread.
@@ -197,6 +200,9 @@ void G1ServiceThread::register_task(G1ServiceTask* task, jlong delay) {
}

void G1ServiceThread::schedule_task(G1ServiceTask* task, jlong delay_ms) {
guarantee(task->is_registered(), "Must be registered before scheduled");
guarantee(task->next() == NULL, "Task already in queue");

// Schedule task by setting the task time and adding it to queue.
jlong delay = TimeHelper::millis_to_counter(delay_ms);
task->set_time(os::elapsed_counter() + delay);
@@ -251,13 +257,16 @@ G1ServiceTask* G1ServiceThread::pop_due_task() {
}

void G1ServiceThread::run_task(G1ServiceTask* task) {
double start = os::elapsedVTime();
double start = os::elapsedTime();
double vstart = os::elapsedVTime();

log_debug(gc, task, start)("G1 Service Thread (%s) (run)", task->name());
task->execute();

double duration = os::elapsedVTime() - start;
Copy link
Contributor

@tschatzl tschatzl Oct 23, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

use of elapsedVTime() seems wrong here and above as I would only care about wall time between executions.

Copy link
Contributor Author

@kstefanj kstefanj Oct 27, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For walltime between executions you will have to enable gc+task+start to get the start time of tasks and look in the log how long it was between two executions (or have the specific task log this). This is measuring the time it took to execute a task, the reason I use vTime is because a task can join the suspendible thread set, and because of this be waiting for a big part of the execution. Using vTime will then show how much the task really used.

If it should be allowed that a task wait for a GC to complete could of course be changed, and then using wall clock time would work.

Copy link
Contributor

@tschatzl tschatzl Oct 30, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this is confusing wrt to all other similar messages. All other concurrent tasks print wall time from start to end. Also for periodicity control (i.e. did it start and end on time) wall time is typically more interesting.

While it is interesting to know how much cpu resources a task took (and for noticing when your machine is overloaded), it is much more interesting to know when it started and ended in absolute terms to see that it was on time or not. I understand that you can derive this yourselves, but this seems tiresome.

Maybe print both similar to "time" output showing both real time and cpu time? I.e. something like

"G1 Service Thread (%s) %1.3fms (cpu: %1.3fms)", task->name(), ...."

(fwiw I think the existing use of elapsedVTime particularly for limiting marking step length in g1 is wrong)

While we are at logging, JFR logging for the tasks would be interesting for these tasks too. Could you file a new CR for that?

Copy link
Contributor Author

@kstefanj kstefanj Nov 2, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added the double logging and filed JDK-8255740 for the JFR events.

log_debug(gc, task)("G1 Service Thread (%s) (run) %1.3fms", task->name(), duration * MILLIUNITS);
double vduration = os::elapsedVTime() - vstart;
log_debug(gc, task)("G1 Service Thread (%s) (run) %1.3fms (cpu: %1.3fms)",
task->name(), duration * MILLIUNITS, vduration * MILLIUNITS);
}

void G1ServiceThread::run_service() {
@@ -294,12 +303,17 @@ void G1ServiceThread::stop_service() {
G1ServiceTask::G1ServiceTask(const char* name) :
_time(),
_name(name),
_next(NULL) { }
_next(NULL),
_service_thread(NULL) { }

void G1ServiceTask::set_service_thread(G1ServiceThread* thread) {
_service_thread = thread;
}

bool G1ServiceTask::is_registered() {
return _service_thread != NULL;
}

void G1ServiceTask::schedule(jlong delay_ms) {
_service_thread->schedule_task(this, delay_ms);
}
@@ -349,7 +363,7 @@ bool G1ServiceTaskQueue::is_empty() {
void G1ServiceTaskQueue::add_ordered(G1ServiceTask* task) {
assert(task != NULL, "not a valid task");
assert(task->next() == NULL, "invariant");
assert(task->time() != DBL_MAX, "invalid time for task");
assert(task->time() != max_jlong, "invalid time for task");

G1ServiceTask* current = &_sentinel;
while (task->time() >= current->next()->time()) {
@@ -28,27 +28,30 @@
#include "gc/shared/concurrentGCThread.hpp"
#include "runtime/mutex.hpp"

class G1ServiceTaskQueue;
class G1ServiceThread;

class G1ServiceTask : public CHeapObj<mtGC> {
friend class G1ServiceTaskQueue;
friend class G1ServiceThread;

// The next absolute time this task should be executed.
jlong _time;
// Name of the task.
const char* _name;
// Next task in the task queue.
G1ServiceTask* _next;
// The service thread this task is associated with.
// The service thread this task is registered with.
G1ServiceThread* _service_thread;

void set_service_thread(G1ServiceThread* thread);
bool is_registered();

public:
G1ServiceTask(const char* name);
const char* name();
void set_service_thread(G1ServiceThread* thread);

void set_time(jlong time);
jlong time();

void set_next(G1ServiceTask* next);
const char* name();
G1ServiceTask* next();

// Do the actual work for the task. To get added back to the
@@ -59,6 +62,11 @@ class G1ServiceTask : public CHeapObj<mtGC> {
// Schedule the task on the associated service thread
// using the provided delay in milliseconds.
void schedule(jlong delay_ms);

// These setters are protected for use by testing and the
// sentinel task only.
void set_time(jlong time);
void set_next(G1ServiceTask* next);
};

class G1SentinelTask : public G1ServiceTask {
@@ -70,8 +78,8 @@ class G1SentinelTask : public G1ServiceTask {
class G1ServiceTaskQueue {
Copy link
Contributor

@tschatzl tschatzl Oct 30, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe add:
// Time ordered list of tasks to execute.

Copy link
Contributor Author

@kstefanj kstefanj Nov 2, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I find this covered by the comment just below.

// The sentinel task is the entry point of this priority queue holding the
// service tasks. The queue is ordered by the time the tasks are scheduled
// to run and the sentinel task has the time set to DBL_MAX. This guarantees
// that any new task will be added just before the sentinel at the latest.
// to run. To simplify list management the sentinel task has its time set
// to max_jlong, guaranteeing it to be the last task in the queue.
G1SentinelTask _sentinel;

// Verify that the queue is ordered.
@@ -89,6 +97,7 @@ class G1ServiceTaskQueue {
// remembered set lengths of the young generation.
// - check if a periodic GC should be scheduled.
class G1ServiceThread: public ConcurrentGCThread {
friend class G1ServiceTask;
// The monitor is used to ensure thread safety for the task queue
// and allow other threads to signal the service thread to wake up.
Monitor _monitor;
@@ -108,11 +117,15 @@ class G1ServiceThread: public ConcurrentGCThread {
G1ServiceTask* pop_due_task();
void run_task(G1ServiceTask* task);

// Schedule a registered task to run after the given delay.
void schedule_task(G1ServiceTask* task, jlong delay);

public:
G1ServiceThread();
double vtime_accum() { return _vtime_accum; }
// Register a task with the service thread and schedule it. If
// no delay is specified the task is scheduled to run directly.
void register_task(G1ServiceTask* task, jlong delay = 0);
Copy link
Contributor

@tschatzl tschatzl Oct 30, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please add a comment what the delay means, i.e. something like: automatically schedules the task with the given delay.

From what is written here I am actually a bit confused about the difference between register_task() and schedule_task(). One seems to be to use by other threads, and the other one should only be called by a ServiceTask (in context of the ServiceThread).

Do we actually need to make a difference between these two and/or do both need to be public? At first glance I would not be sure who is allowed to call which and what the difference actually is.
It also seems that if either is called by the wrong thread bad things happen. Maybe it is possible to add some asserts to warn about most unintentional misuse?

Copy link
Contributor Author

@kstefanj kstefanj Nov 2, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree these are very similar and as you say it's not good that both are public, I changed this by making G1ServiceTask a friend of G1ServiceThread, so that schedule_task() can be private. Also added short comments to help when only reading the interface.

void schedule_task(G1ServiceTask* task, jlong delay);
};

#endif // SHARE_GC_G1_G1SERVICETHREAD_HPP
@@ -122,7 +122,9 @@ class TestTask : public G1ServiceTask {
set_time(delay);
}
virtual void execute() {}
jlong delay_ms() { return _delay_ms; }
void update_time(jlong now, int multiplier) {
set_time(now + (_delay_ms * multiplier));
}
};

TEST_VM(G1ServiceTaskQueue, add_ordered) {
@@ -144,7 +146,7 @@ TEST_VM(G1ServiceTaskQueue, add_ordered) {
TestTask* task = (TestTask*) queue.pop();
// Update delay multiplier.
task->execute();
task->set_time(now + (task->delay_ms() * multiplier));
task->update_time(now, multiplier);
// All additions will verify that the queue is sorted.
queue.add_ordered(task);
}
@@ -175,7 +177,7 @@ TEST_VM_ASSERT_MSG(G1ServiceTaskQueue, set_time_in_queue,
TestTask a(100);
queue.add_ordered(&a);
// Not allowed to update time while in queue.
a.set_time(500);
a.update_time(500, 1);
}

#endif