Add debug logging to `SerializedInvoker` (#8914)
Added debug logging and task naming
This commit is contained in:
parent
e7f6f6729a
commit
00e355bebb
|
@ -45,8 +45,26 @@ public class SerializedInvoker
|
||||||
public Runnable offer(Runnable task)
|
public Runnable offer(Runnable task)
|
||||||
{
|
{
|
||||||
if (task == null)
|
if (task == null)
|
||||||
|
{
|
||||||
|
if (LOG.isDebugEnabled())
|
||||||
|
LOG.debug("Offering task null, skipping it in {}", this);
|
||||||
return null;
|
return null;
|
||||||
|
}
|
||||||
|
// The NamedRunnable logger is checked to make it possible to enable the nice task names in a debugger
|
||||||
|
// while not flooding the logs nor stderr with logging statements just by adding
|
||||||
|
// org.eclipse.jetty.util.thread.SerializedInvoker$NamedRunnable.LEVEL=DEBUG to jetty-logging.properties.
|
||||||
|
if (NamedRunnable.LOG.isDebugEnabled())
|
||||||
|
{
|
||||||
|
if (!(task instanceof NamedRunnable))
|
||||||
|
{
|
||||||
|
// Wrap the given task with another one that's going to delegate run() to the wrapped task while the
|
||||||
|
// wrapper's toString() returns a description of the place in code where SerializedInvoker.run() was called.
|
||||||
|
task = new NamedRunnable(task, deriveTaskName(task));
|
||||||
|
}
|
||||||
|
}
|
||||||
Link link = new Link(task);
|
Link link = new Link(task);
|
||||||
|
if (LOG.isDebugEnabled())
|
||||||
|
LOG.debug("Offering link {} of {}", link, this);
|
||||||
Link penultimate = _tail.getAndSet(link);
|
Link penultimate = _tail.getAndSet(link);
|
||||||
if (penultimate == null)
|
if (penultimate == null)
|
||||||
return link;
|
return link;
|
||||||
|
@ -54,6 +72,18 @@ public class SerializedInvoker
|
||||||
return null;
|
return null;
|
||||||
}
|
}
|
||||||
|
|
||||||
|
protected String deriveTaskName(Runnable task)
|
||||||
|
{
|
||||||
|
StackTraceElement[] stackTrace = new Exception().getStackTrace();
|
||||||
|
for (StackTraceElement stackTraceElement : stackTrace)
|
||||||
|
{
|
||||||
|
String className = stackTraceElement.getClassName();
|
||||||
|
if (!className.equals(SerializedInvoker.class.getName()) && !className.equals(getClass().getName()))
|
||||||
|
return "Queued at " + stackTraceElement;
|
||||||
|
}
|
||||||
|
return task.toString();
|
||||||
|
}
|
||||||
|
|
||||||
/**
|
/**
|
||||||
* Arrange for tasks to be invoked, mutually excluded from other tasks.
|
* Arrange for tasks to be invoked, mutually excluded from other tasks.
|
||||||
* @param tasks The tasks to invoke
|
* @param tasks The tasks to invoke
|
||||||
|
@ -62,6 +92,8 @@ public class SerializedInvoker
|
||||||
*/
|
*/
|
||||||
public Runnable offer(Runnable... tasks)
|
public Runnable offer(Runnable... tasks)
|
||||||
{
|
{
|
||||||
|
if (LOG.isDebugEnabled())
|
||||||
|
LOG.debug("Offering {} tasks in {}", tasks.length, this);
|
||||||
Runnable runnable = null;
|
Runnable runnable = null;
|
||||||
for (Runnable task : tasks)
|
for (Runnable task : tasks)
|
||||||
{
|
{
|
||||||
|
@ -83,6 +115,9 @@ public class SerializedInvoker
|
||||||
Runnable todo = offer(task);
|
Runnable todo = offer(task);
|
||||||
if (todo != null)
|
if (todo != null)
|
||||||
todo.run();
|
todo.run();
|
||||||
|
else
|
||||||
|
if (LOG.isDebugEnabled())
|
||||||
|
LOG.debug("Queued link in {}", this);
|
||||||
}
|
}
|
||||||
|
|
||||||
/**
|
/**
|
||||||
|
@ -95,6 +130,15 @@ public class SerializedInvoker
|
||||||
Runnable todo = offer(tasks);
|
Runnable todo = offer(tasks);
|
||||||
if (todo != null)
|
if (todo != null)
|
||||||
todo.run();
|
todo.run();
|
||||||
|
else
|
||||||
|
if (LOG.isDebugEnabled())
|
||||||
|
LOG.debug("Queued links in {}", this);
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public String toString()
|
||||||
|
{
|
||||||
|
return String.format("%s@%x", getClass().getSimpleName(), hashCode());
|
||||||
}
|
}
|
||||||
|
|
||||||
protected void onError(Runnable task, Throwable t)
|
protected void onError(Runnable task, Throwable t)
|
||||||
|
@ -140,16 +184,45 @@ public class SerializedInvoker
|
||||||
Link link = this;
|
Link link = this;
|
||||||
while (link != null)
|
while (link != null)
|
||||||
{
|
{
|
||||||
|
if (LOG.isDebugEnabled())
|
||||||
|
LOG.debug("Running link {} of {}", link, SerializedInvoker.this);
|
||||||
try
|
try
|
||||||
{
|
{
|
||||||
link._task.run();
|
link._task.run();
|
||||||
}
|
}
|
||||||
catch (Throwable t)
|
catch (Throwable t)
|
||||||
{
|
{
|
||||||
|
if (LOG.isDebugEnabled())
|
||||||
|
LOG.debug("Failed while running link {} of {}", link, SerializedInvoker.this, t);
|
||||||
onError(link._task, t);
|
onError(link._task, t);
|
||||||
}
|
}
|
||||||
link = link.next();
|
link = link.next();
|
||||||
|
if (link == null && LOG.isDebugEnabled())
|
||||||
|
LOG.debug("Next link is null, execution is over in {}", SerializedInvoker.this);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public String toString()
|
||||||
|
{
|
||||||
|
return String.format("%s@%x[%s] -> %s", getClass().getSimpleName(), hashCode(), _task, _next);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
private record NamedRunnable(Runnable delegate, String name) implements Runnable
|
||||||
|
{
|
||||||
|
private static final Logger LOG = LoggerFactory.getLogger(NamedRunnable.class);
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public void run()
|
||||||
|
{
|
||||||
|
delegate.run();
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public String toString()
|
||||||
|
{
|
||||||
|
return name;
|
||||||
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
|
@ -2,3 +2,4 @@
|
||||||
#org.eclipse.jetty.util.PathWatcher.LEVEL=DEBUG
|
#org.eclipse.jetty.util.PathWatcher.LEVEL=DEBUG
|
||||||
#org.eclipse.jetty.util.thread.QueuedThreadPool.LEVEL=DEBUG
|
#org.eclipse.jetty.util.thread.QueuedThreadPool.LEVEL=DEBUG
|
||||||
#org.eclipse.jetty.util.thread.ReservedThreadExecutor.LEVEL=DEBUG
|
#org.eclipse.jetty.util.thread.ReservedThreadExecutor.LEVEL=DEBUG
|
||||||
|
#org.eclipse.jetty.util.thread.SerializedInvoker$NamedRunnable.LEVEL=DEBUG
|
||||||
|
|
Loading…
Reference in New Issue