Java Timer/TimerTask - fire event if message not received

Question

I have the following code whose purpose is to increment a prometheus counter if periodic calls stop coming to messageReceived():

...

    private static final int tenMinutes = 10 * 60 * 1000;
    private Timer timer = new Timer();
    private boolean newTimer = false;

...
    public void messageReceived() {

        timer.cancel();
        timer = new Timer();
        newTimer = true;

        TimerTask action = new TimerTask() {
            public void run() {
                if (!newTimer)
                    counter.increment();
                else
                    newTimer = false;
            }

        };

        timer.schedule(action, tenMinutes, tenMinutes);

    }

  ...

The goal is to set a timer that will only fire an action if a new event is not received. Every time messageReceived() is called before ten minutes have passed, the timer should be cancelled so it will not fire.

What I am seeing happen is pretty much exactly every ten minutes the action fires, even though messageReceived is called more than once per minute.

MessageReceived is called from a service so its not called on the same thread every time, but messageReceived is inside a singleton. I am not sure, but I would think that if multithreading was the problem, I would see many firings of "action" and not just one every 10 minutes.

Answer 1

I think you do have a multi-threading problem, just like SnowmanXL said. Here is a simple MCVE reproducing the problem:

import java.text.SimpleDateFormat;
import java.util.*;

class MiscellaneousMonitor {
  private static SimpleDateFormat dateFormat = new SimpleDateFormat("HH:mm:ss.SSS");

  private boolean isRunning;
  private Counter counter;
  private static final int tenMinutes = /*10 * 60 **/ 1000;
  private Timer timer = new Timer();
  private boolean newTimer = false;

  static class Counter {
    private int count = 0;

    public /*synchronized*/ void increment() {
      count++;
    }
  }

  public /*synchronized*/ void start() {
    counter = new Counter();
    isRunning = true;
  }

  public /*synchronized*/ void messageReceived() {
    timer.cancel();
    timer = new Timer();
    newTimer = true;
    TimerTask action = new TimerTask() {
      public void run() {
        System.out.println(dateFormat.format(new Date()) + " Timer task running: " + this);
        if (!newTimer)
          counter.increment();
        else
          newTimer = false;
      }
    };
    timer.schedule(action, tenMinutes, tenMinutes);
  }

  public /*synchronized*/ void stop() {
    timer.cancel();
    isRunning = false;
  }

  public /*synchronized*/ boolean isRunning() {
    return isRunning;
  }

  public static void main(String[] args) throws InterruptedException {
    MiscellaneousMonitor monitor = new MiscellaneousMonitor();
    monitor.start();
    Queue<Thread> threads = new LinkedList<>();
    for (int t = 0; t < 10; t++) {
      Thread thread = new Thread(() -> {
        for (int i = 0; i < 10; i++) {
          try { Thread.sleep(150); } catch (InterruptedException e) { e.printStackTrace(); }
          monitor.messageReceived();
        }
        try { Thread.sleep(1500); } catch (InterruptedException e) { e.printStackTrace(); }
      });
      thread.start();
      threads.add(thread);
    }
    while (!threads.isEmpty()) {
      threads.poll().join();
    }
    monitor.stop();
  }
}

The console log will look something like this:

Exception in thread "Thread-4" java.lang.IllegalStateException: Timer already cancelled.
    at java.base/java.util.Timer.sched(Timer.java:398)
    at java.base/java.util.Timer.schedule(Timer.java:249)
    at MiscellaneousMonitor.messageReceived(scratch_3.java:39)
    at MiscellaneousMonitor.lambda$main$0(scratch_3.java:59)
    at java.base/java.lang.Thread.run(Thread.java:832)
09:25:58.147 Timer task running: MiscellaneousMonitor$1@1ce7fd7d
09:25:58.142 Timer task running: MiscellaneousMonitor$1@7ba42a49
09:25:58.147 Timer task running: MiscellaneousMonitor$1@493cb0eb
09:25:58.147 Timer task running: MiscellaneousMonitor$1@6f9a3afe
09:25:58.148 Timer task running: MiscellaneousMonitor$1@1d86f308
Exception in thread "Thread-9" java.lang.IllegalStateException: Timer already cancelled.
    at java.base/java.util.Timer.sched(Timer.java:398)
    at java.base/java.util.Timer.schedule(Timer.java:249)
    at MiscellaneousMonitor.messageReceived(scratch_3.java:39)
    at MiscellaneousMonitor.lambda$main$0(scratch_3.java:59)
    at java.base/java.lang.Thread.run(Thread.java:832)
09:25:58.445 Timer task running: MiscellaneousMonitor$1@53c65632
09:25:58.445 Timer task running: MiscellaneousMonitor$1@6ce24daa
09:25:58.445 Timer task running: MiscellaneousMonitor$1@784b861f
09:25:58.447 Timer task running: MiscellaneousMonitor$1@783528c9
09:25:58.447 Timer task running: MiscellaneousMonitor$1@2cc4944f
09:25:58.597 Timer task running: MiscellaneousMonitor$1@711e91d9
09:25:58.597 Timer task running: MiscellaneousMonitor$1@19ddcb88
09:25:58.597 Timer task running: MiscellaneousMonitor$1@5fbdc1a8
(...)

Sometimes you see the execeptions, sometimes not, depending on the timing when you run the program. But even if you do not see any exceptions, multiple timer tasks - MiscellaneousMonitor$1 is the internal name of the anonymous TimerTask instance - will log forever and never be cancelled, which is why the program continues to run forever until you kill it, despite you calling join() on all running tasks. But there are still rogue TimerTasks.

Now if you uncomment all synchronized keywords where I put them in the code, your console log will change to the expected

09:31:44.880 Timer task running: MiscellaneousMonitor$1@4f963263

and the program will terminate.

P.S.: You maybe could synchronise on smaller sections of code instead of on whole methods, I did not analyse that. I just showed you the basic problem of thread unsafety with your singleton which is accessed by multiple other threads, like you said.