How does the thread pool print stack information?

Keywords: Java Concurrent Programming thread pool

preface

This article belongs to the column "100 problems to solve Java concurrency". This column is original by the author. Please indicate the source of quotation. Please help point out the deficiencies and errors in the comment area. Thank you!

Please refer to table of contents and references for this column 100 problems to solve Java concurrency

text

Simple example

Start with a simple example. First, we have a Runnable interface, which is used to calculate the quotient of two numbers.

public class DivTask implements Runnable {
    int a,b;
    public DivTask(int a,int b){
        this.a=a;
        this.b=b;
    }
    @Override
    public void run() {
        double re=a/b;
        System.out.println(re);
    }
}

If the program runs this task, we expect it to print the quotient of a given two numbers.

Now we construct several such tasks, hoping that the program can calculate the quotient of a given set of arrays.

import java.util.concurrent.ExecutionException;
import java.util.concurrent.SynchronousQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

/**
 * submit Abnormal eating
 * 1. Get the exception with Future.get()
 * 2. try-catch
 * @author Geym
 *
 */
public class CatchExceptionMain {
    public static void main(String[] args) throws InterruptedException, ExecutionException {
        ThreadPoolExecutor pools=new ThreadPoolExecutor(0, Integer.MAX_VALUE,
                0L, TimeUnit.SECONDS,
                new SynchronousQueue<Runnable>());
        
        for(int i=0;i<5;i++){
            pools.submit(new DivTask(100,i));
        }
    }
}

The above code submits DivTask to the thread pool. From the for loop, we should get five results, which are the quotient of 100 divided by the given i.

But if you really run the program, the whole result is:

100.0
25.0
33.0
50.0

There are only four outputs, that is, the program misses a set of data, but more unfortunately, the program does not have any logs or error prompts, as if everything is normal.

In this simple case, as long as you have a little experience, you can find that the divisor i gets 0, and the missing value is likely caused by dividing by 0.

But in a slightly complex business scenario, this error can make you depressed for a few days.

Therefore, although using thread pool is a good thing, we still have to pay attention to these "pits" everywhere.

The thread pool is likely to "eat" the exceptions thrown by the program, causing us to know nothing about the program's errors.

The exception stack is as important to programmers as the compass is to ships sailing on the vast sea.

Without a compass, the ship can only find direction more difficult. There is no abnormal stack. When troubleshooting problems, it can only think about it slowly.

Here we will discuss the method of retrieving the exception stack from the thread pool.

execute

The simplest way is to abandon the submit() method and use the execute() method instead. Change the task submission code above to:

import java.util.concurrent.ExecutionException;
import java.util.concurrent.SynchronousQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

/**
 * submit Abnormal eating
 * 1. Get the exception with Future.get()
 * 2. try-catch
 *
 * @author Geym
 */
public class CatchExceptionMain2 {
	public static void main(String[] args) throws InterruptedException, ExecutionException {
		ThreadPoolExecutor pools = new ThreadPoolExecutor(0, Integer.MAX_VALUE,
				0L, TimeUnit.SECONDS,
				new SynchronousQueue<Runnable>());

		for (int i = 0; i < 5; i++) {
			pools.execute(new DivTask(100, i));
		}
	}
}

Or use the following code:

import java.util.concurrent.*;

/**
 * submit Abnormal eating
 * 1. Get the exception with Future.get()
 * 2. try-catch
 *
 * @author Geym
 */
public class CatchExceptionMain3 {
	public static void main(String[] args) throws InterruptedException, ExecutionException {
		ThreadPoolExecutor pools = new ThreadPoolExecutor(0, Integer.MAX_VALUE,
				0L, TimeUnit.SECONDS,
				new SynchronousQueue<Runnable>());

		for (int i = 0; i < 5; i++) {
			Future re = pools.submit(new DivTask(100, i));
			re.get();
		}
	}
}

The above two methods can get some stack information, as shown below:

Exception in thread "pool-1-thread-1" java.lang.ArithmeticException: / by zero
	at com.shockang.study.java.concurrent.trace.DivTask.run(DivTask.java:11)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
100.0
25.0
33.0
50.0

Notice, I'm talking about part.

This is because from the two exception stacks, we can only know where the exception was thrown (here is line 11 of DivTask).

But we also hope to get another more important information, that is, where was the task submitted?

The specific submission location of the task has been completely flooded by the thread pool.

Along the stack, we can only find the scheduling process in the thread pool at most, which is of little value to us.

In that case, we can only do it ourselves and have plenty of food and clothing!

In order to add a few days less work in the future, it is very necessary to dig out the stack information completely!

Expand our ThreadPoolExecutor thread pool to save the stack information of the task submitting thread before scheduling the task.

Extend ThreadPoolExecutor

import java.util.concurrent.BlockingQueue;
import java.util.concurrent.Future;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

public class TraceThreadPoolExecutor extends ThreadPoolExecutor {
	public TraceThreadPoolExecutor(int corePoolSize, int maximumPoolSize,
								   long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue) {
		super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
	}

	@Override
	public void execute(Runnable task) {
		super.execute(wrap(task, clientTrace(), Thread.currentThread()
				.getName()));
	}

	@Override
	public Future<?> submit(Runnable task) {
		return super.submit(wrap(task, clientTrace(), Thread.currentThread()
				.getName()));
	}

	private Exception clientTrace() {
		return new Exception("Client stack trace");
	}

	private Runnable wrap(final Runnable task, final Exception clientStack,
						  String clientThreadName) {
		return new Runnable() {
			@Override
			public void run() {
				try {
					task.run();
				} catch (Exception e) {
					clientStack.printStackTrace();
					throw e;
				}
			}
		};
	}
}

In line 23, the second parameter of the wrap method is an exception, which stores the stack information of the thread submitting the task.

This method wraps the Runnable task we passed in, so that it can handle exception information.

When an exception occurs in a task, the exception will be printed.

Well, now you can try to execute this code using our new member (tracethread pool executor).

import java.util.concurrent.SynchronousQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;


public class TraceMain {

	public static void main(String[] args) {
		ThreadPoolExecutor pools = new TraceThreadPoolExecutor(0, Integer.MAX_VALUE,
				0L, TimeUnit.SECONDS,
				new SynchronousQueue<Runnable>());
		for (int i = 0; i < 5; i++) {
			pools.execute(new DivTask(100, i));
		}
	}

}

By executing the above code, you can get the following information:

java.lang.Exception: Client stack trace
	at com.shockang.study.java.concurrent.trace.TraceThreadPoolExecutor.clientTrace(TraceThreadPoolExecutor.java:27)
	at com.shockang.study.java.concurrent.trace.TraceThreadPoolExecutor.execute(TraceThreadPoolExecutor.java:16)
	at com.shockang.study.java.concurrent.trace.TraceMain.main(TraceMain.java:15)
Exception in thread "pool-1-thread-1" java.lang.ArithmeticException: / by zero
	at com.shockang.study.java.concurrent.trace.DivTask.run(DivTask.java:11)
	at com.shockang.study.java.concurrent.trace.TraceThreadPoolExecutor$1.run(TraceThreadPoolExecutor.java:36)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
100.0
25.0
33.0
50.0

Posted by Zoofu on Wed, 10 Nov 2021 08:39:55 -0800