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.

Sign up for GitHub

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

Jump to bottom

[JENKINS-42556] Improved logging for Queue #2791

Merged
merged 1 commit into from
Mar 11, 2017
Merged

[JENKINS-42556] Improved logging for Queue #2791

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 10 additions & 4 deletions core/src/main/java/hudson/model/Queue.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -728,7 +728,11 @@ public boolean cancel(Task p) {
}

private void updateSnapshot() {
snapshot = new Snapshot(waitingList, blockedProjects, buildables, pendings);
Snapshot revised = new Snapshot(waitingList, blockedProjects, buildables, pendings);
if (LOGGER.isLoggable(Level.FINEST)) {
LOGGER.log(Level.FINEST, "{0} → {1}; leftItems={2}", new Object[] {snapshot, revised, leftItems.asMap()});
Copy link
Member Author

Choose a reason for hiding this comment

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

Generally handy to know when the state of the queue changes, for whatever reason.

}
snapshot = revised;
}

public boolean cancel(Item item) {
Expand Down Expand Up @@ -1443,9 +1447,11 @@ public void maintain() {
}
// pending -> buildable
for (BuildableItem p: lostPendings) {
LOGGER.log(Level.FINE,
if (LOGGER.isLoggable(Level.FINE)) {
Copy link
Member Author

Choose a reason for hiding this comment

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

Avoid computing getFullDisplayName if we do not have to.

Copy link
Member Author

Choose a reason for hiding this comment

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

Note that there are more cases of this optimization that could be done; I just picked some sample cases.

Copy link
Member Author

Choose a reason for hiding this comment

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

#2947

LOGGER.log(Level.FINE,
"BuildableItem {0}: pending -> buildable as the assigned executor disappeared",
p.task.getFullDisplayName());
}
p.isPending = false;
pendings.remove(p);
makeBuildable(p); // TODO whatever this is for, the return value is being ignored, so this does nothing at all
Expand All @@ -1464,7 +1470,7 @@ public void maintain() {
Collections.sort(blockedItems, QueueSorter.DEFAULT_BLOCKED_ITEM_COMPARATOR);
}
for (BlockedItem p : blockedItems) {
String taskDisplayName = p.task.getFullDisplayName();
String taskDisplayName = LOGGER.isLoggable(Level.FINEST) ? p.task.getFullDisplayName() : null;
Copy link
Member Author

Choose a reason for hiding this comment

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

I recommended @christ66 do this in #1863 but he did not. Turns out this had a far worse consequence than wasting a bit of CPU time, which will become clearer in another PR.

LOGGER.log(Level.FINEST, "Current blocked item: {0}", taskDisplayName);
if (!isBuildBlocked(p) && allowNewBuildableTask(p.task)) {
LOGGER.log(Level.FINEST,
Expand Down Expand Up @@ -1499,7 +1505,7 @@ public void maintain() {
if (!isBuildBlocked(top) && allowNewBuildableTask(p)) {
// ready to be executed immediately
Runnable r = makeBuildable(new BuildableItem(top));
String topTaskDisplayName = top.task.getFullDisplayName();
String topTaskDisplayName = LOGGER.isLoggable(Level.FINEST) ? top.task.getFullDisplayName() : null;
if (r != null) {
LOGGER.log(Level.FINEST, "Executing runnable {0}", topTaskDisplayName);
r.run();
Expand Down