Work around deqp log file creation issues.
Work around log file creation spuriously failing by creating and making sure
the log file exists in the host-side test runner.
Bug: 22328970
Change-Id: I92d167ae169da617acd515b666c5336e8c43acd5
diff --git a/tools/tradefed-host/src/com/android/cts/tradefed/testtype/DeqpTestRunner.java b/tools/tradefed-host/src/com/android/cts/tradefed/testtype/DeqpTestRunner.java
index 43aaf98..12adb9f 100644
--- a/tools/tradefed-host/src/com/android/cts/tradefed/testtype/DeqpTestRunner.java
+++ b/tools/tradefed-host/src/com/android/cts/tradefed/testtype/DeqpTestRunner.java
@@ -64,6 +64,7 @@
new BatchRunConfiguration("rgba8888d24s8", "unspecified", "window");
private static final int UNRESPOSIVE_CMD_TIMEOUT_MS = 60000; // one minute
+ private static final int FILE_REMOVE_RETRY_INTERVAL = 2000; // 2 seconds
private final String mPackageName;
private final String mName;
@@ -78,6 +79,7 @@
private Set<String> mDeviceFeatures;
private Map<String, Boolean> mConfigQuerySupportCache = new HashMap<>();
private IRunUtil mRunUtil = RunUtil.getDefault();
+ private ISleepProvider mSleepProvider = new SleepProvider();
private IRecovery mDeviceRecovery = new Recovery();
{
@@ -152,6 +154,15 @@
}
/**
+ * Sets the sleep provider DeqpTestRunner works on.
+ *
+ * Exposed for unit testing.
+ */
+ public void setSleepProvider(ISleepProvider sleepProvider) {
+ mSleepProvider = sleepProvider;
+ }
+
+ /**
* Set IRunUtil.
*
* Exposed for unit testing.
@@ -766,12 +777,12 @@
public void recoverConnectionRefused() throws DeviceNotAvailableException;
/**
- * Tries to recover device after abnormal execution termination or link failure.
+ * Tries to recover device after abnormal termination of a command or a test run execution
+ * or link failure.
*
- * @param progressedSinceLastCall true if test execution has progressed since last call
* @throws DeviceNotAvailableException if recovery did not succeed
*/
- public void recoverComLinkKilled() throws DeviceNotAvailableException;
+ public void recoverCommandNotCompleted() throws DeviceNotAvailableException;
};
/**
@@ -864,7 +875,7 @@
* {@inheritDoc}
*/
@Override
- public void recoverComLinkKilled() throws DeviceNotAvailableException {
+ public void recoverCommandNotCompleted() throws DeviceNotAvailableException {
switch (mState) {
case WAIT:
// First failure, just try to wait and try again
@@ -879,10 +890,10 @@
killDeqpProcess();
} catch (DeviceNotAvailableException ex) {
// chain forward
- recoverComLinkKilled();
+ recoverCommandNotCompleted();
} catch (ProcessKillFailureException ex) {
// chain forward
- recoverComLinkKilled();
+ recoverCommandNotCompleted();
}
break;
@@ -896,10 +907,10 @@
killDeqpProcess();
} catch (DeviceNotAvailableException ex) {
// chain forward
- recoverComLinkKilled();
+ recoverCommandNotCompleted();
} catch (ProcessKillFailureException ex) {
// chain forward
- recoverComLinkKilled();
+ recoverCommandNotCompleted();
}
break;
@@ -912,7 +923,7 @@
rebootDevice();
} catch (DeviceNotAvailableException ex) {
// chain forward
- recoverComLinkKilled();
+ recoverCommandNotCompleted();
}
break;
@@ -1397,6 +1408,51 @@
}
}
+ private static final class FileRecreateFailedException extends Exception {
+ };
+
+ /**
+ * Creates a log file suitable for writing.
+ *
+ * Creates an empty file that is suitable for writing. If target file already exists, it will
+ * first be removed and then recreated. This delete-recreate cycle should guarantee that the
+ * target file is always writable and is not affected by file-access flags of the pre-existing
+ * file.
+ *
+ * Precreating a file in the runner makes detecting file-access issues faster and more
+ * reliable. It also avoids issues caused by sdcard FUSE spuriously preventing file creation.
+ */
+ private void precreateLogFile() throws DeviceNotAvailableException,
+ FileRecreateFailedException {
+ final int NUM_ATTEMPTS = 4;
+ int attemptNum = 0;
+ for (;;) {
+ mDevice.executeShellCommand("rm " + LOG_FILE_NAME);
+ ++attemptNum;
+
+ if (!mDevice.doesFileExist(LOG_FILE_NAME)) {
+ // yay, remove works like it should
+ break;
+ } else if (attemptNum < NUM_ATTEMPTS) {
+ // wait if we failed
+ CLog.w("Remote file removal failed, retrying...");
+ mSleepProvider.sleep(FILE_REMOVE_RETRY_INTERVAL);
+ } else {
+ // Bail
+ CLog.e("Could not delete a remote file.");
+ throw new FileRecreateFailedException();
+ }
+ }
+
+ // create & truncate and make world read-writable
+ mDevice.pushString("", LOG_FILE_NAME);
+
+ if (!mDevice.doesFileExist(LOG_FILE_NAME)) {
+ CLog.e("Could not precreate log file.");
+ throw new FileRecreateFailedException();
+ }
+ }
+
/**
* Runs one execution pass over the given batch.
*
@@ -1412,8 +1468,8 @@
final String testCases = generateTestCaseTrie(batch.tests);
+ // Caselist file cannot linger.
mDevice.executeShellCommand("rm " + CASE_LIST_FILE_NAME);
- mDevice.executeShellCommand("rm " + LOG_FILE_NAME);
mDevice.pushString(testCases + "\n", CASE_LIST_FILE_NAME);
final String instrumentationName =
@@ -1443,6 +1499,9 @@
Throwable interruptingError = null;
try {
+ // we might have lingering log file from a previous dirty run and it might be somehow
+ // locked (details unknown). Make sure it's writable when test is run.
+ precreateLogFile();
executeShellCommandAndReadOutput(command, parser);
} catch (Throwable ex) {
interruptingError = ex;
@@ -1462,7 +1521,9 @@
if (interruptingError instanceof AdbComLinkOpenError) {
mDeviceRecovery.recoverConnectionRefused();
} else if (interruptingError instanceof AdbComLinkKilledError) {
- mDeviceRecovery.recoverComLinkKilled();
+ mDeviceRecovery.recoverCommandNotCompleted();
+ } else if (interruptingError instanceof FileRecreateFailedException) {
+ mDeviceRecovery.recoverCommandNotCompleted();
} else if (interruptingError instanceof RunInterruptedException) {
// external run interruption request. Terminate immediately.
throw (RunInterruptedException)interruptingError;
@@ -1473,7 +1534,7 @@
// recoverXXX did not throw => recovery succeeded
} else if (!parser.wasSuccessful()) {
- mDeviceRecovery.recoverComLinkKilled();
+ mDeviceRecovery.recoverCommandNotCompleted();
// recoverXXX did not throw => recovery succeeded
}
diff --git a/tools/tradefed-host/tests/src/com/android/cts/tradefed/testtype/DeqpTestRunnerTest.java b/tools/tradefed-host/tests/src/com/android/cts/tradefed/testtype/DeqpTestRunnerTest.java
index 7ec09c9..4c879b4 100644
--- a/tools/tradefed-host/tests/src/com/android/cts/tradefed/testtype/DeqpTestRunnerTest.java
+++ b/tools/tradefed-host/tests/src/com/android/cts/tradefed/testtype/DeqpTestRunnerTest.java
@@ -106,7 +106,7 @@
* {@inheritDoc}
*/
@Override
- public void recoverComLinkKilled() throws DeviceNotAvailableException {
+ public void recoverCommandNotCompleted() throws DeviceNotAvailableException {
}
};
@@ -1717,12 +1717,15 @@
EasyMock.expect(mockDevice.executeShellCommand(EasyMock.eq("rm " + CASE_LIST_FILE_NAME)))
.andReturn("").once();
- EasyMock.expect(mockDevice.executeShellCommand(EasyMock.eq("rm " + LOG_FILE_NAME)))
- .andReturn("").once();
-
EasyMock.expect(mockDevice.pushString("{dEQP-GLES3{loss{instance}}}\n", CASE_LIST_FILE_NAME))
.andReturn(true).once();
+ EasyMock.expect(mockDevice.executeShellCommand(EasyMock.eq("rm " + LOG_FILE_NAME)))
+ .andReturn("").once();
+ EasyMock.expect(mockDevice.doesFileExist(LOG_FILE_NAME)).andReturn(false).once();
+ EasyMock.expect(mockDevice.pushString("", LOG_FILE_NAME)).andReturn(true).once();
+ EasyMock.expect(mockDevice.doesFileExist(LOG_FILE_NAME)).andReturn(true).once();
+
String command = String.format(
"am instrument %s -w -e deqpLogFileName \"%s\" -e deqpCmdLine \""
+ "--deqp-caselist-file=%s"
@@ -1753,10 +1756,10 @@
});
if (!recoverySuccessful) {
- mockRecovery.recoverComLinkKilled();
+ mockRecovery.recoverCommandNotCompleted();
EasyMock.expectLastCall().andThrow(new DeviceNotAvailableException()).once();
} else {
- mockRecovery.recoverComLinkKilled();
+ mockRecovery.recoverCommandNotCompleted();
EasyMock.expectLastCall().once();
// retry running config B
@@ -1860,7 +1863,7 @@
recovery.recoverConnectionRefused();
break;
case FAIL_LINK_KILLED:
- recovery.recoverComLinkKilled();
+ recovery.recoverCommandNotCompleted();
break;
}
}
@@ -2141,7 +2144,7 @@
orderedControl.replay();
recovery.setDevice(mockDevice);
recovery.setSleepProvider(mockSleepProvider);
- recovery.recoverComLinkKilled();
+ recovery.recoverCommandNotCompleted();
orderedControl.verify();
}
@@ -2312,17 +2315,217 @@
EasyMock.verify(mockDevice, mockIDevice);
}
+ /**
+ * Test log file precreate persistent failure
+ */
+ public void testPrecreate_persistentFailure() throws Exception {
+ final TestIdentifier testId = new TestIdentifier("dEQP-GLES3.precreate", "test");
+ final String testTrie = "{dEQP-GLES3{precreate{test}}}";
+
+ Collection<TestIdentifier> tests = new ArrayList<TestIdentifier>();
+ tests.add(testId);
+
+ Map<TestIdentifier, List<Map<String, String>>> instance = new HashMap<>();
+ instance.put(testId, DEFAULT_INSTANCE_ARGS);
+
+ ITestInvocationListener mockListener
+ = EasyMock.createStrictMock(ITestInvocationListener.class);
+ ITestDevice mockDevice = EasyMock.createMock(ITestDevice.class);
+ IDevice mockIDevice = EasyMock.createMock(IDevice.class);
+ DeqpTestRunner.ISleepProvider mockSleepProvider =
+ EasyMock.createMock(DeqpTestRunner.ISleepProvider.class);
+ DeqpTestRunner.IRecovery mockRecovery =
+ EasyMock.createMock(DeqpTestRunner.IRecovery.class);
+
+ DeqpTestRunner deqpTest = new DeqpTestRunner(NAME, NAME, tests, instance);
+ deqpTest.setAbi(UnitTests.ABI);
+ deqpTest.setDevice(mockDevice);
+ deqpTest.setBuildHelper(new StubCtsBuildHelper());
+ deqpTest.setSleepProvider(mockSleepProvider);
+ deqpTest.setRecovery(mockRecovery);
+
+ mockRecovery.setDevice(mockDevice);
+ EasyMock.expectLastCall().atLeastOnce();
+
+ int version = 3 << 16;
+ EasyMock.expect(mockDevice.getProperty("ro.opengles.version"))
+ .andReturn(Integer.toString(version)).atLeastOnce();
+
+ EasyMock.expect(mockDevice.uninstallPackage(EasyMock.eq(DEQP_ONDEVICE_PKG))).
+ andReturn("").once();
+
+ EasyMock.expect(mockDevice.installPackage(EasyMock.<File>anyObject(),
+ EasyMock.eq(true),
+ EasyMock.eq(AbiUtils.createAbiFlag(UnitTests.ABI.getName())))).andReturn(null)
+ .once();
+
+ expectRenderConfigQuery(mockDevice,
+ "--deqp-gl-config-name=rgba8888d24s8 --deqp-screen-rotation=unspecified "
+ + "--deqp-surface-type=window --deqp-gl-major-version=3 "
+ + "--deqp-gl-minor-version=0");
+
+ EasyMock.expect(mockDevice.executeShellCommand(EasyMock.eq("rm " + CASE_LIST_FILE_NAME)))
+ .andReturn("").once();
+
+ EasyMock.expect(mockDevice.pushString(testTrie + "\n", CASE_LIST_FILE_NAME))
+ .andReturn(true).once();
+
+ // fail persistently...
+ EasyMock.expect(mockDevice.executeShellCommand(EasyMock.eq("rm " + LOG_FILE_NAME)))
+ .andReturn("").anyTimes();
+ EasyMock.expect(mockDevice.doesFileExist(LOG_FILE_NAME)).andReturn(true).anyTimes();
+ mockSleepProvider.sleep(EasyMock.gt(0));
+ EasyMock.expectLastCall().anyTimes();
+
+ // ..and when retries won't help, trigger recovery tactics
+ mockRecovery.recoverCommandNotCompleted();
+ EasyMock.expectLastCall().andThrow(new DeviceNotAvailableException()).once();
+
+ mockListener.testRunStarted(ID, 1);
+ EasyMock.expectLastCall().once();
+
+ EasyMock.replay(mockDevice, mockIDevice);
+ EasyMock.replay(mockListener);
+ EasyMock.replay(mockSleepProvider);
+ EasyMock.replay(mockRecovery);
+ try {
+ deqpTest.run(mockListener);
+ fail("expected DeviceNotAvailableException");
+ } catch (DeviceNotAvailableException ex) {
+ // expected
+ }
+ EasyMock.verify(mockRecovery);
+ EasyMock.verify(mockSleepProvider);
+ EasyMock.verify(mockListener);
+ EasyMock.verify(mockDevice, mockIDevice);
+ }
+
+ /**
+ * Test log file precreate transient failure
+ */
+ public void testPrecreate_transientFailure() throws Exception {
+ final TestIdentifier testId = new TestIdentifier("dEQP-GLES3.precreate", "test");
+ final String testPath = "dEQP-GLES3.precreate.test";
+ final String testTrie = "{dEQP-GLES3{precreate{test}}}";
+ final String output = "INSTRUMENTATION_STATUS: dEQP-SessionInfo-Name=releaseName\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-EventType=SessionInfo\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-SessionInfo-Value=2014.x\r\n"
+ + "INSTRUMENTATION_STATUS_CODE: 0\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-SessionInfo-Name=releaseId\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-EventType=SessionInfo\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-SessionInfo-Value=0xcafebabe\r\n"
+ + "INSTRUMENTATION_STATUS_CODE: 0\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-SessionInfo-Name=targetName\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-EventType=SessionInfo\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-SessionInfo-Value=android\r\n"
+ + "INSTRUMENTATION_STATUS_CODE: 0\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-EventType=BeginSession\r\n"
+ + "INSTRUMENTATION_STATUS_CODE: 0\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-EventType=BeginTestCase\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-BeginTestCase-TestCasePath=" + testPath + "\r\n"
+ + "INSTRUMENTATION_STATUS_CODE: 0\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-TestCaseResult-Code=Pass\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-TestCaseResult-Details=DetailPass\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-EventType=TestCaseResult\r\n"
+ + "INSTRUMENTATION_STATUS_CODE: 0\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-EventType=EndTestCase\r\n"
+ + "INSTRUMENTATION_STATUS_CODE: 0\r\n"
+ + "INSTRUMENTATION_STATUS: dEQP-EventType=EndSession\r\n"
+ + "INSTRUMENTATION_STATUS_CODE: 0\r\n"
+ + "INSTRUMENTATION_CODE: 0\r\n";
+
+ Collection<TestIdentifier> tests = new ArrayList<TestIdentifier>();
+ tests.add(testId);
+
+ Map<TestIdentifier, List<Map<String, String>>> instance = new HashMap<>();
+ instance.put(testId, DEFAULT_INSTANCE_ARGS);
+
+ ITestInvocationListener mockListener
+ = EasyMock.createStrictMock(ITestInvocationListener.class);
+ ITestDevice mockDevice = EasyMock.createMock(ITestDevice.class);
+ IDevice mockIDevice = EasyMock.createMock(IDevice.class);
+ DeqpTestRunner.ISleepProvider mockSleepProvider =
+ EasyMock.createMock(DeqpTestRunner.ISleepProvider.class);
+
+ DeqpTestRunner deqpTest = new DeqpTestRunner(NAME, NAME, tests, instance);
+ deqpTest.setAbi(UnitTests.ABI);
+ deqpTest.setDevice(mockDevice);
+ deqpTest.setBuildHelper(new StubCtsBuildHelper());
+ deqpTest.setSleepProvider(mockSleepProvider);
+
+ int version = 3 << 16;
+ EasyMock.expect(mockDevice.getProperty("ro.opengles.version"))
+ .andReturn(Integer.toString(version)).atLeastOnce();
+
+ EasyMock.expect(mockDevice.uninstallPackage(EasyMock.eq(DEQP_ONDEVICE_PKG))).
+ andReturn("").once();
+
+ EasyMock.expect(mockDevice.installPackage(EasyMock.<File>anyObject(),
+ EasyMock.eq(true),
+ EasyMock.eq(AbiUtils.createAbiFlag(UnitTests.ABI.getName())))).andReturn(null)
+ .once();
+
+ expectRenderConfigQuery(mockDevice,
+ "--deqp-gl-config-name=rgba8888d24s8 --deqp-screen-rotation=unspecified "
+ + "--deqp-surface-type=window --deqp-gl-major-version=3 "
+ + "--deqp-gl-minor-version=0");
+
+ // fail once
+ EasyMock.expect(mockDevice.executeShellCommand(EasyMock.eq("rm " + LOG_FILE_NAME)))
+ .andReturn("").once();
+ EasyMock.expect(mockDevice.doesFileExist(LOG_FILE_NAME)).andReturn(true).once();
+ mockSleepProvider.sleep(EasyMock.gt(0));
+ EasyMock.expectLastCall().once();
+
+ String commandLine = String.format(
+ "--deqp-caselist-file=%s --deqp-gl-config-name=rgba8888d24s8 "
+ + "--deqp-screen-rotation=unspecified "
+ + "--deqp-surface-type=window "
+ + "--deqp-log-images=disable "
+ + "--deqp-watchdog=enable",
+ CASE_LIST_FILE_NAME);
+
+ runInstrumentationLineAndAnswer(mockDevice, mockIDevice, testTrie, commandLine,
+ output);
+
+ EasyMock.expect(mockDevice.uninstallPackage(EasyMock.eq(DEQP_ONDEVICE_PKG))).
+ andReturn("").once();
+
+ mockListener.testRunStarted(ID, 1);
+ EasyMock.expectLastCall().once();
+
+ mockListener.testStarted(EasyMock.eq(testId));
+ EasyMock.expectLastCall().once();
+
+ mockListener.testEnded(EasyMock.eq(testId), EasyMock.<Map<String, String>>notNull());
+ EasyMock.expectLastCall().once();
+
+ mockListener.testRunEnded(EasyMock.anyLong(), EasyMock.<Map<String, String>>notNull());
+ EasyMock.expectLastCall().once();
+
+ EasyMock.replay(mockDevice, mockIDevice);
+ EasyMock.replay(mockListener);
+ EasyMock.replay(mockSleepProvider);
+ deqpTest.run(mockListener);
+ EasyMock.verify(mockSleepProvider);
+ EasyMock.verify(mockListener);
+ EasyMock.verify(mockDevice, mockIDevice);
+ }
+
private void runInstrumentationLineAndAnswer(ITestDevice mockDevice, IDevice mockIDevice,
final String testTrie, final String cmd, final String output) throws Exception {
EasyMock.expect(mockDevice.executeShellCommand(EasyMock.eq("rm " + CASE_LIST_FILE_NAME)))
.andReturn("").once();
- EasyMock.expect(mockDevice.executeShellCommand(EasyMock.eq("rm " + LOG_FILE_NAME)))
- .andReturn("").once();
-
EasyMock.expect(mockDevice.pushString(testTrie + "\n", CASE_LIST_FILE_NAME))
.andReturn(true).once();
+ EasyMock.expect(mockDevice.executeShellCommand(EasyMock.eq("rm " + LOG_FILE_NAME)))
+ .andReturn("").once();
+ EasyMock.expect(mockDevice.doesFileExist(LOG_FILE_NAME)).andReturn(false).once();
+ EasyMock.expect(mockDevice.pushString("", LOG_FILE_NAME)).andReturn(true).once();
+ EasyMock.expect(mockDevice.doesFileExist(LOG_FILE_NAME)).andReturn(true).once();
+
String command = String.format(
"am instrument %s -w -e deqpLogFileName \"%s\" -e deqpCmdLine \"%s\" "
+ "-e deqpLogData \"%s\" %s",
