JDK-8085980 : java/lang/ProcessHandle/TreeTest.java: AssertionError: Wrong number of spawned children expected [1] but found [2]
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.lang
  • Affected Version: 9
  • Priority: P4
  • Status: Closed
  • Resolution: Fixed
  • OS: windows
  • CPU: x86
  • Submitted: 2015-06-08
  • Updated: 2016-06-13
  • Resolved: 2015-07-07
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 9
9 b73Fixed
Related Reports
Duplicate :  
JDK-8086118 - java/lang/ProcessHandle/OnExitTest.java: AssertionError: spawned process should have been in children expected [true] but found [false]
Relates :  
JDK-8152112 - java/lang/ProcessHandle/OnExitTest.java failed with error - java.lang.AssertionError: spawned process should have been in children expected [true] but found [false]
Relates :  
JDK-8086118 - java/lang/ProcessHandle/OnExitTest.java: AssertionError: spawned process should have been in children expected [true] but found [false]
Relates :  
JDK-8130276 - Intermittent failures for Process API JEP Tests
Description
jdk9 b68 PIT
single failure on win32

[TestNG] Running:
  java/lang/ProcessHandle/TreeTest.java

self pid: 71416
pid 71416, alive: true; parent: Optional[29488], [user: Optional[ORADEV\\gtee], cmd: C:\\local\\aurora\\CommonData\\jdk\\bin\\java.exe, startTime: Optional[2015-06-07T01:57:10.550Z], totalTime: Optional[PT2.65625S]]
   pid 135448, alive: true; parent: Optional[71416], [user: Optional[ORADEV\\gtee], cmd: C:\\Windows\\System32\\conhost.exe, startTime: Optional[2015-06-07T01:57:10.552Z], totalTime: Optional[PT0.015625S]]
pid 75172, alive: true; parent: Optional[71416], [user: Optional[ORADEV\\gtee], cmd: C:\\local\\aurora\\CommonData\\jdk\\bin\\java.exe, startTime: Optional[2015-06-07T01:57:12.233Z], totalTime: Optional[PT0S]]
pid 14756, alive: true; parent: Optional[71416], [user: Optional[ORADEV\\gtee], cmd: C:\\local\\aurora\\CommonData\\jdk\\bin\\java.exe, startTime: Optional[2015-06-07T01:57:12.237Z], totalTime: Optional[PT0S]]
test TreeTest.test1(): success
  p1 pid: 171592
 waiting for subprocesses of 171592 to start, expected: 3, current: 0
 waiting for subprocesses of 171592 to start, expected: 3, current: 0
 waiting for subprocesses of 171592 to start, expected: 3, current: 3
 waiting for subprocesses of 106868 to start, expected: 2, current: 0
 waiting for subprocesses of 106868 to start, expected: 2, current: 0
 waiting for subprocesses of 106868 to start, expected: 2, current: 0
 waiting for subprocesses of 106868 to start, expected: 2, current: 0
 waiting for subprocesses of 106868 to start, expected: 2, current: 2
 waiting for subprocesses of 113116 to start, expected: 2, current: 2
 waiting for subprocesses of 143936 to start, expected: 2, current: 2
 allChildren:  [106868, 113116, 143936, 111488, 167068, 17264, 84620, 48040, 85224]
destroyProcessTree destroyForcibly
pid 171592, alive: false; parent: Optional[71416], [user: Optional[ORADEV\\gtee], startTime: Optional[2015-06-07T01:57:13.365Z], totalTime: Optional[PT1.046875S]]
test TreeTest.test2(): success
 p1: 108768
test TreeTest.test3(): failure
java.lang.AssertionError: Wrong number of spawned children expected [1] but found [2]
	at org.testng.Assert.fail(Assert.java:94)
	at org.testng.Assert.failNotEquals(Assert.java:494)
	at org.testng.Assert.assertEquals(Assert.java:123)
	at org.testng.Assert.assertEquals(Assert.java:265)
	at TreeTest.test3(TreeTest.java:209)
	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:502)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
	at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
	at org.testng.TestRunner.privateRun(TestRunner.java:767)
	at org.testng.TestRunner.run(TestRunner.java:617)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:334)
	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:329)
	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:291)
	at org.testng.SuiteRunner.run(SuiteRunner.java:240)
	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1224)
	at org.testng.TestNG.runSuitesLocally(TestNG.java:1149)
	at org.testng.TestNG.run(TestNG.java:1057)
	at com.sun.javatest.regtest.TestNGAction$TestNGRunner.main(TestNGAction.java:163)
	at com.sun.javatest.regtest.TestNGAction$TestNGRunner.main(TestNGAction.java:147)
	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:502)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:92)
	at java.lang.Thread.run(Thread.java:745)
    Parent     Child  Info
        null,       0, []
        null,       4, []
        null,     240, []
        null,     348, [, cmd: C:\\Windows\\System32\\svchost.exe, startTime: Optional[2015-04-26T19:15:13.456Z], totalTime: Optional[PT2M15.265625S]]
        null,     380, []
        null,     436, []
        null,     444, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\wininit.exe, startTime: Optional[2015-04-26T19:14:49.371Z], totalTime: Optional[PT0.609375S]]
        null,     488, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\winlogon.exe, startTime: Optional[2015-04-26T19:14:49.824Z], totalTime: Optional[PT0.75S]]
        null,     596, [, cmd: C:\\Windows\\System32\\svchost.exe, startTime: Optional[2015-04-26T19:15:04.351Z], totalTime: Optional[PT1M7.421875S]]
        null,     640, [, cmd: C:\\Windows\\System32\\svchost.exe, startTime: Optional[2015-04-26T19:15:05.085Z], totalTime: Optional[PT4M32.765625S]]
        null,     708, [, cmd: C:\\Windows\\System32\\svchost.exe, startTime: Optional[2015-04-26T19:15:07.022Z], totalTime: Optional[PT3M24.046875S]]
        null,     740, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\svchost.exe, startTime: Optional[2015-04-26T19:15:07.616Z], totalTime: Optional[PT50M16.265625S]]
        null,     824, [, cmd: C:\\Windows\\System32\\svchost.exe, startTime: Optional[2015-04-26T19:15:08.084Z], totalTime: Optional[PT51.84375S]]
        null,     928, [, cmd: C:\\Windows\\System32\\svchost.exe, startTime: Optional[2015-04-26T19:15:08.943Z], totalTime: Optional[PT3M50.75S]]
        null,    1008, [, cmd: C:\\Windows\\System32\\spoolsv.exe, startTime: Optional[2015-04-26T19:15:15.127Z], totalTime: Optional[PT6.96875S]]
        null,    1060, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Program Files (x86)\\McAfee\\Common Framework\\FrameworkService.exe, startTime: Optional[2015-04-26T19:15:15.893Z], totalTime: Optional[PT5M24.984375S]]
        null,    1132, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Program Files (x86)\\McAfee\\VirusScan Enterprise\\vstskmgr.exe, startTime: Optional[2015-04-26T19:15:18.861Z], totalTime: Optional[PT6.09375S]]
        null,    1164, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\mfevtps.exe, startTime: Optional[2015-04-26T19:15:21.157Z], totalTime: Optional[PT29.453125S]]
        null,    1200, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\SysWOW64\\mksauth.exe, startTime: Optional[2015-04-26T19:15:21.313Z], totalTime: Optional[PT0.46875S]]
        null,    1276, [, cmd: C:\\Program Files\\Microsoft SQL Server\\MSSQL10.SQLEXPRESS\\MSSQL\\Binn\\sqlservr.exe, startTime: Optional[2015-04-26T19:15:21.922Z], totalTime: Optional[PT47H9M14S]]
        null,    1396, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\mksnt\\bin\\secshd.exe, startTime: Optional[2015-04-26T19:15:33.792Z], totalTime: Optional[PT1.40625S]]
        null,    1400, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\nutsrv4.exe, startTime: Optional[2015-04-26T19:15:29.465Z], totalTime: Optional[PT4.3125S]]
        null,    1432, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Program Files (x86)\\Oracle Corporation\\Oracle VM Windows PV Drivers\\OVMSvc_64.exe, startTime: Optional[2015-04-26T19:15:29.793Z], totalTime: Optional[PT15.390625S]]
        null,    1536, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\mksnt\\bin\\snmptrapd.exe, startTime: Optional[2015-04-26T19:15:30.386Z], totalTime: Optional[PT16M1.9375S]]
        null,    1612, [, cmd: C:\\Program Files\\Microsoft SQL Server\\90\\Shared\\sqlwriter.exe, startTime: Optional[2015-04-26T19:15:30.841Z], totalTime: Optional[PT0.671875S]]
        null,    1648, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\svchost.exe, startTime: Optional[2015-04-26T19:15:31.307Z], totalTime: Optional[PT10.890625S]]
        null,    1664, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Program Files\\UltraVNC\\winvnc.exe, startTime: Optional[2015-04-26T19:15:31.366Z], totalTime: Optional[PT9.578125S]]
        null,    1724, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Program Files\\Common Files\\McAfee\\SystemCore\\mcshield.exe, startTime: Optional[2015-04-26T19:15:31.756Z], totalTime: Optional[PT10H30M37.078125S]]
        null,    2020, [, cmd: C:\\Windows\\System32\\svchost.exe, startTime: Optional[2015-04-26T19:17:14.508Z], totalTime: Optional[PT10.796875S]]
        null,    2060, [user: Optional[ORADEV\\gtee], cmd: C:\\Program Files (x86)\\McAfee\\Common Framework\\UdaterUI.exe, startTime: Optional[2015-04-26T19:19:22.258Z], totalTime: Optional[PT1M9.953125S]]
        null,    2112, [user: Optional[ORADEV\\gtee], cmd: C:\\Windows\\explorer.exe, startTime: Optional[2015-04-26T19:18:55.713Z], totalTime: Optional[PT51.234375S]]
        null,    3032, [, cmd: C:\\Windows\\System32\\msdtc.exe, startTime: Optional[2015-04-26T19:18:43.113Z], totalTime: Optional[PT0.6875S]]
        null,   15312, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\winlogon.exe, startTime: Optional[2015-04-30T19:15:48.998Z], totalTime: Optional[PT0.203125S]]
        null,   22728, []
        null,   25328, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\tee.exe, startTime: Optional[2015-06-07T00:55:12.889Z], totalTime: Optional[PT0.0625S]]
        null,   61136, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:45:46.269Z], totalTime: Optional[PT1.015625S]]
        null,  119320, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:57:44.359Z], totalTime: Optional[PT0.0625S]]
        null,  128652, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\sleep.exe, startTime: Optional[2015-06-07T01:57:19.107Z], totalTime: Optional[PT0S]]
        null,  143380, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:57:19.292Z], totalTime: Optional[PT0.46875S]]
        null,  171592, [user: Optional[ORADEV\\gtee], startTime: Optional[2015-06-07T01:57:13.365Z], totalTime: Optional[PT1.046875S]]
         444,     528, []
         444,     536, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\lsass.exe, startTime: Optional[2015-04-26T19:14:57.477Z], totalTime: Optional[PT6M2.3125S]]
         488,     816, [, cmd: C:\\Windows\\System32\\dwm.exe, startTime: Optional[2015-04-26T19:15:08.006Z], totalTime: Optional[PT2.140625S]]
         488,    3996, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\LogonUI.exe, startTime: Optional[2015-04-26T20:19:26.871Z], totalTime: Optional[PT0.59375S]]
         596,    1336, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Program Files (x86)\\McAfee\\Common Framework\\naPrdMgr.exe, startTime: Optional[2015-04-26T19:15:22.906Z], totalTime: Optional[PT1M26.296875S]]
         596,    2828, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\wbem\\WmiPrvSE.exe, startTime: Optional[2015-04-26T19:16:33.270Z], totalTime: Optional[PT36M51.25S]]
         596,    3008, [user: Optional[ORADEV\\gtee], cmd: C:\\Windows\\System32\\OpenWith.exe, startTime: Optional[2015-04-26T19:19:15.461Z], totalTime: Optional[PT0.359375S]]
         740,    3316, [user: Optional[ORADEV\\gtee], cmd: C:\\Windows\\System32\\taskhostex.exe, startTime: Optional[2015-04-26T19:18:54.773Z], totalTime: Optional[PT0.28125S]]
        1132,    1192, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Program Files (x86)\\McAfee\\VirusScan Enterprise\\mfeann.exe, startTime: Optional[2015-04-26T19:15:21.313Z], totalTime: Optional[PT6.828125S]]
        1184,     896, [user: Optional[ORADEV\\gtee], cmd: C:\\Windows\\System32\\conhost.exe, startTime: Optional[2015-04-26T19:19:13.948Z], totalTime: Optional[PT24M30.1875S]]
        1184,    3512, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-04-26T19:19:14.225Z], totalTime: Optional[PT0.140625S]]
        1192,    1244, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\conhost.exe, startTime: Optional[2015-04-26T19:15:21.501Z], totalTime: Optional[PT30.5S]]
        1664,   17356, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Program Files\\UltraVNC\\winvnc.exe, startTime: Optional[2015-04-30T19:15:57.735Z], totalTime: Optional[PT23.640625S]]
        2060,    3660, [user: Optional[ORADEV\\gtee], cmd: C:\\Program Files (x86)\\McAfee\\Common Framework\\McTray.exe, startTime: Optional[2015-04-26T19:19:24.027Z], totalTime: Optional[PT14.203125S]]
        2112,    1184, [user: Optional[ORADEV\\gtee], cmd: C:\\Windows\\System32\\cmd.exe, startTime: Optional[2015-04-26T19:19:13.945Z], totalTime: Optional[PT0.140625S]]
        3512,    3172, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-04-26T19:19:20.960Z], totalTime: Optional[PT1M4.25S]]
       15312,   19860, [user: Optional[NT AUTHORITY\\SYSTEM], cmd: C:\\Windows\\System32\\LogonUI.exe, startTime: Optional[2015-04-30T19:15:54.427Z], totalTime: Optional[PT0.90625S]]
       15312,   23224, [, cmd: C:\\Windows\\System32\\dwm.exe, startTime: Optional[2015-04-30T19:15:54.428Z], totalTime: Optional[PT0.5625S]]
       29488,   71416, [user: Optional[ORADEV\\gtee], cmd: C:\\local\\aurora\\CommonData\\jdk\\bin\\java.exe, startTime: Optional[2015-06-07T01:57:10.550Z], totalTime: Optional[PT3.40625S]]
       33000,   66572, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:55:12.876Z], totalTime: Optional[PT0.46875S]]
       61136,   21988, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:46:05.812Z], totalTime: Optional[PT1.234375S]]
       61136,   33000, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:55:12.866Z], totalTime: Optional[PT0.03125S]]
       66572,  148520, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:57:19.276Z], totalTime: Optional[PT9.5625S]]
       66572,  176328, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:57:19.266Z], totalTime: Optional[PT0S]]
       71416,  108768, [user: Optional[ORADEV\\gtee], cmd: C:\\local\\aurora\\CommonData\\jdk\\bin\\java.exe, startTime: Optional[2015-06-07T01:57:19.311Z], totalTime: Optional[PT0.1875S]]
       71416,  135448, [user: Optional[ORADEV\\gtee], cmd: C:\\Windows\\System32\\conhost.exe, startTime: Optional[2015-06-07T01:57:10.552Z], totalTime: Optional[PT0.015625S]]
      108768,   26964, [user: Optional[ORADEV\\gtee], cmd: C:\\Windows\\System32\\conhost.exe, startTime: Optional[2015-06-07T01:57:19.312Z], totalTime: Optional[PT0.015625S]]
      117492,   29488, [user: Optional[ORADEV\\gtee], cmd: C:\\local\\aurora\\CommonData\\STABLE_JAVA_HOME\\bin\\java.exe, startTime: Optional[2015-06-07T00:57:45.610Z], totalTime: Optional[PT8.96875S]]
      119320,  117492, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:57:45.598Z], totalTime: Optional[PT0.015625S]]
      143380,   12964, [user: Optional[ORADEV\\gtee], cmd: C:\\cygwin\\bin\\bash.exe, startTime: Optional[2015-06-07T00:57:44.335Z], totalTime: Optional[PT0.03125S]]
test TreeTest.test4(): success
Spawning 2 x 2 x 2 processes, pid: 174484
 waiting for subprocesses of 174484 to start, expected: 14, current: 0
 waiting for subprocesses of 174484 to start, expected: 14, current: 0
 waiting for subprocesses of 174484 to start, expected: 14, current: 2
 waiting for subprocesses of 174484 to start, expected: 14, current: 2
 waiting for subprocesses of 174484 to start, expected: 14, current: 5
 waiting for subprocesses of 174484 to start, expected: 14, current: 6
 waiting for subprocesses of 174484 to start, expected: 14, current: 6
 waiting for subprocesses of 174484 to start, expected: 14, current: 8
 waiting for subprocesses of 174484 to start, expected: 14, current: 12
 waiting for subprocesses of 174484 to start, expected: 14, current: 12
 waiting for subprocesses of 174484 to start, expected: 14, current: 12
 waiting for subprocesses of 174484 to start, expected: 14, current: 14
 allChildren:  [18160, 19572, 73664, 40932, 11564, 89964, 56396, 168700, 79288, 173344, 142644, 155840, 62592, 100216]
Duration: PT10.9140988S
destroyProcessTree destroyForcibly
pid 108768, alive: true; parent: Optional[71416], [user: Optional[ORADEV\\gtee], cmd: C:\\local\\aurora\\CommonData\\jdk\\bin\\java.exe, startTime: Optional[2015-06-07T01:57:19.311Z], totalTime: Optional[PT1S]]
test TreeTest.test5(): success

===============================================
java/lang/ProcessHandle/TreeTest.java
Total tests run: 5, Failures: 1, Skips: 0
===============================================
Comments
Review thread: http://mail.openjdk.java.net/pipermail/core-libs-dev/2015-July/034468.html
07-07-2015