0

I have deployed java service application on linux using apache jsvc. It's a multithread application, however when daemon stop is initiated, it kills jvm before all threads are finished.

It goes like this:

  1. WorkerLauncher which implements daemon interface, starts service
  2. WorkerPool class initiates parent thread and worker (child) threads that are represented by Worker class.
  3. When WorkerLauncher stop is called, WorkerPool thread is interrupt and this InterruptedException is caught, where child threads are interrupted as well.
  4. When child thread is interrupted, it performs calculations before stopping. This is where it goes wrong: calculations are not finished before thread is killed I guess (not quite sure here).

WorkerLauncher

public class WorkerLauncher implements Daemon {
    private static final Logger log = LoggerFactory.getLogger("com.worker");

    private WorkerPool pool;

    @Override
    public void init(DaemonContext context) {
    }

    @Override
    public void start()  {
        log.info("Starting worker pool...");
        if (pool == null) pool = new WorkerPool();
        pool.start();
        log.info("Worker pool started");
    }

    @Override
    public void stop(){
        pool.stop();
    }

    @Override
    public void destroy() {
        pool = null;
    }
}

WorkerPool

public class WorkerPool implements Runnable {
    private static final Logger log = LoggerFactory.getLogger("com.worker");

    private Thread thread = null;

    private List<Thread> workers = new ArrayList<Thread>();

    public WorkerPool() {
        for (int i = 0; i < 1; i++) workers.add(new Thread(new Worker("Worker "+i), "Worker "+i));
        this.thread = new Thread(this, "Worker Main");
    }

    @Override
    public void run() {
        for (Thread thread : workers) {
            thread.start();
        }

        while (isRunning()) {
            try {
                Thread.sleep(1000);
            } catch (InterruptedException e) {
                log.info("Worker pool stopping");
                for (Thread worker : workers) {
                    worker.interrupt();
                }
                break;
            }
        }
    }

    public boolean isRunning() {
        return !thread.isInterrupted();
    }

    public void stop() {
        thread.interrupt();
    }

    public void start() {
        thread.start();
    }
}

Worker

public class Worker implements Runnable{
    private static final Logger log = LoggerFactory.getLogger("com.worker");

    private String name;

    public Worker(String name) {
        this.name = name;
    }

    private void stop() {
        longCalculations();
        log.info("Worker {] stopped", name);
    }

    @Override
    public void run() {
        try {
            try {
                while (true) {
                    Thread.sleep(1000);
                }
            } catch (InterruptedException e) {
                log.info("InterruptedException");
            }
        } finally {
            stop();
        }
    }

    private void longCalculations() {
        for (int i = 0; i < 99999; i++) {
            for (int j = 0; j < 9999; j++) {
                Math.round(i + j * 0.999);
            }
        }
    }

}

This is just an example from real application, but with this I reproduce the same issue. commons-daemon 1.1 and 1.2 versions tested. If long calculations are removed or made to last shorter (better performance) everything works. What am I missing here? Any ideas?

Here's how log output looks like:

07:55:10.790 (      main) INFO  Starting worker pool...
07:55:10.791 (      main) INFO  Worker pool started
07:55:34.056 (Worker Main) INFO  Worker pool stopping
07:55:34.057 (  Worker 0) INFO  InterruptedException

Note how Worker {] stopped is missing. And in real application 3rd party process that was started by worker is still running, which can be seen in ps -A even if jsvc does not show in processes.

EDIT

Modified stop() method:

private void stop() {
    log.info("Worker {] being stopped", name);
    longCalculations();
    log.info("Worker {] stopped", name);
}

Log output:

06:18:55.762 (      main) INFO  Starting worker pool...
06:18:55.764 (      main) INFO  Worker pool started
06:19:08.614 (Worker Main) INFO  Worker pool stopping
06:19:08.615 (  Worker 0) INFO  InterruptedException
06:19:08.616 (  Worker 0) INFO  Worker {] being stopped

I start/stop the service using jsvc:

START

./jsvc -cwd . -cp commons-daemon-1.1.0.jar:multithread-test.jar -outfile /tmp/worker.out -errfile /tmp/worker.err -pidfile /var/run/worker.pid com.worker.WorkerLauncher

STOP

./jsvc -cwd . -cp commons-daemon-1.1.0.jar:multithread-test.jar -outfile /tmp/worker.out -errfile /tmp/worker.err -pidfile /var/run/worker.pid -stop com.worker.WorkerLauncher

IMPORTANT!

Forgot to mention, that this application works as expected on windows using apache procun. This is only happening when lauching it on linux using jsvc.

ANOTHER EDIT

if I wait for threads to finish (check if any worker thread isAlive) after pool.stop() in WorkerLauncher.stop() everything works.

@Override
public void stop(){
    pool.stop();
    while(pool.isAnyGuardianRunning()) {
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            break;
        }
    }
}

And in WorkerPool:

public boolean isAnyGuardianRunning() {
    for (Thread thread : workers) {
        if (thread.isAlive()) return true;
    }
    return false;
}

But I still don't know why is this happening... Any ideas?

CrazySabbath
  • 1,274
  • 3
  • 11
  • 33
  • Generally should not be happening. Could you add a System.out before the calculation is started in the 'stop' method of the worker. How is the program initiated, is there a main method for instance. – Ironluca Aug 26 '19 at 13:56
  • @Ironluca Edited question – CrazySabbath Aug 27 '19 at 06:22

0 Answers0