diff --git a/core/src/main/java/hudson/model/AsyncAperiodicWork.java b/core/src/main/java/hudson/model/AsyncAperiodicWork.java index 9111e5fd474d5536879c86180272737fe26aa67c..ba8ca4aecec4b9a129ae0e3d46a89d221f4f1f34 100644 --- a/core/src/main/java/hudson/model/AsyncAperiodicWork.java +++ b/core/src/main/java/hudson/model/AsyncAperiodicWork.java @@ -25,11 +25,11 @@ package hudson.model; import hudson.security.ACL; import hudson.util.StreamTaskListener; - import java.io.File; import java.io.IOException; +import java.util.Date; +import java.util.concurrent.TimeUnit; import java.util.logging.Level; - import jenkins.model.Jenkins; /** @@ -40,8 +40,46 @@ import jenkins.model.Jenkins; * @since 1.410 */ public abstract class AsyncAperiodicWork extends AperiodicWork { - - /** + /** + * The default number of minutes after which to try and rotate the log file used by {@link #createListener()}. + * This value is controlled by the system property {@code hudson.model.AsyncAperiodicWork.logRotateMinutes}. + * Each individual AsyncAperiodicWork can also have a per-extension override using the system property + * based on their fully qualified class name with {@code .logRotateMinutes} appended. + * + * @since 1.650 + */ + private static Long LOG_ROTATE_MINUTES = Long.getLong(AsyncAperiodicWork.class.getName() + ".logRotateMinutes", + TimeUnit.DAYS.toMinutes(1)); + /** + * The default file size after which to try and rotate the log file used by {@link #createListener()}. + * A value of {@code -1L} disables rotation based on file size. + * This value is controlled by the system property {@code hudson.model.AsyncAperiodicWork.logRotateSize}. + * Each individual AsyncAperiodicWork can also have a per-extension override using the system property + * based on their fully qualified class name with {@code .logRotateSize} appended. + * + * @since 1.650 + */ + private static Long LOG_ROTATE_SIZE = Long.getLong(AsyncAperiodicWork.class.getName() + ".logRotateSize", -1L); + /** + * The number of milliseconds (since startup or previous rotation) after which to try and rotate the log file. + * + * @since 1.650 + */ + private final long logRotateMillis; + /** + * {@code -1L} disabled file size based log rotation, otherwise when starting an {@link #execute(TaskListener)}, + * if the log file size is above this number of bytes then the log file will be rotated beforehand. + * + * @since 1.650 + */ + private final long logRotateSize; + /** + * The last time the log files were rotated. + * + * @since 1.650 + */ + private Long lastRotateMillis; + /** * Name of the work. */ public final String name; @@ -50,6 +88,9 @@ public abstract class AsyncAperiodicWork extends AperiodicWork { protected AsyncAperiodicWork(String name) { this.name = name; + this.logRotateMillis = TimeUnit.MINUTES.toMillis( + Long.getLong(getClass().getName()+".logRotateMinutes", LOG_ROTATE_MINUTES)); + this.logRotateSize = Long.getLong(getClass().getName() +".logRotateSize", LOG_ROTATE_SIZE); } /** @@ -59,19 +100,25 @@ public abstract class AsyncAperiodicWork extends AperiodicWork { public final void doAperiodicRun() { try { if(thread!=null && thread.isAlive()) { - logger.log(Level.INFO, name+" thread is still running. Execution aborted."); + logger.log(getSlowLoggingLevel(), name+" thread is still running. Execution aborted."); return; } thread = new Thread(new Runnable() { public void run() { - logger.log(Level.INFO, "Started "+name); + logger.log(getNormalLoggingLevel(), "Started "+name); long startTime = System.currentTimeMillis(); StreamTaskListener l = createListener(); try { + l.getLogger().printf("Started at %tc%n", new Date(startTime)); ACL.impersonate(ACL.SYSTEM); - execute(l); + try { + execute(l); + } finally { + long stopTime = System.currentTimeMillis(); + l.getLogger().printf("Finished at %tc. %dms%n", new Date(stopTime), stopTime - startTime); + } } catch (IOException e) { e.printStackTrace(l.fatalError(e.getMessage())); } catch (InterruptedException e) { @@ -80,8 +127,8 @@ public abstract class AsyncAperiodicWork extends AperiodicWork { l.closeQuietly(); } - logger.log(Level.INFO, "Finished "+name+". "+ - (System.currentTimeMillis()-startTime)+" ms"); + logger.log(getNormalLoggingLevel(), "Finished {0}. {1,number} ms", + new Object[]{name, System.currentTimeMillis() - startTime}); } },name+" thread"); thread.start(); @@ -91,8 +138,34 @@ public abstract class AsyncAperiodicWork extends AperiodicWork { } protected StreamTaskListener createListener() { + File f = getLogFile(); + if (f.isFile()) { + if ((lastRotateMillis == null) + || (lastRotateMillis + logRotateMillis < System.currentTimeMillis()) + || (logRotateSize > 0 && f.length() > logRotateSize)) { + lastRotateMillis = System.currentTimeMillis(); + File p = null; + for (int i = 5; i >= 0; i--) { + File o = i == 0 ? f : new File(f.getParentFile(), f.getName() + "." + i); + if (o.isFile()) { + if (p != null && !p.exists()) { + if (!o.renameTo(p)) { + logger.log(getErrorLoggingLevel(), "Could not rotate log files {0} to {1}", + new Object[]{o, p}); + } + } else { + if (!o.delete()) { + logger.log(getErrorLoggingLevel(), "Could not delete log files {0} to enable rotation", + o); + } + } + p = o; + } + } + } + } try { - return new StreamTaskListener(getLogFile()); + return new StreamTaskListener(f, true, null); } catch (IOException e) { throw new Error(e); } @@ -105,6 +178,36 @@ public abstract class AsyncAperiodicWork extends AperiodicWork { return new File(Jenkins.getInstance().getRootDir(),name+".log"); } + /** + * Returns the logging level at which normal messages are displayed. + * + * @return The logging level. + * @since 1.650 + */ + protected Level getNormalLoggingLevel() { + return Level.INFO; + } + + /** + * Returns the logging level at which previous task still executing messages is displayed. + * + * @return The logging level. + * @since 1.650 + */ + protected Level getSlowLoggingLevel() { + return getNormalLoggingLevel(); + } + + /** + * Returns the logging level at which error messages are displayed. + * + * @return The logging level. + * @since 1.650 + */ + protected Level getErrorLoggingLevel() { + return Level.SEVERE; + } + /** * Executes the task. * diff --git a/core/src/main/java/hudson/model/AsyncPeriodicWork.java b/core/src/main/java/hudson/model/AsyncPeriodicWork.java index 9444887b5b1c262818920df69006021e291e5559..4ac18552a597360e3f877622fdd3d17508b84b3e 100644 --- a/core/src/main/java/hudson/model/AsyncPeriodicWork.java +++ b/core/src/main/java/hudson/model/AsyncPeriodicWork.java @@ -2,12 +2,13 @@ package hudson.model; import hudson.security.ACL; import hudson.util.StreamTaskListener; -import jenkins.model.Jenkins; - import java.io.File; import java.io.IOException; +import java.util.Date; +import java.util.concurrent.TimeUnit; import java.util.logging.Level; import java.util.logging.LogRecord; +import jenkins.model.Jenkins; /** * {@link PeriodicWork} that takes a long time to run. @@ -20,6 +21,45 @@ import java.util.logging.LogRecord; * @author Kohsuke Kawaguchi */ public abstract class AsyncPeriodicWork extends PeriodicWork { + /** + * The default number of minutes after which to try and rotate the log file used by {@link #createListener()}. + * This value is controlled by the system property {@code hudson.model.AsyncPeriodicWork.logRotateMinutes}. + * Each individual AsyncPeriodicWork can also have a per-extension override using the system property + * based on their fully qualified class name with {@code .logRotateMinutes} appended. + * + * @since 1.650 + */ + private static Long LOG_ROTATE_MINUTES = Long.getLong(AsyncPeriodicWork.class.getName() + ".logRotateMinutes", + TimeUnit.DAYS.toMinutes(1)); + /** + * The default file size after which to try and rotate the log file used by {@link #createListener()}. + * A value of {@code -1L} disables rotation based on file size. + * This value is controlled by the system property {@code hudson.model.AsyncPeriodicWork.logRotateSize}. + * Each individual AsyncPeriodicWork can also have a per-extension override using the system property + * based on their fully qualified class name with {@code .logRotateSize} appended. + * + * @since 1.650 + */ + private static Long LOG_ROTATE_SIZE = Long.getLong(AsyncPeriodicWork.class.getName() + ".logRotateSize", -1L); + /** + * The number of milliseconds (since startup or previous rotation) after which to try and rotate the log file. + * + * @since 1.650 + */ + private final long logRotateMillis; + /** + * {@code -1L} disabled file size based log rotation, otherwise when starting an {@link #execute(TaskListener)}, + * if the log file size is above this number of bytes then the log file will be rotated beforehand. + * + * @since 1.650 + */ + private final long logRotateSize; + /** + * The last time the log files were rotated. + * + * @since 1.650 + */ + private Long lastRotateMillis; /** * Human readable name of the work. */ @@ -29,6 +69,9 @@ public abstract class AsyncPeriodicWork extends PeriodicWork { protected AsyncPeriodicWork(String name) { this.name = name; + this.logRotateMillis = TimeUnit.MINUTES.toMillis( + Long.getLong(getClass().getName() + ".logRotateMinutes", LOG_ROTATE_MINUTES)); + this.logRotateSize = Long.getLong(getClass().getName() + ".logRotateSize", LOG_ROTATE_SIZE); } /** @@ -48,9 +91,15 @@ public abstract class AsyncPeriodicWork extends PeriodicWork { StreamTaskListener l = createListener(); try { + l.getLogger().printf("Started at %tc%n", new Date(startTime)); ACL.impersonate(ACL.SYSTEM); - execute(l); + try { + execute(l); + } finally { + long stopTime = System.currentTimeMillis(); + l.getLogger().printf("Finished at %tc. %dms%n", new Date(stopTime), stopTime - startTime); + } } catch (IOException e) { e.printStackTrace(l.fatalError(e.getMessage())); } catch (InterruptedException e) { @@ -60,7 +109,7 @@ public abstract class AsyncPeriodicWork extends PeriodicWork { } logger.log(getNormalLoggingLevel(), "Finished {0}. {1,number} ms", - new Object[]{name, (System.currentTimeMillis()-startTime)}); + new Object[]{name, System.currentTimeMillis() - startTime}); } },name+" thread"); thread.start(); @@ -73,8 +122,34 @@ public abstract class AsyncPeriodicWork extends PeriodicWork { } protected StreamTaskListener createListener() { + File f = getLogFile(); + if (f.isFile()) { + if ((lastRotateMillis == null) + || (lastRotateMillis + logRotateMillis < System.currentTimeMillis()) + || (logRotateSize > 0 && f.length() > logRotateSize)) { + lastRotateMillis = System.currentTimeMillis(); + File p = null; + for (int i = 5; i >= 0; i--) { + File o = i == 0 ? f : new File(f.getParentFile(), f.getName() + "." + i); + if (o.isFile()) { + if (p != null && !p.exists()) { + if (!o.renameTo(p)) { + logger.log(getErrorLoggingLevel(), "Could not rotate log files {0} to {1}", + new Object[]{o, p}); + } + } else { + if (!o.delete()) { + logger.log(getErrorLoggingLevel(), "Could not delete log files {0} to enable rotation", + o); + } + } + p = o; + } + } + } + } try { - return new StreamTaskListener(getLogFile()); + return new StreamTaskListener(f, true, null); } catch (IOException e) { throw new Error(e); } diff --git a/core/src/main/java/hudson/util/StreamTaskListener.java b/core/src/main/java/hudson/util/StreamTaskListener.java index 4d6aea568d74bce91f31172e5150c0a866ebb2b6..ed97a89ae1bff34043459391eb1b2e37a750b120 100644 --- a/core/src/main/java/hudson/util/StreamTaskListener.java +++ b/core/src/main/java/hudson/util/StreamTaskListener.java @@ -98,6 +98,13 @@ public class StreamTaskListener extends AbstractTaskListener implements Serializ this(new FileOutputStream(out),charset); } + public StreamTaskListener(File out, boolean append, Charset charset) throws IOException { + // don't do buffering so that what's written to the listener + // gets reflected to the file immediately, which can then be + // served to the browser immediately + this(new FileOutputStream(out, append),charset); + } + public StreamTaskListener(Writer w) throws IOException { this(new WriterOutputStream(w)); }