Skip to content
Permalink
Browse files
[JENKINS-41517] More consistent logging
  • Loading branch information
stephenc committed Jan 27, 2017
1 parent 9d5cd18 commit 7e131c4eed023755fbf7ccae7930c852db799c8a
Showing with 37 additions and 20 deletions.
  1. +12 −12 src/main/java/jenkins/branch/MultiBranchProject.java
  2. +25 −8 src/main/java/jenkins/branch/OrganizationFolder.java
@@ -1231,8 +1231,8 @@ private int processHeadCreate(SCMHeadEvent<?> event, TaskListener global, String
listener = new LogTaskListener(LOGGER, Level.FINE);
}
long start = System.currentTimeMillis();
listener.getLogger().format("[%tc] Received %s event with timestamp %tc%n",
start, eventType, eventTimestamp);
listener.getLogger().format("[%tc] Received %s %s event with timestamp %tc%n",
start, eventClass, eventType, eventTimestamp);
ChildObserver childObserver = p.createEventsChildObserver();
try {
for (SCMSource source : p.getSCMSources()) {
@@ -1255,8 +1255,8 @@ private int processHeadCreate(SCMHeadEvent<?> event, TaskListener global, String
e.printStackTrace(listener.error(e.getMessage()));
} finally {
long end = System.currentTimeMillis();
listener.getLogger().format("[%tc] %s event processed in %s%n",
end, eventType, Util.getTimeSpanString(end - start));
listener.getLogger().format("[%tc] %s %s event processed in %s%n",
end, eventClass, eventType, Util.getTimeSpanString(end - start));
}
}
}
@@ -1456,8 +1456,8 @@ private int processHeadUpdate(SCMHeadEvent<?> event, TaskListener global, String
listener = new LogTaskListener(LOGGER, Level.FINE);
}
long start = System.currentTimeMillis();
listener.getLogger().format("[%tc] Received %s event with timestamp %tc%n",
start, eventType, eventTimestamp);
listener.getLogger().format("[%tc] Received %s %s event with timestamp %tc%n",
start, eventClass, eventType, eventTimestamp);
ChildObserver childObserver = p.createEventsChildObserver();
try {
for (Map.Entry<SCMSource, SCMHead> m : matches.entrySet()) {
@@ -1503,8 +1503,8 @@ private int processHeadUpdate(SCMHeadEvent<?> event, TaskListener global, String
e.printStackTrace(listener.error(e.getMessage()));
} finally {
long end = System.currentTimeMillis();
listener.getLogger().format("[%tc] %s event processed in %s%n",
end, eventType, Util.getTimeSpanString(end - start));
listener.getLogger().format("[%tc] %s %s event processed in %s%n",
end, eventClass, eventType, Util.getTimeSpanString(end - start));
}
} else {
// didn't match an existing branch, maybe the criteria now match against an updated branch
@@ -1533,8 +1533,8 @@ private int processHeadUpdate(SCMHeadEvent<?> event, TaskListener global, String
listener = new LogTaskListener(LOGGER, Level.FINE);
}
long start = System.currentTimeMillis();
listener.getLogger().format("[%tc] Received %s event with timestamp %tc%n",
start, eventType, eventTimestamp);
listener.getLogger().format("[%tc] Received %s %s event with timestamp %tc%n",
start, eventClass, eventType, eventTimestamp);
ChildObserver childObserver = p.createEventsChildObserver();
try {
for (SCMSource source : p.getSCMSources()) {
@@ -1558,8 +1558,8 @@ private int processHeadUpdate(SCMHeadEvent<?> event, TaskListener global, String
e.printStackTrace(listener.error(e.getMessage()));
} finally {
long end = System.currentTimeMillis();
listener.getLogger().format("[%tc] %s event processed in %s%n",
end, eventType, Util.getTimeSpanString(end - start));
listener.getLogger().format("[%tc] %s %s event processed in %s%n",
end, eventClass, eventType, Util.getTimeSpanString(end - start));
}
}
}
@@ -934,16 +934,17 @@ public void onSCMHeadEvent(SCMHeadEvent<?> event) {
}
ChildObserver childObserver = p.createEventsChildObserver();
long start = System.currentTimeMillis();
listener.getLogger().format("[%tc] Received %s event with timestamp %tc%n",
start, event.getType().name(), event.getTimestamp());
listener.getLogger().format("[%tc] Received %s %s event with timestamp %tc%n",
start, event.getClass().getName(), event.getType().name(), event.getTimestamp());
try {
navigator.visitSources(p.new SCMSourceObserverImpl(listener, childObserver, event), event);
} catch (IOException | InterruptedException e) {
e.printStackTrace(listener.error(e.getMessage()));
} finally {
long end = System.currentTimeMillis();
listener.getLogger().format("[%tc] %s event processed in %s%n",
end, event.getType().name(), Util.getTimeSpanString(end - start));
listener.getLogger().format("[%tc] %s %s event processed in %s%n",
end, event.getClass().getName(), event.getType().name(),
Util.getTimeSpanString(end - start));
}
}
}
@@ -959,6 +960,11 @@ public void onSCMHeadEvent(SCMHeadEvent<?> event) {
*/
@Override
public void onSCMNavigatorEvent(SCMNavigatorEvent<?> event) {
TaskListener global = globalEventsListener();
global.getLogger().format("[%tc] Received %s %s event with timestamp %tc%n",
System.currentTimeMillis(), event.getClass().getName(), event.getType().name(),
event.getTimestamp());
int matchCount = 0;
if (UPDATED == event.getType()) {
Set<SCMNavigator> matches = new HashSet<>();
for (OrganizationFolder p : Jenkins.getActiveInstance().getAllItems(OrganizationFolder.class)) {
@@ -969,6 +975,7 @@ public void onSCMNavigatorEvent(SCMNavigatorEvent<?> event) {
}
}
if (!matches.isEmpty()) {
matchCount++;
TaskListener listener;
try {
listener = p.getComputation().createEventsListener();
@@ -1014,6 +1021,9 @@ public void onSCMNavigatorEvent(SCMNavigatorEvent<?> event) {
}
}
}
global.getLogger().format("[%tc] Finished processing %s %s event with timestamp %tc. Matched %d.%n",
System.currentTimeMillis(), event.getClass().getName(), event.getType().name(),
event.getTimestamp(), matchCount);
}

/**
@@ -1025,6 +1035,7 @@ public void onSCMSourceEvent(SCMSourceEvent<?> event) {
global.getLogger().format("[%tc] Received %s %s event with timestamp %tc%n",
System.currentTimeMillis(), event.getClass().getName(), event.getType().name(),
event.getTimestamp());
int matchCount = 0;
if (CREATED == event.getType()) {
for (OrganizationFolder p : Jenkins.getActiveInstance().getAllItems(OrganizationFolder.class)) {
boolean haveMatch = false;
@@ -1036,6 +1047,7 @@ public void onSCMSourceEvent(SCMSourceEvent<?> event) {
}
}
if (haveMatch) {
matchCount++;
TaskListener listener;
try {
listener = p.getComputation().createEventsListener();
@@ -1044,8 +1056,8 @@ public void onSCMSourceEvent(SCMSourceEvent<?> event) {
}
ChildObserver childObserver = p.createEventsChildObserver();
long start = System.currentTimeMillis();
listener.getLogger().format("[%tc] Received %s event with timestamp %tc%n",
start, event.getType().name(), event.getTimestamp());
listener.getLogger().format("[%tc] Received %s %s event with timestamp %tc%n",
start, event.getClass().getName(), event.getType().name(), event.getTimestamp());
try {
for (SCMNavigator n : p.getSCMNavigators()) {
if (event.isMatch(n)) {
@@ -1060,13 +1072,18 @@ public void onSCMSourceEvent(SCMSourceEvent<?> event) {
e.printStackTrace(listener.error(e.getMessage()));
} finally {
long end = System.currentTimeMillis();
listener.getLogger().format("[%tc] %s event processed in %s%n",
end, event.getType().name(), Util.getTimeSpanString(end - start));
listener.getLogger().format("[%tc] %s %s event processed in %s%n",
end, event.getClass().getName(), event.getType().name(),
Util.getTimeSpanString(end - start));
}

}
}
}
global.getLogger().format("[%tc] Finished processing %s %s event with timestamp %tc. Matched %d.%n",
System.currentTimeMillis(), event.getClass().getName(), event.getType().name(),
event.getTimestamp(), matchCount);

}
}

0 comments on commit 7e131c4

Please sign in to comment.