GP-0 task time reporting improvement

This commit is contained in:
ghidra1 2021-07-01 15:10:33 -04:00
parent 16a82642b2
commit e87574fb2c

View file

@ -41,7 +41,8 @@ public class ToolTaskManager implements Runnable {
private Map<UndoableDomainObject, PriorityQueue<BackgroundCommand>> queuedCommandsMap = private Map<UndoableDomainObject, PriorityQueue<BackgroundCommand>> queuedCommandsMap =
new HashMap<>(); new HashMap<>();
private Map<UndoableDomainObject, Integer> openForgroundTransactionIDs = new HashMap<>(); private Map<UndoableDomainObject, Integer> openForgroundTransactionIDs = new HashMap<>();
private long start_time = 0; private long startQueueTime = 0;
private long startTaskTime = 0;
private Thread taskThread; private Thread taskThread;
private ThreadGroup taskThreadGroup; private ThreadGroup taskThreadGroup;
private ToolTaskMonitor toolTaskMonitor; private ToolTaskMonitor toolTaskMonitor;
@ -185,7 +186,7 @@ public class ToolTaskManager implements Runnable {
BackgroundCommandTask task = new BackgroundCommandTask(this, obj, cmd); BackgroundCommandTask task = new BackgroundCommandTask(this, obj, cmd);
tasks.addLast(task); tasks.addLast(task);
start_time = System.currentTimeMillis();
if (taskThread != null && taskThread.isAlive()) { if (taskThread != null && taskThread.isAlive()) {
return; return;
} }
@ -297,9 +298,12 @@ public class ToolTaskManager implements Runnable {
@Override @Override
public void run() { public void run() {
try { try {
Msg.debug(this, (new Date()) + " Background processing started...");
startQueueTime = System.currentTimeMillis();
for (BackgroundCommandTask task = getNextTask(); task != null; task = getNextTask()) { for (BackgroundCommandTask task = getNextTask(); task != null; task = getNextTask()) {
Msg.debug(this, "Exec Task " + task.getTaskTitle()); Msg.debug(this, (new Date()) + " Exec Task " + task.getTaskTitle());
startTaskTime = System.currentTimeMillis();
synchronized (this) { synchronized (this) {
currentTask = task; currentTask = task;
@ -315,6 +319,10 @@ public class ToolTaskManager implements Runnable {
task.run(toolTaskMonitor); task.run(toolTaskMonitor);
} }
} }
double totalTime = (System.currentTimeMillis() - startQueueTime) / 1000.00;
Msg.debug(this,
(new Date()) + " Background processing complete (" + totalTime + " secs)");
} }
finally { finally {
synchronized (this) { synchronized (this) {
@ -353,8 +361,9 @@ public class ToolTaskManager implements Runnable {
*/ */
public void taskCompleted(UndoableDomainObject obj, BackgroundCommandTask task, public void taskCompleted(UndoableDomainObject obj, BackgroundCommandTask task,
TaskMonitor monitor) { TaskMonitor monitor) {
double taskTime = (System.currentTimeMillis() - start_time) / 1000.00; double taskTime = (System.currentTimeMillis() - startTaskTime) / 1000.00;
Msg.debug(this, " task finish (" + taskTime + " secs)"); Msg.debug(this,
(new Date()) + " " + task.getTaskTitle() + " task finish (" + taskTime + " secs)");
obj.flushEvents(); obj.flushEvents();
try { try {
while (!monitor.isCancelled()) { while (!monitor.isCancelled()) {
@ -367,13 +376,13 @@ public class ToolTaskManager implements Runnable {
break; break;
} }
} }
Msg.debug(this, " Queue - " + cmd.getName()); Msg.debug(this, (new Date()) + " Queue - " + cmd.getName());
toolTaskMonitor.updateTaskCmd(cmd); toolTaskMonitor.updateTaskCmd(cmd);
long localStart = System.currentTimeMillis(); long localStart = System.currentTimeMillis();
cmd.applyTo(obj, monitor); cmd.applyTo(obj, monitor);
cmd.taskCompleted(); cmd.taskCompleted();
double totalTime = (System.currentTimeMillis() - localStart) / 1000.00; double totalTime = (System.currentTimeMillis() - localStart) / 1000.00;
Msg.debug(this, " (" + totalTime + " secs)"); Msg.debug(this, (new Date()) + " (" + totalTime + " secs)");
obj.flushEvents(); obj.flushEvents();
} }
} }
@ -403,8 +412,9 @@ public class ToolTaskManager implements Runnable {
} }
} }
task.getCommand().taskCompleted(); task.getCommand().taskCompleted();
double totalTime = (System.currentTimeMillis() - start_time) / 1000.00; double totalTime = (System.currentTimeMillis() - startTaskTime) / 1000.00;
Msg.debug(this, " task complete (" + totalTime + " secs)"); Msg.debug(this,
(new Date()) + " " + task.getTaskTitle() + " task complete (" + totalTime + " secs)");
} }
/** /**