diff --git a/dd-smoke-tests/osgi/src/test/groovy/datadog/smoketest/AbstractOSGiSmokeTest.groovy b/dd-smoke-tests/osgi/src/test/groovy/datadog/smoketest/AbstractOSGiSmokeTest.groovy index 784cb7ae53d..38085608aea 100644 --- a/dd-smoke-tests/osgi/src/test/groovy/datadog/smoketest/AbstractOSGiSmokeTest.groovy +++ b/dd-smoke-tests/osgi/src/test/groovy/datadog/smoketest/AbstractOSGiSmokeTest.groovy @@ -1,6 +1,9 @@ package datadog.smoketest +import java.util.concurrent.TimeUnit + abstract class AbstractOSGiSmokeTest extends AbstractSmokeTest { + private static final long EXIT_TIMEOUT_MINUTES = 2 @Override ProcessBuilder createProcessBuilder() { @@ -18,6 +21,11 @@ abstract class AbstractOSGiSmokeTest extends AbstractSmokeTest { List command = new ArrayList<>() command.add(javaPath()) command.addAll(defaultJavaProperties) + if (isIBM) { + // Write javacores (SIGQUIT) into the collected reports and take a system dump on SIGUSR2 for hang diagnostics. + command.add("-Xdump:directory=${diagnosticsDirectory().absolutePath}".toString()) + command.add('-Xdump:system:events=user2,request=exclusive+prepwalk') + } command.add("-Ddd.profiling.enabled=false") command.add((String) "-Dorg.osgi.framework.storage=${storageDir}") command.add("-Dorg.osgi.framework.bootdelegation=") @@ -44,7 +52,9 @@ abstract class AbstractOSGiSmokeTest extends AbstractSmokeTest { def "example application runs without errors"() { when: - testedProcess.waitFor() + if (!testedProcess.waitFor(EXIT_TIMEOUT_MINUTES, TimeUnit.MINUTES)) { + collectDiagnostics() + } then: testedProcess.exitValue() == 0 @@ -53,6 +63,62 @@ abstract class AbstractOSGiSmokeTest extends AbstractSmokeTest { } } + private File diagnosticsDirectory() { + // Share the application log timestamp so retries keep separate dumps that match their logs. + // Not created here: the IBM JVM creates its dump directory on the first dump, so passing runs leave no folder. + return new File(buildDirectory, "reports/${getClass().simpleName}.${logFileTimestamp}-dumps") + } + + /** Collects thread dumps (and a system dump on IBM) of the hanging application, then fails the test. */ + private void collectDiagnostics() { + File directory = diagnosticsDirectory() + AssertionError failure = new AssertionError((Object) "OSGi application did not exit within ${EXIT_TIMEOUT_MINUTES} minutes; diagnostics: ${directory}; application log: ${logFilePath}") + try { + // Java 8 has no public Process.pid() API. + long pid = testedProcess.metaClass.respondsTo(testedProcess, 'pid') ? testedProcess.pid() : testedProcess.@pid + directory.mkdirs() + File summary = new File(directory, 'collection.log') + summary << "Application PID: ${pid}\n" + if (isIBM) { + summary << 'IBM JVM: SIGQUIT thread dumps are written as javacore.*.txt and the SIGUSR2 system dump as core.*.dmp in this directory; ' + + 'threads-*.log and system-dump.log only capture the output of the kill commands\n' + } + + List threadDump + if (isIBM) { + threadDump = ['kill', '-3', pid.toString()] + } else { + File javaHome = new File(System.getProperty('java.home')) + File jcmd = new File(javaHome.name == 'jre' ? javaHome.parentFile : javaHome, 'bin/jcmd') + threadDump = [jcmd.path, pid.toString(), 'Thread.print', '-l'] + } + def run = { List command, String output -> + Process diagnostic = new ProcessBuilder(command).redirectErrorStream(true).redirectOutput(new File(directory, output)).start() + if (diagnostic.waitFor(15, TimeUnit.SECONDS)) { + summary << "Exited ${diagnostic.exitValue()}: ${command}\n" + } else { + diagnostic.destroyForcibly() + summary << "Timed out: ${command}\n" + } + } + + run(threadDump, 'threads-1.log') + // Space the snapshots so a stuck thread can be told apart from a slow one. + if (!testedProcess.waitFor(10, TimeUnit.SECONDS)) { + run(threadDump, 'threads-2.log') + if (isIBM) { + run(['kill', '-USR2', pid.toString()], 'system-dump.log') + // The VM logs the end of the dump event once the core file is in place; cleanup must not kill it earlier. + outputThreads.processTestLogLines({ it.contains('Processed dump event "user2"') }, TimeUnit.MINUTES.toMillis(2)) + summary << 'System dump event processed\n' + } + } + } catch (Exception e) { + failure.addSuppressed(e) + } + throw failure + } + @Override def logLevel() { return "debug" diff --git a/dd-smoke-tests/src/main/groovy/datadog/smoketest/ProcessManager.groovy b/dd-smoke-tests/src/main/groovy/datadog/smoketest/ProcessManager.groovy index 5cb11cd3216..72016a63fac 100644 --- a/dd-smoke-tests/src/main/groovy/datadog/smoketest/ProcessManager.groovy +++ b/dd-smoke-tests/src/main/groovy/datadog/smoketest/ProcessManager.groovy @@ -57,7 +57,7 @@ abstract class ProcessManager extends Specification { // Added a timestamp to protect logs from being overwritten on retries. @Shared - private String logFileTimestamp = LOG_FILE_TIMESTAMP_FORMATTER.format(Instant.now()) + protected String logFileTimestamp = LOG_FILE_TIMESTAMP_FORMATTER.format(Instant.now()) @Shared private String[] logFilePaths = (0..