Skip to content

Commit

Permalink
[WFCORE-5968] log thread dump upon management timeout
Browse files Browse the repository at this point in the history
  • Loading branch information
aogburn committed Sep 9, 2022
1 parent de3d3d9 commit b3cfcb7
Show file tree
Hide file tree
Showing 3 changed files with 155 additions and 0 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -501,6 +501,8 @@ void awaitServiceContainerStability() throws InterruptedException, TimeoutExcept
// Deliberate log and throw; we want to log this but the caller method passes a slightly different
// message to the user as part of the operation response
MGMT_OP_LOGGER.timeoutExecutingOperation(timeout / 1000, containerMonitorStep.operationId.name, containerMonitorStep.address);
// Produce and log thread dump for diagnostics
ThreadDumpUtil.threadDump();
throw te;
} finally {
executionStatus = originalExecutionStatus;
Expand Down Expand Up @@ -868,6 +870,8 @@ private void ensureWriteLockForRuntime() {
// in AbstractOperationContext.executeStep is not what I wanted
ControllerLogger.MGMT_OP_LOGGER.timeoutAwaitingInitialStability(timeout / 1000, activeStep.operationId.name, activeStep.operationId.address);
setRollbackOnly();
// Produce and log thread dump for diagnostics
ThreadDumpUtil.threadDump();
throw new OperationFailedRuntimeException(ControllerLogger.ROOT_LOGGER.timeoutAwaitingInitialStability());
} finally {
executionStatus = origStatus;
Expand Down Expand Up @@ -1233,6 +1237,8 @@ void releaseStepLocks(AbstractOperationContext.Step step) {
// it's almost certain we never stabilized during execution or we are rolling back and destabilized there.
// Either one means there is already a failure message associated with this op.
MGMT_OP_LOGGER.timeoutCompletingOperation(timeout / 1000, activeStep.operationId.name, activeStep.operationId.address);
// Produce and log thread dump for diagnostics
ThreadDumpUtil.threadDump();
}
}

Expand Down
129 changes: 129 additions & 0 deletions controller/src/main/java/org/jboss/as/controller/ThreadDumpUtil.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,129 @@
/*
* JBoss, Home of Professional Open Source.
*
* Copyright 2022 Red Hat, Inc., and individual contributors
* as indicated by the @author tags.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/

package org.jboss.as.controller;

import org.jboss.as.controller.logging.ControllerLogger;

import java.io.PrintWriter;
import java.io.StringWriter;
import java.lang.management.LockInfo;
import java.lang.management.ManagementFactory;
import java.lang.management.MonitorInfo;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;

final class ThreadDumpUtil {

public static void threadDump() {

try (
StringWriter dumpstr = new StringWriter();
PrintWriter dumpout = new PrintWriter(dumpstr);
StringWriter deadlockstr = new StringWriter();
PrintWriter deadlockout = new PrintWriter(deadlockstr);
) {

ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();

for (ThreadInfo threadInfo : threadMXBean.dumpAllThreads(true, true)) {
dumpout.println(threadInfoToString(threadInfo));
}

ControllerLogger.MGMT_OP_LOGGER.threadDump(dumpstr.toString());

long[] deadlockedThreads = threadMXBean.findDeadlockedThreads();

if (deadlockedThreads != null && deadlockedThreads.length > 0) {
for (ThreadInfo threadInfo : threadMXBean.getThreadInfo(deadlockedThreads, true, true)) {
deadlockout.println(threadInfoToString(threadInfo));
}

ControllerLogger.MGMT_OP_LOGGER.deadLock(deadlockstr.toString());
}

} catch (Exception e) {
ControllerLogger.ROOT_LOGGER.threadDumpException(e);
}
}

private static String threadInfoToString(ThreadInfo threadInfo) {
StringBuilder sb = new StringBuilder("\"" + threadInfo.getThreadName() + "\"" +
" Id=" + threadInfo.getThreadId() + " " +
threadInfo.getThreadState());
if (threadInfo.getLockName() != null) {
sb.append(" on " + threadInfo.getLockName());
}
if (threadInfo.getLockOwnerName() != null) {
sb.append(" owned by \"" + threadInfo.getLockOwnerName() +
"\" Id=" + threadInfo.getLockOwnerId());
}
if (threadInfo.isSuspended()) {
sb.append(" (suspended)");
}
if (threadInfo.isInNative()) {
sb.append(" (in native)");
}
sb.append('\n');
int i = 0;
for (; i < threadInfo.getStackTrace().length; i++) {
StackTraceElement ste = threadInfo.getStackTrace()[i];
sb.append("\tat " + ste.toString());
sb.append('\n');
if (i == 0 && threadInfo.getLockInfo() != null) {
Thread.State ts = threadInfo.getThreadState();
switch (ts) {
case BLOCKED:
sb.append("\t- blocked on " + threadInfo.getLockInfo());
sb.append('\n');
break;
case WAITING:
sb.append("\t- waiting on " + threadInfo.getLockInfo());
sb.append('\n');
break;
case TIMED_WAITING:
sb.append("\t- waiting on " + threadInfo.getLockInfo());
sb.append('\n');
break;
default:
}
}

for (MonitorInfo mi : threadInfo.getLockedMonitors()) {
if (mi.getLockedStackDepth() == i) {
sb.append("\t- locked " + mi);
sb.append('\n');
}
}
}

LockInfo[] locks = threadInfo.getLockedSynchronizers();
if (locks.length > 0) {
sb.append("\n\tNumber of locked synchronizers = " + locks.length);
sb.append('\n');
for (LockInfo li : locks) {
sb.append("\t- " + li);
sb.append('\n');
}
}
sb.append('\n');
return sb.toString();
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -3707,6 +3707,26 @@ OperationFailedRuntimeException capabilityAlreadyRegisteredInContext(String capa
@Message(id = 495, value = "\"fetch-from-master\" is a deprecated value for \"domain-controller.remote.admin-only-policy\", \"fetch-from-domain-controller\" will be used instead.")
void adminOnlyPolicyDeprecatedValue();

@LogMessage(level = WARN)
@Message(id = 496, value = "Thread dump:\n"+
"*******************************************************************************\n" +
"{0}\n===============================================================================\n" +
"End Thread dump\n*******************************************************************************\n",
format = Message.Format.MESSAGE_FORMAT)
void threadDump(String dump);

@LogMessage(level = WARN)
@Message(id = 497, value = "Deadlock detected!\n"+
"*******************************************************************************\n" +
"{0}\n===============================================================================\n" +
"End Deadlock\n*******************************************************************************\n",
format = Message.Format.MESSAGE_FORMAT)
void deadLock(String dump);

@LogMessage(level = WARN)
@Message(id = 498, value = "Exception thrown during generation of thread dump")
void threadDumpException(@Cause Exception cause);

@Message(id = NONE, value = "While constructing a mapping; %s; expected a mapping for merging, but found %s")
String errorConstructingYAMLMapping(Mark mark, NodeId node);

Expand Down

0 comments on commit b3cfcb7

Please sign in to comment.