Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
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
Copy link
Member

Choose a reason for hiding this comment

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

  1. Remove the FIX (part 1)-sort comments, please. Instead, if something is not obvious at first glance, explain in the rationale, when necessary.
  2. Run linter: ./mvnw spotless:apply -pl :log4j-core
  3. Don't touch/change unrelated lines

Original file line number Diff line number Diff line change
Expand Up @@ -147,12 +147,20 @@ public CronScheduledFuture<?> scheduleWithCron(final CronExpression cronExpressi
public CronScheduledFuture<?> scheduleWithCron(
final CronExpression cronExpression, final Date startDate, final Runnable command) {
final Date fireDate = cronExpression.getNextValidTimeAfter(startDate == null ? new Date() : startDate);

// --- FIX (part 1): prevent race by assigning a placeholder future BEFORE scheduling ---
final CronRunnable runnable = new CronRunnable(command, cronExpression);
final ScheduledFuture<?> future = schedule(runnable, nextFireInterval(fireDate), TimeUnit.MILLISECONDS);
final CronScheduledFuture<?> cronScheduledFuture = new CronScheduledFuture<>(future, fireDate);
CronScheduledFuture<?> cronScheduledFuture = new CronScheduledFuture<>(null, fireDate);
runnable.setScheduledFuture(cronScheduledFuture);
LOGGER.debug(
"{} scheduled cron expression {} to fire at {}", name, cronExpression.getCronExpression(), fireDate);

// schedule and then update the placeholder with the real ScheduledFuture
final ScheduledFuture<?> future =
schedule(runnable, nextFireInterval(fireDate), TimeUnit.MILLISECONDS);
cronScheduledFuture.reset(future, fireDate);
// --- end fix ---

LOGGER.debug("{} scheduled cron expression {} to fire at {}", name,
cronExpression.getCronExpression(), fireDate);
return cronScheduledFuture;
}

Expand Down Expand Up @@ -231,33 +239,47 @@ public void setScheduledFuture(final CronScheduledFuture<?> future) {
@Override
public void run() {
try {
final long millis = scheduledFuture.getFireTime().getTime() - System.currentTimeMillis();
if (millis > 0) {
LOGGER.debug("{} Cron thread woke up {} millis early. Sleeping", name, millis);
try {
Thread.sleep(millis);
} catch (final InterruptedException ie) {
// Ignore the interruption.
// --- FIX (part 2): guard against null scheduledFuture on first execution ---
final CronScheduledFuture<?> localFuture = this.scheduledFuture;
if (localFuture != null) {
final long millis = localFuture.getFireTime().getTime() - System.currentTimeMillis();
if (millis > 0) {
LOGGER.debug("{} Cron thread woke up {} millis early. Sleeping", name, millis);
try {
Thread.sleep(millis);
} catch (final InterruptedException ie) {
// Ignore the interruption.
}
}
}
// --- end fix ---

runnable.run();
} catch (final Throwable ex) {
LOGGER.error("{} caught error running command", name, ex);
} finally {
final Date fireDate = cronExpression.getNextValidTimeAfter(new Date());
final ScheduledFuture<?> future = schedule(this, nextFireInterval(fireDate), TimeUnit.MILLISECONDS);
LOGGER.debug(
"{} Cron expression {} scheduled to fire again at {}",
name,
cronExpression.getCronExpression(),
fireDate);
scheduledFuture.reset(future, fireDate);
final ScheduledFuture<?> future =
schedule(this, nextFireInterval(fireDate), TimeUnit.MILLISECONDS);
LOGGER.debug("{} Cron expression {} scheduled to fire again at {}",
name, cronExpression.getCronExpression(), fireDate);

// --- FIX (part 3): reset safely even if first execution had no future assigned ---
final CronScheduledFuture<?> currentFuture = this.scheduledFuture;
if (currentFuture != null) {
currentFuture.reset(future, fireDate);
} else {
setScheduledFuture(new CronScheduledFuture<>(future, fireDate));
}
// --- end fix ---
}
}

@Override
public String toString() {
return "CronRunnable{" + cronExpression.getCronExpression() + " - " + scheduledFuture.getFireTime();
final CronScheduledFuture<?> f = this.scheduledFuture;
return "CronRunnable{" + cronExpression.getCronExpression() + " - "
+ (f != null ? f.getFireTime() : "unassigned") + "}";
}
}

Expand Down
Copy link
Member

Choose a reason for hiding this comment

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

Would you implement the following changes, please?

  1. This test is not effective. That is, it even passes without the fix. Could you make sure this test fails without the fix?
  2. Could you move this test from log4j-core/src/test to log4j-core-test/src/test?
  3. Could you add the license header?
  4. Could you make sure ./mvnw verify -pl :log4j-core,:log4j-core-test passes before submitting your changes?

Original file line number Diff line number Diff line change
@@ -0,0 +1,32 @@
package org.apache.logging.log4j.core.config;

import org.junit.Test;
import static org.junit.Assert.assertTrue;

import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;

import org.apache.logging.log4j.core.util.CronExpression;

public class CronSchedulerNpeTest {

@Test
public void testCronSchedulerDoesNotThrowNpe() throws Exception {
ConfigurationScheduler scheduler = new ConfigurationScheduler();
scheduler.incrementScheduledItems(); // ensure a pool exists
scheduler.start();

// fire every second
CronExpression cron = new CronExpression("* * * * * ?");
AtomicBoolean ran = new AtomicBoolean(false);

scheduler.scheduleWithCron(cron, () -> ran.set(true));

// wait up to 2 seconds for the first fire; if an NPE happens, the test will fail
Thread.sleep(2000L);

scheduler.stop(0, TimeUnit.MILLISECONDS);

assertTrue("cron task should have executed at least once", ran.get());
}
}