Fix TimedRunnable log NPE

[AnonHxy]

Descriptions of the changes in this PR:

Motivation

When the ReadEntryProcessor runs slow, the TimedRunnable will print the warn log like below:

Runnable xx:xx took too long xx micros to execute.

bookkeeper/bookkeeper-common/src/main/java/org/apache/bookkeeper/common/util/OrderedExecutor.java

Lines 197 to 208 in fd2c7c6

	public void run() {
	taskPendingStats.registerSuccessfulEvent(MathUtils.elapsedNanos(initNanos), TimeUnit.NANOSECONDS);
	long startNanos = MathUtils.nowInNano();
	try {
	this.runnable.run();
	} finally {
	long elapsedMicroSec = MathUtils.elapsedMicroSec(startNanos);
	taskExecutionStats.registerSuccessfulEvent(elapsedMicroSec, TimeUnit.MICROSECONDS);
	if (elapsedMicroSec >= warnTimeMicroSec) {
	log.warn("Runnable {}:{} took too long {} micros to execute.", runnable, runnable.getClass(),
	elapsedMicroSec);
	}

However we found that NPE happened in this log:

WARN  [BookieReadThreadPool-OrderedExecutor-1-0:OrderedExecutor$TimedRunnable@206] - Runnable [!!!org.apache.bookkeeper.proto.ReadEntryProcessor@1dd094f3=>java.lang.NullPointerException:Cannot invoke "org.apache.bookkeeper.proto.BookieProtocol$ReadRequest.getLedgerId()" because "this.request" is null!!!]:class org.apache.bookkeeper.proto.ReadEntryProcessor took too long 1125904 micros to execute.

The root cause is that the ReadEntryProcessor will be recycled after calling run method, which means we shouldn't call any method of the ReadEntryProcessor after calling ReadEntryProcessor#run(). So line206 calling toString() method of runnable(ReadEntryProcessor) will cause NPE or any other wrong message.

Changes

Save runnable string name and class when create TimedRunnable and TimedCallable

[dlg99]

Good catch!
One note about perf implications of the change

[dlg99]

toString() can be expensive; maybe skip this and only log the class?

[AnonHxy]

Nice suggestion. Updated @dlg99