Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion api/src/org/labkey/api/cache/BlockingCache.java
Original file line number Diff line number Diff line change
Expand Up @@ -99,7 +99,7 @@ public V get(@NotNull K key, @Nullable Object argument, CacheLoader<K, V> loader
if (null == loader)
loader = _loader;

try (var ignored = DebugInfoDumper.pushThreadDumpContext(this.getClass().getSimpleName() + ".get(" + key + ")"))
try (var _ = DebugInfoDumper.pushThreadDumpContext(this.getClass().getSimpleName() + ".get(" + key + ")"))
{
synchronized (loader == null ? _cache : loader.getSyncObject(_cache))
{
Expand Down
60 changes: 37 additions & 23 deletions api/src/org/labkey/api/util/DebugInfoDumper.java
Original file line number Diff line number Diff line change
Expand Up @@ -162,7 +162,7 @@ record ThreadExtraContext(String context, StackTraceElement[] stack, long startT
* This is primarily intended to help understand deadlocks. Developers are encouraged to
* add information related to attaining locks or starting transactions.
*/
public static _PopAutoCloseable pushThreadDumpContext(String context)
public static QuietCloser pushThreadDumpContext(String context)
{
final var arr = _threadDumpExtraContext.computeIfAbsent(Thread.currentThread(), (_) -> Collections.synchronizedList(new ArrayList<>()));
int size = arr.size();
Expand All @@ -178,7 +178,7 @@ public static void resetThreadDumpContext()
}


public static class _PopAutoCloseable implements AutoCloseable
public static class _PopAutoCloseable implements QuietCloser
{
final int _size;

Expand All @@ -193,7 +193,7 @@ public void close()
var arr = _threadDumpExtraContext.get(Thread.currentThread());
assert null != arr;
while (arr.size() > _size)
arr.remove(arr.size() - 1);
arr.removeLast();
}
}

Expand Down Expand Up @@ -407,7 +407,7 @@ public static synchronized void dumpThreads(LoggerWriter logWriter)
logWriter.debug("*********************************************");
}

// GitHib Issue 713: Automatically include PG locks and active queries in thread dumps
// GitHub Issue 713: Automatically include PG locks and active queries in thread dumps
UserSchema schema = QueryService.get().getUserSchema(User.getAdminServiceUser(), ContainerManager.getRoot(), BasePostgreSqlDialect.POSTGRES_SCHEMA_NAME);
// Schema won't exist on SQLServer
if (schema != null)
Expand Down Expand Up @@ -489,26 +489,9 @@ private static void dumpOneThread(Thread thread, LoggerWriter logWriter, Map<Thr
// subtract 1 because dumpThreads includes Thread.run() in the stack trace
logWriter.debug(String.format("%3d\t\t%s", stack.length-i-1, stack[i].toString()));
}
var extraInfo = _threadDumpExtraContext.get(thread);
if (null != extraInfo && !extraInfo.isEmpty())
for (String line : getFormattedExtraContext(thread))
{
logWriter.debug("extra stack context (may not match stacktrace if thread is not blocked)");
var messages = extraInfo.toArray(new ThreadExtraContext[0]);
for (var i = messages.length-1 ; i>= 0 ; i--)
{
logWriter.debug("\t" + messages[i].context.replace('\n',' ') + "\tage: " + (System.currentTimeMillis() - messages[i].startTime) + "ms");
var messageStack = messages[i].stack();
if (null != messageStack)
{
for (int j=0, count=0 ; j<messageStack.length && count < 4; j++)
{
if (skipMethods.contains(messageStack[j].getMethodName()))
continue;
logWriter.debug(String.format("%3d\t\t%s", messageStack.length - j, messageStack[j].toString()));
count++;
}
}
}
logWriter.debug(line);
}

if (ConnectionWrapper.getProbableLeakCount() > 0)
Expand All @@ -517,6 +500,37 @@ private static void dumpOneThread(Thread thread, LoggerWriter logWriter, Map<Thr
}
}

/**
* Returns formatted extra stack context lines for the given thread, suitable for display in thread dumps.
* Returns an empty list if the thread has no extra context.
*/
public static List<String> getFormattedExtraContext(Thread thread)
{
var extraInfo = _threadDumpExtraContext.get(thread);
if (extraInfo == null || extraInfo.isEmpty())
return List.of();

List<String> result = new ArrayList<>();
result.add("extra stack context (may not match stacktrace if thread is not blocked)");
var messages = extraInfo.toArray(new ThreadExtraContext[0]);
for (int i = messages.length - 1; i >= 0; i--)
{
result.add("\t" + messages[i].context.replace('\n', ' ') + "\tage: " + (System.currentTimeMillis() - messages[i].startTime) + "ms");
var messageStack = messages[i].stack();
if (messageStack != null)
{
for (int j = 0, count = 0; j < messageStack.length && count < 4; j++)
{
if (skipMethods.contains(messageStack[j].getMethodName()))
continue;
result.add(String.format("%3d\t\t%s", messageStack.length - j, messageStack[j].toString()));
count++;
}
}
}
return result;
}

/**
* Writes the current set of thread stacks once to the supplied logger.
*/
Expand Down
7 changes: 7 additions & 0 deletions core/src/org/labkey/core/admin/threads.jsp
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,8 @@
<%@ page import="java.util.Date" %>
<%@ page import="java.util.Set" %>
<%@ page import="org.labkey.api.data.TransactionFilter" %>
<%@ page import="org.labkey.api.util.DebugInfoDumper" %>
<%@ page import="java.util.List" %>
<%@ page extends="org.labkey.api.jsp.JspBase" %>
<%
HttpView<AdminController.ThreadsBean> me = HttpView.currentView();
Expand Down Expand Up @@ -70,6 +72,11 @@ for (Thread t : bean.threads)
{
%><%= h(" at " + e + "\n") %><%
}
List<String> extraContext = DebugInfoDumper.getFormattedExtraContext(t);
for (String line : extraContext)
{
%><%= h(line + "\n") %><%
}
}
catch (Exception x)
{
Expand Down
32 changes: 24 additions & 8 deletions search/src/org/labkey/search/model/AbstractSearchService.java
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,7 @@
import org.labkey.api.security.User;
import org.labkey.api.services.ServiceRegistry;
import org.labkey.api.util.ContextListener;
import org.labkey.api.util.DebugInfoDumper;
import org.labkey.api.util.ExceptionUtil;
import org.labkey.api.util.Formats;
import org.labkey.api.util.GUID;
Expand All @@ -51,6 +52,7 @@
import org.labkey.api.util.PageFlowUtil;
import org.labkey.api.util.Pair;
import org.labkey.api.util.Path;
import org.labkey.api.util.QuietCloser;
import org.labkey.api.util.ShutdownListener;
import org.labkey.api.util.StringUtilsLabKey;
import org.labkey.api.util.SystemMaintenance;
Expand Down Expand Up @@ -227,7 +229,7 @@ void complete(boolean success)
}
};
addItem(i);
final Item r = new Item(this, (q) -> queueItem(i), pri, null);
final Item r = new Item(this, (_) -> queueItem(i), pri, null);
queueItem(r);
}

Expand Down Expand Up @@ -412,7 +414,13 @@ public int compareTo(@NotNull AbstractSearchService.Item o)
}


final Item _commitItem = new Item(null, (q) -> {}, PRIORITY.commit, null);
private static String getSearchThreadDumpContext(Item i)
{
String taskDescription = i._task != null ? i._task.getDescription() : "unknown";
return "Search item: " + i._id + " (task: " + taskDescription + ")";
}

final Item _commitItem = new Item(null, (_) -> {}, PRIORITY.commit, null);


@Override
Expand Down Expand Up @@ -469,7 +477,7 @@ public void setLastIndexedForPath(Path path, long time, long indexed)
@Override
public final void deleteContainer(final String id)
{
Consumer<TaskIndexingQueue> r = (q) -> {
Consumer<TaskIndexingQueue> r = (_) -> {
deleteIndexedContainer(id);
synchronized (_commitLock)
{
Expand Down Expand Up @@ -512,7 +520,7 @@ public void clearLastIndexed()
public void reindexContainerFiles(Container c)
{
//Create new runnable instead of using existing methods so they can be run within the same job.
Consumer<TaskIndexingQueue> r = (q) -> {
Consumer<TaskIndexingQueue> r = (_) -> {
//Remove old items
clearIndexedFileSystemFiles(c);

Expand Down Expand Up @@ -721,7 +729,7 @@ public void indexError(Resource r, Throwable t)
});
// The indexer uses multiple threads for different types of work. Queue a Runnable first, and when it executes,
// queue an Item to ensure all queues are cleared
task.addRunnable(null, priority, (q) -> {
task.addRunnable(null, priority, (_) -> {
logQueueStatus("drainQueue's Runnable.run()");
task.addNoop(priority);
});
Expand Down Expand Up @@ -865,7 +873,7 @@ public Map<String, Map<String, Object>> getCustomSearchJsonMap(User user, @NotNu
if (resourceResolverKeyIdentifier == null)
continue;
resolverIdentifiers
.computeIfAbsent(resourceResolverKeyIdentifier.first, (k) -> new HashMap<>())
.computeIfAbsent(resourceResolverKeyIdentifier.first, (_) -> new HashMap<>())
.put(resourceResolverKeyIdentifier.second, resourceIdentifier);
}

Expand Down Expand Up @@ -1078,6 +1086,7 @@ public void shutdownStarted()
{
Item i = null;
boolean success = true;
QuietCloser threadDumpContext = null;

try
{
Expand All @@ -1086,9 +1095,10 @@ public void shutdownStarted()
if (null != i)
{
final Item item = i;
threadDumpContext = DebugInfoDumper.pushThreadDumpContext(getSearchThreadDumpContext(item));
while (!_shuttingDown && _itemQueue.size() > 1000)
{
try {Thread.sleep(100);}catch(InterruptedException ignored){}
try {Thread.sleep(100);}catch(InterruptedException _){}
}

Container c;
Expand Down Expand Up @@ -1149,6 +1159,8 @@ public Container getContainer()
}
finally
{
if (threadDumpContext != null)
threadDumpContext.close();
if (null != i)
{
try
Expand Down Expand Up @@ -1248,6 +1260,7 @@ private void _indexLoop()
{
Item i = null;
boolean success = false;
QuietCloser threadDumpContext = null;
try
{
i = getItemToIndex();
Expand All @@ -1267,6 +1280,7 @@ private void _indexLoop()
return;
}

threadDumpContext = DebugInfoDumper.pushThreadDumpContext(getSearchThreadDumpContext(i));
WebdavResource r = i.getResource();
if (null == r || !r.exists())
{
Expand Down Expand Up @@ -1331,6 +1345,8 @@ private void _indexLoop()
{
try
{
if (threadDumpContext != null)
threadDumpContext.close();
if (null != i)
i.complete(success);
}
Expand Down Expand Up @@ -1525,7 +1541,7 @@ public Map<String, Object> getIndexerStats()
history.addAll(_history);
}

IndexerRateAccumulator historyAccumulator = new IndexerRateAccumulator(history.get(history.size() - 1).getStart());
IndexerRateAccumulator historyAccumulator = new IndexerRateAccumulator(history.getLast().getStart());
SimpleDateFormat f = new SimpleDateFormat("h:mm a");
StringBuilder hourly = new StringBuilder();
hourly.append("<table>");
Expand Down
Loading