pantsbuild / pants

The Pants Build System
https://www.pantsbuild.org
Apache License 2.0
3.27k stars 626 forks source link

Test failure for `tests/java/org/pantsbuild/tools/runner:jar` on mac-mini2 #3615

Closed jsirois closed 8 years ago

jsirois commented 8 years ago

As seen here Jenkins CI for master fails for:

[master@2] Running shell script
+ ./build-support/ci/print_node_info.sh
Running on:
           os: Darwin pantsbuild-mac-mini2.local 14.5.0 Darwin Kernel Version 14.5.0: Mon Jan 11 18:48:35 PST 2016; root:xnu-2782.50.2~1/RELEASE_X86_64 x86_64
+ ./build-support/bin/ci.sh -fkmsrcn -u 0/2

[== 00:00 CI BEGINS ==]
...

Like so:

...
21:13:32 02:05     [junit]
21:13:32 02:05       [cache].
                   Using cached artifacts for 1 target.
21:13:32 02:05       [run]
                     Java HotSpot(TM) 64-Bit Server VM warning: ignoring option MaxPermSize=256m; support was removed in 8.0
                     Java HotSpot(TM) 64-Bit Server VM warning: ignoring option UseSplitVerifier; support was removed in 8.0
                     Auto-detected 8 processors, using -parallel-threads=8
                     .................................................................................................F.......................................................................................................................................................................................................................................................................................................................................
                     Time: 298.909
                     There was 1 failure:
                     1) org.pantsbuild.tools.runner.PantsRunnerTest
                     java.lang.AssertionError: expected:<0> but was:<1>
                        at org.junit.Assert.fail(Assert.java:88)
                        at org.junit.Assert.failNotEquals(Assert.java:834)
                        at org.junit.Assert.assertEquals(Assert.java:645)
                        at org.junit.Assert.assertEquals(Assert.java:631)
                        at org.pantsbuild.tools.runner.PantsRunnerTest.setup(PantsRunnerTest.java:33)
                        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
                        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
                        at java.lang.reflect.Method.invoke(Method.java:498)
                        at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
                        at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
                        at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
                        at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
                        at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.CompositeRequestRunner.runChild(CompositeRequestRunner.java:66)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConcurrentCompositeRequestRunner$1$1.run(ConcurrentCompositeRequestRunner.java:37)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConcurrentRunnerScheduler.finished(ConcurrentRunnerScheduler.java:95)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConcurrentCompositeRequestRunner$1.evaluate(ConcurrentCompositeRequestRunner.java:46)
                        at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
                        at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.runLegacy(ConsoleRunnerImpl.java:502)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.run(ConsoleRunnerImpl.java:420)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.main(ConsoleRunnerImpl.java:795)
                        at org.pantsbuild.tools.junit.ConsoleRunner.main(ConsoleRunner.java:12)

                     FAILURES!!!
                     Tests run: 424,  Failures: 1

FAILURE: 
    tests/java/org/pantsbuild/tools/runner:jar
        org.pantsbuild.tools.runner.PantsRunnerTest#org.pantsbuild.tools.runner.PantsRunnerTest

java org.pantsbuild.tools.junit.ConsoleRunner ... exited non-zero (1); 1 failed 1 target.

21:18:32 07:05   [complete]
               FAILURE

Core jvm test failure
jsirois commented 8 years ago

Noting this looks like a fragile test in several ways: 1.) It assumes CWD is the repo root (attempts to run ./pants ...) 2.) It uses a @BeforeClass that produces output to a single fixed path (dist/...) - if ./pants bundle so it is likely not concurrent safe but has no @TestSerial annotation.

jsirois commented 8 years ago

Trying to debug with these edits in https://github.com/pantsbuild/pants/pull/3616:

jsirois@gill ~/dev/pantsbuild/jsirois-pants (jsirois/issues/3615) $ git diff HEAD~1
diff --git a/Jenkinsfile b/Jenkinsfile
index a5434c0..f92a3c1 100644
--- a/Jenkinsfile
+++ b/Jenkinsfile
@@ -56,23 +56,13 @@ def List shardList() {
     shards << [os: os, branchName: branchName, flags: flags]
   }

-  nodes = ['linux': 10]
-  isPullRequest = env.CHANGE_URL ==~ 'https://github.com/pantsbuild/pants/pull/[0-9]+'
-  if (!isPullRequest) {
-    // We only add OSX to the mix on master commits since our 1 mac-mini is currently a severe
-    // throughput bottleneck.
-    nodes['osx'] = 2
-  }
+  nodes = ['osx': 2]

   nodes.each { os, totalShards ->
-    addShard(os, "${os}_self-checks", '-cjlpn')
-    addShard(os, "${os}_contrib", '-fkmsrcjlp')
-
     for (int shard in 0..<totalShards) {
       String shardName = "${shard + 1}_of_${totalShards}"
       String shardId = "${shard}/${totalShards}"
       addShard(os, "${os}_unit_tests_${shardName}", "-fkmsrcn -u ${shardId}")
-      addShard(os, "${os}_integration_tests_${shardName}", "-fkmsrjlpn -i ${shardId}")
     }
   }
   return shards
diff --git a/tests/java/org/pantsbuild/tools/runner/PantsRunnerTest.java b/tests/java/org/pantsbuild/tools/runner/PantsRunnerTest.java
index 74dae91..864f096 100644
--- a/tests/java/org/pantsbuild/tools/runner/PantsRunnerTest.java
+++ b/tests/java/org/pantsbuild/tools/runner/PantsRunnerTest.java
@@ -28,9 +28,61 @@ public class PantsRunnerTest {
           "testprojects.src.java.org.pantsbuild.testproject.runner.main-class-0.jar");
   static final String MAIN_CLASS = "org.pantsbuild.testproject.runner.MainClass";

+  static class Reader extends Thread {
+    static Reader start(InputStream stream) {
+      Reader reader = new Reader(stream);
+      reader.start();
+      return reader;
+    }
+
+    private static final int BUFFER_SIZE = 8 * 1024;
+
+    private final InputStream stream;
+    private final ByteArrayOutputStream capturedData = new ByteArrayOutputStream(BUFFER_SIZE);
+
+    private Reader(InputStream stream) {
+      this.stream = stream;
+    }
+
+    @Override
+    public void run() {
+      byte[] buffer = new byte[BUFFER_SIZE];
+      int read;
+      while ((read = read(buffer)) != -1) {
+        capturedData.write(buffer, 0, read);
+      }
+    }
+
+    private int read(byte[] buffer) {
+      try {
+        return stream.read(buffer);
+      } catch (IOException e) {
+        throw new RuntimeException(e);
+      }
+    }
+
+    String readAll() throws InterruptedException {
+      join();
+      return capturedData.toString();
+    }
+  }
+
   @BeforeClass
-  public static void setup() throws Exception {
-    assertEquals(0, Runtime.getRuntime().exec("./pants bundle " + TEST_PROJECT).waitFor());
+  public static void setUpClass() throws Exception {
+    String command = "./pants bundle " + TEST_PROJECT;
+    Process process = Runtime.getRuntime().exec(command);
+    Reader stdout = Reader.start(process.getInputStream());
+    Reader stderr = Reader.start(process.getErrorStream());
+    int result = process.waitFor();
+    assertEquals(
+        String.format(
+            "Problem running %s - exited with %d:\nSTDOUT:\n%s\n\nSTDERR:\n%s",
+            command,
+            result,
+            stdout.readAll(),
+            stderr.readAll()),
+        0,
+        result);
     assertTrue(SYNTHETIC_JAR.exists());
     assertTrue(MAIN_JAR.exists());
   }
jsirois commented 8 years ago

This does not repro on the branch, I'll send up the extra debug output change for commit to master to see if that doesn't smoke this out.

jsirois commented 8 years ago

Master burn with the improved test failure output is away here: http://jenkins.pantsbuild.org/job/pantsbuild/job/pants/job/master/163/

jsirois commented 8 years ago

Excellent - promptly failed here:

...
11:31:52 01:35   [test]
11:31:52 01:35     [test-jvm-prep-command]
11:31:52 01:35       [jvm_prep_command]
11:31:52 01:35     [test-prep-command]
11:31:52 01:35     [test]
11:31:52 01:35     [pytest]
11:31:52 01:35     [junit]
11:31:52 01:35       [cache].
                   Using cached artifacts for 1 target.
11:31:53 01:36       [run]
                     Java HotSpot(TM) 64-Bit Server VM warning: ignoring option MaxPermSize=256m; support was removed in 8.0
                     Java HotSpot(TM) 64-Bit Server VM warning: ignoring option UseSplitVerifier; support was removed in 8.0
                     Auto-detected 4 processors, using -parallel-threads=4
                     .................................................................................................F.......................................................................................................................................................................................................................................................................................................................................
                     Time: 260.899
                     There was 1 failure:
                     1) org.pantsbuild.tools.runner.PantsRunnerTest
                     java.lang.AssertionError: Problem running ./pants bundle testprojects/src/java/org/pantsbuild/testproject/runner:pants-runner-testproject - exited with 1:
                     STDOUT:

                     11:32:52 00:00 [main]
                                    (To run a reporting server: ./pants server)
                     11:32:52 00:00   [setup]
                     11:32:52 00:00     [parse]
                                    Executing tasks in goals: bootstrap -> imports -> unpack-jars -> deferred-sources -> gen -> jvm-platform-validate -> resolve -> resources -> compile -> binary -> apk -> sign -> bundle
                     11:32:52 00:00   [bootstrap]
                     11:32:52 00:00     [substitute-aliased-targets]
                     11:32:52 00:00     [jar-dependency-management]
                     11:32:52 00:00     [bootstrap-jvm-tools]
                     11:32:52 00:00     [provide-tools-jar]
                     11:32:52 00:00   [imports]
                     11:32:52 00:00     [ivy-imports]
                     11:32:52 00:00   [unpack-jars]
                     11:32:52 00:00     [unpack-jars]
                     11:32:52 00:00     [unpack-libs]
                     11:32:52 00:00   [deferred-sources]
                     11:32:52 00:00     [deferred-sources]
                     11:32:52 00:00   [gen]
                     11:32:52 00:00     [thrift]
                     11:32:52 00:00     [protoc]
                     11:32:52 00:00     [antlr]
                     11:32:52 00:00     [ragel]
                     11:32:52 00:00     [jaxb]
                     11:32:52 00:00     [wire]
                     11:32:52 00:00     [aapt]
                     11:32:52 00:00     [go-thrift]
                     11:32:52 00:00     [scrooge]
                     11:32:52 00:00   [jvm-platform-validate]
                     11:32:52 00:00     [jvm-platform-validate]
                                        Invalidated 3 targets.
                     11:32:52 00:00   [resolve]
                     11:32:52 00:00     [ivy]
                     11:32:52 00:00     [go]
                     11:32:52 00:00     [scala-js-compile]
                     11:32:52 00:00     [scala-js-link]
                     11:32:52 00:00     [node]
                     11:32:52 00:00   [resources]
                     11:32:52 00:00     [prepare]
                     11:32:52 00:00     [services]
                     11:32:52 00:00   [compile]
                     11:32:52 00:00     [compile-jvm-prep-command]
                     11:32:52 00:00       [jvm_prep_command]
                     11:32:52 00:00     [compile-prep-command]
                     11:32:52 00:00     [compile]
                     11:32:52 00:00     [zinc]
                                        Invalidated 2 targets.
                     11:32:52 00:00       [isolation-zinc-pool-bootstrap]
                                        [1/2] Compiling 1 zinc source in 1 target (testprojects/src/java/org/pantsbuild/testproject/runner:dependent-class).
                     11:32:52 00:00       [compile]

                     11:32:52 00:00         [zinc]
                                            [info] Compiling 1 Java source to /Users/jenkins/slave/workspace/pantsbuild/pants/master/.pants.d/compile/zinc/252d64521cf9/testprojects.src.java.org.pantsbuild.testproject.runner.dependent-class/current/classes...
                                            [warn] bootstrap class path not set in conjunction with -source 1.6
                                            [info] Compile success at Jul 1, 2016 11:32:52 AM [0.112s]

                     11:32:52 00:00       [unused-check]

                                        [2/2] Compiling 1 zinc source in 1 target (testprojects/src/java/org/pantsbuild/testproject/runner:main-class).
                     11:32:52 00:00       [compile]

                     11:32:52 00:00         [zinc]
                                            [info] Compiling 1 Java source to /Users/jenkins/slave/workspace/pantsbuild/pants/master/.pants.d/compile/zinc/252d64521cf9/testprojects.src.java.org.pantsbuild.testproject.runner.main-class/current/classes...
                                            [warn] bootstrap class path not set in conjunction with -source 1.6
                                            [info] Compile success at Jul 1, 2016 11:32:53 AM [0.148s]

                     11:32:53 00:01       [unused-check]

                     11:32:53 00:01     [jvm-dep-check]
                     11:32:53 00:01     [checkstyle]
                                        Invalidated 2 targets.
                     11:32:53 00:01       [checkstyle]
                     11:32:53 00:01     [scalastyle]
                     11:32:53 00:01     [cpp]
                     11:32:53 00:01     [findbugs]
                     11:32:53 00:01     [go]
                     11:32:53 00:01     [gofmt]
                     11:32:53 00:01     [python-eval]
                     11:32:53 00:01     [pythonstyle]
                     11:32:53 00:01   [binary]
                     11:32:53 00:01     [binary-jvm-prep-command]
                     11:32:53 00:01       [jvm_prep_command]
                     11:32:53 00:01     [binary-prep-command]
                     11:32:53 00:01     [python-binary-create]
                     11:32:53 00:01     [jvm]
                                        creating dist/pants-runner-testproject.jar
                     11:32:53 00:01       [create-monolithic-jar]
                     11:32:53 00:01         [add-internal-classes]
                     11:32:53 00:01         [add-dependency-jars]
                     11:32:53 00:01         [cache]
                     11:32:53 00:01         [bootstrap-jar-tool]
                     11:32:54 00:02         [jar-tool]
                     11:32:54 00:02     [dup]
                     11:32:54 00:02     [dex]
                     11:32:54 00:02     [cpplib]
                     11:32:54 00:02       [cpp-library]
                     11:32:54 00:02     [cpp]
                     11:32:54 00:02       [cpp-binary]
                     11:32:54 00:02     [go]
                     11:32:54 00:02   [apk]
                     11:32:54 00:02     [apk]
                     11:32:54 00:02   [sign]
                     11:32:54 00:02     [sign]
                     11:32:54 00:02   [bundle]
                     11:32:54 00:02     [jvm]
                                        Invalidated 1 target.
                     11:32:54 00:02       [create-monolithic-jar]
                     11:32:54 00:02         [jar-tool]
                     11:32:55 00:03   [complete]
                                    FAILURE

                     STDERR:
                     .Exception caught: (<type 'exceptions.OSError'>)
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/bin/pants_exe.py", line 50, in <module>
                         main()
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/bin/pants_exe.py", line 44, in main
                         PantsRunner(exiter).run()
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/bin/pants_runner.py", line 57, in run
                         options_bootstrapper=options_bootstrapper)
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/bin/pants_runner.py", line 46, in _run
                         return LocalPantsRunner(exiter, args, env, options_bootstrapper=options_bootstrapper).run()
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/bin/local_pants_runner.py", line 53, in run
                         self._maybe_profiled(self._run)
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/bin/local_pants_runner.py", line 50, in _maybe_profiled
                         runner()
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/bin/local_pants_runner.py", line 95, in _run
                         result = goal_runner.run()
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/bin/goal_runner.py", line 245, in run
                         result = self._execute_engine()
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/bin/goal_runner.py", line 234, in _execute_engine
                         result = engine.execute(self._context, self._goals)
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/engine/legacy_engine.py", line 26, in execute
                         self.attempt(context, goals)
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/engine/round_engine.py", line 224, in attempt
                         goal_executor.attempt(explain)
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/engine/round_engine.py", line 47, in attempt
                         task.execute()
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/backend/jvm/tasks/bundle_create.py", line 171, in execute
                         self._store_results(vt, bundle_dir, archive_path, app)
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/backend/jvm/tasks/bundle_create.py", line 108, in _store_results
                         absolute_symlink(bundle_dir, bundle_copy)
                       File "/Users/jenkins/slave/workspace/pantsbuild/pants/master/src/python/pants/util/dirutil.py", line 261, in absolute_symlink
                         os.unlink(target_path)

                     Exception message: [Errno 1] Operation not permitted: '/Users/jenkins/slave/workspace/pantsbuild/pants/master/dist/testprojects.src.java.org.pantsbuild.testproject.runner.pants-runner-testproject-bundle'

                      expected:<0> but was:<1>
                        at org.junit.Assert.fail(Assert.java:88)
                        at org.junit.Assert.failNotEquals(Assert.java:834)
                        at org.junit.Assert.assertEquals(Assert.java:645)
                        at org.pantsbuild.tools.runner.PantsRunnerTest.setUpClass(PantsRunnerTest.java:82)
                        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
                        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
                        at java.lang.reflect.Method.invoke(Method.java:498)
                        at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
                        at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
                        at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
                        at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
                        at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.CompositeRequestRunner.runChild(CompositeRequestRunner.java:66)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConcurrentCompositeRequestRunner$1$1.run(ConcurrentCompositeRequestRunner.java:37)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConcurrentRunnerScheduler.finished(ConcurrentRunnerScheduler.java:95)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConcurrentCompositeRequestRunner$1.evaluate(ConcurrentCompositeRequestRunner.java:46)
                        at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
                        at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.runLegacy(ConsoleRunnerImpl.java:502)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.run(ConsoleRunnerImpl.java:420)
                        at __shaded_by_pants__.org.pantsbuild.tools.junit.impl.ConsoleRunnerImpl.main(ConsoleRunnerImpl.java:795)
                        at org.pantsbuild.tools.junit.ConsoleRunner.main(ConsoleRunner.java:12)

                     FAILURES!!!
                     Tests run: 424,  Failures: 1

FAILURE: 
    tests/java/org/pantsbuild/tools/runner:jar
        org.pantsbuild.tools.runner.PantsRunnerTest#org.pantsbuild.tools.runner.PantsRunnerTest

java org.pantsbuild.tools.junit.ConsoleRunner ... exited non-zero (1); 1 failed 1 target.

11:36:15 05:58   [complete]
               FAILURE

Core jvm test failure
jsirois commented 8 years ago

And the operation not permitted is because the file in question is a directory - not a file, not a symlink:

$ ssh -i ~/.ssh/pantsbuild-jenkins-bot.pem administrator@mac-mini1 ls -l /Users/jenkins/slave/workspace/pantsbuild/pants/master/dist/ | grep testprojects.src.java.org.pantsbuild.testproject.runner.pants-runner-testproject-bundle
drwxr-xr-x   4 jenkins  staff       136 Jun 28 16:34 testprojects.src.java.org.pantsbuild.testproject.runner.pants-runner-testproject-bundle
jsirois commented 8 years ago

Since absolute_symlink (introduced here) is general-purpose, it should be fixed up to handle the case of target_path being a dir. I'll take a spin.

jsirois commented 8 years ago

Fix is in master @ 6c33785