Re: Locked trying to write to journal

[mlukica <ma...@tis.hr>]

Manuel Teira-2 wrote:
> 
> Hello. I've just detected a lock problem using activemq-core 4.0.2 that 
> seems to be related with journal writing logic.
> I was able to get a stack of the running process, where we can see that 
> a lot of threads (56 to be precise) are waiting to lock the journal
> 

I've had the same problem with activemq-core 4.1.0. I think that the problem
lies in ThreadPoolExecutor (backport-util-concurrent-2.1), and the way it's
used in JournalImpl. Problem is fixed in backport-util-concurrent-3.1 (and
probably 3.0).

Task that should be run by executor is added to its task queue, but never
gets executed (race condition in ThreadPoolExecutor execute method in ver
2.1). Since it's never executed, it doesn't countdown the latch and thread
which called it gets stuck in a wait. This thread locks access to given
executor by holding monitor on JournalImpl and no other thread can access
the executor, so the task is never taken from queue and handled by some
thread from pool (hence the lock).

This behaviour of ThreadPoolExecutor is caused by setting core and maximum
pool size to 1, and allowing core thread timeout.

I've written the test that reproduces the lock in the same synchronization
scenario (I've changed keepAliveTime to smaller values to cause this lock to
occur faster):

import edu.emory.mathcs.backport.java.util.concurrent.*;
import org.testng.annotations.Test;

@Test
public class ThreadPoolExecutorTest {

    public void testExecute() throws InterruptedException {
        ThreadPoolExecutor executor = new ThreadPoolExecutor(1, 1, 95,
TimeUnit.MILLISECONDS, new LinkedBlockingQueue(), new ThreadFactory() {
            public Thread newThread(Runnable runnable) {
                Thread answer = new Thread(runnable, "Journal Writer");
                answer.setPriority(Thread.MAX_PRIORITY);
                answer.setDaemon(true);
                return answer;
            }
        });
        executor.allowCoreThreadTimeOut(true);

        TestRunnable testRunnable = new TestRunnable();
        testRunnable.executor = executor;

        for (int i = 0; i < 10000; i++) {
            CountDownLatch latch = new CountDownLatch(1);
            testRunnable.latch = latch;
            executor.execute(testRunnable);
            Thread.sleep((long)(Math.random() * 10));
            latch.await();
            Thread.sleep(100);

        }
    }

    private class TestRunnable implements Runnable {
        private int counter;
        CountDownLatch latch;
        ThreadPoolExecutor executor;

        public void run() {

            try {
                counter++;
                System.out.println("Executing task: " + counter);
                Thread.sleep((long)(Math.random() * 10));
                latch.countDown();
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }
    }

    public static void main(String[] args) throws InterruptedException {
        new ThreadPoolExecutorTest().testExecute();
    }
}

Lock will regularly happen after cca 100 iterations on Solaris (it does not
happen on windows or mac) so I guess it's influenced by JVM implementation
and probably its thread scheduling.

When using backport-util-concurrent-3.1.jar, threads never lock up.
-- 
View this message in context: http://www.nabble.com/Locked-trying-to-write-to-journal-tp10947063s2354p15476618.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.