Derby
  1. Derby
  2. DERBY-4201

SecureServerTest AssertionFailedError: Timed out waiting for network server to start

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Minor Minor
    • Resolution: Fixed
    • Affects Version/s: 10.5.2.0, 10.7.1.1, 10.8.2.2
    • Component/s: Test
    • Environment:
      java version "1.4.2"
      Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.2)
      Classic VM (build 1.4.2, J2RE 1.4.2 IBM build cxia32142-20061124 (SR7) (JIT enabled: jitc))
      SUSE linux running on vmware.
    • Urgency:
      Normal
    • Bug behavior facts:
      Regression Test Failure

      Description

      I saw this failure in the nightly run on 4/27 on the 10.5 branch - 10.5.1.2 - (769232). I have not seen it in previous runs on the same machine. There were actually two failures in the test. I think the second one failed because of the first so am not reporting a separate issue for that.

      There were 2 failures:
      1) SecureServerTest( Opened = false, Authenticated= false, CustomDerbyProperties= null, WildCardHost= null )junit.framework.AssertionFailedError: Timed out waiting for network server to start:Spawned SpawnedNetworkServer exitCode=0
      at org.apache.derbyTesting.junit.NetworkServerTestSetup.setUp(NetworkServerTestSetup.java:200)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:18)
      at junit.extensions.TestSetup.run(TestSetup.java:23)
      at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
      at junit.extensions.TestSetup.run(TestSetup.java:23)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
      at junit.extensions.TestSetup.run(TestSetup.java:23)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
      at junit.extensions.TestSetup.run(TestSetup.java:23)
      2) SecureServerTest( Opened = false, Authenticated= false, CustomDerbyProperties= functionTests/tests/derbynet/SecureServerTest.derby.properties, WildCardHost= null )junit.framework.AssertionFailedError: directory trace does not exist
      at org.apache.derbyTesting.functionTests.tests.derbynet.SecureServerTest.setTraceDirectory(SecureServerTest.java:386)
      at org.apache.derbyTesting.functionTests.tests.derbynet.SecureServerTest.testServerStartup(SecureServerTest.java:358)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:85)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:58)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java(Compiled Code))
      at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:105)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
      at junit.extensions.TestSetup.run(TestSetup.java:23)
      at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
      at junit.extensions.TestSetup.run(TestSetup.java:23)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
      at junit.extensions.TestSetup.run(TestSetup.java:23)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
      at junit.extensions.TestSetup.run(TestSetup.java:23)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
      at junit.extensions.TestSetup.run(TestSetup.java:23)

      1. repro.diff
        2 kB
        Knut Anders Hatlen
      2. d4201-1a.diff
        4 kB
        Knut Anders Hatlen

        Issue Links

          Activity

          Hide
          Knut Anders Hatlen added a comment -

          [bulk update: close all resolved issues that haven't had any activity the last year]

          Show
          Knut Anders Hatlen added a comment - [bulk update: close all resolved issues that haven't had any activity the last year]
          Hide
          Mamta A. Satoor added a comment -

          Assigning to myself to do the backport.

          Show
          Mamta A. Satoor added a comment - Assigning to myself to do the backport.
          Hide
          Kathey Marsden added a comment -

          Reopen for 10.5 backport consideration. If working on the backport for this issue. Temporarily assign yourself and add a comment that you are working on it. When finished, reresolve with the new fix versions or label backport_reject_10_x as appropriate.

          Show
          Kathey Marsden added a comment - Reopen for 10.5 backport consideration. If working on the backport for this issue. Temporarily assign yourself and add a comment that you are working on it. When finished, reresolve with the new fix versions or label backport_reject_10_x as appropriate.
          Hide
          Knut Anders Hatlen added a comment -

          I think so. I have run the regression tests on 10.8 with the patch without seeing any problems, and I haven't seen any related problems in the nightly tests on trunk after the fix went in. Backported and committed revision 1214635.

          Show
          Knut Anders Hatlen added a comment - I think so. I have run the regression tests on 10.8 with the patch without seeing any problems, and I haven't seen any related problems in the nightly tests on trunk after the fix went in. Backported and committed revision 1214635.
          Hide
          Myrna van Lunteren added a comment -

          Is this fix suitable for backport to 10.8?

          Show
          Myrna van Lunteren added a comment - Is this fix suitable for backport to 10.8?
          Hide
          Dag H. Wanvik added a comment -

          Clean patch, looks good to me! +1.
          Good to get all these issues cleaned up. Thanks, Knut.

          Show
          Dag H. Wanvik added a comment - Clean patch, looks good to me! +1. Good to get all these issues cleaned up. Thanks, Knut.
          Hide
          Knut Anders Hatlen added a comment -

          Committed revision 1210846.

          I believe this issue is also what's causing DERBY-4265, DERBY-4914, DERBY-5194, DERBY-5518 and DERBY-5520, so we might close those issues as duplicates for now and reopen them if they happen again.

          Show
          Knut Anders Hatlen added a comment - Committed revision 1210846. I believe this issue is also what's causing DERBY-4265 , DERBY-4914 , DERBY-5194 , DERBY-5518 and DERBY-5520 , so we might close those issues as duplicates for now and reopen them if they happen again.
          Hide
          Knut Anders Hatlen added a comment -

          Attaching a patch (d4201-1a.diff) which attempts to address these intermittent failures by making NetworkServerTestSetup wait until the previous test has completely shut down its server instance, before it tries to start a new server.

          This is done by attempting to start a ServerSocket listening on the server port and immediately closing it. If it succeeds, the decorator assumes it is safe to start a new server. If it fails, the decorator waits a little while (0.1 sec) before it tries again. If it doesn't succeed until the server startup timeout (default 40 sec, configurable with derby.tests.networkServerStartTimeout) has elapsed, it gives up and report an exception.

          SecureServerTest passes with this patch (when using the repro.diff patch to provoke the problem), and so does AutoloadTest (DERBY-5194).

          Show
          Knut Anders Hatlen added a comment - Attaching a patch (d4201-1a.diff) which attempts to address these intermittent failures by making NetworkServerTestSetup wait until the previous test has completely shut down its server instance, before it tries to start a new server. This is done by attempting to start a ServerSocket listening on the server port and immediately closing it. If it succeeds, the decorator assumes it is safe to start a new server. If it fails, the decorator waits a little while (0.1 sec) before it tries again. If it doesn't succeed until the server startup timeout (default 40 sec, configurable with derby.tests.networkServerStartTimeout) has elapsed, it gives up and report an exception. SecureServerTest passes with this patch (when using the repro.diff patch to provoke the problem), and so does AutoloadTest ( DERBY-5194 ).
          Hide
          Knut Anders Hatlen added a comment -

          Using the sleep-repro.diff patch attached to DERBY-5194, I'm able to reproduce the failure reported here too. Not when running SecureServerTest alone, but when running as part of a suite so that there is a network server from an earlier test case that's only partially shut down when SecureServerTest starts.

          See the attached repro.diff that combines the changes in the DERBY-5194 repro patch with adding NetHarnessJavaTest at the beginning of the test suite returned by SecureServerTest.suite(). With that patch, SecureServerTest fails when running alone.

          The suspected cause of this intermittent failure is that the server used in an earlier test case might not be fully shut down when a new test case starts. The server shutdown command doesn't return until the server has stopped responding to ping. That works most of the time, but since it stops responding to ping before it actually releases the server socket, there is a possibility that the new server is started too early and fails to start listening on the port.

          Show
          Knut Anders Hatlen added a comment - Using the sleep-repro.diff patch attached to DERBY-5194 , I'm able to reproduce the failure reported here too. Not when running SecureServerTest alone, but when running as part of a suite so that there is a network server from an earlier test case that's only partially shut down when SecureServerTest starts. See the attached repro.diff that combines the changes in the DERBY-5194 repro patch with adding NetHarnessJavaTest at the beginning of the test suite returned by SecureServerTest.suite(). With that patch, SecureServerTest fails when running alone. The suspected cause of this intermittent failure is that the server used in an earlier test case might not be fully shut down when a new test case starts. The server shutdown command doesn't return until the server has stopped responding to ping. That works most of the time, but since it stops responding to ping before it actually releases the server socket, there is a possibility that the new server is started too early and fails to start listening on the port.
          Hide
          Knut Anders Hatlen added a comment -
          Show
          Knut Anders Hatlen added a comment - Seen again when testing the 10.8.2.2 release candidate: http://dbtg.foundry.sun.com/derby/test/10.8.2.2_RC/logs/jvm1.6/lin/suitesAll/report.txt
          Hide
          Knut Anders Hatlen added a comment -
          Show
          Knut Anders Hatlen added a comment - Seen again when testing the 10.7.1.1 release candidate: http://dbtg.foundry.sun.com/derby/test/10.7.1.1_RC/logs/jvm1.6-64/sles/suitesAll/report.txt
          Hide
          Myrna van Lunteren added a comment - - edited

          Seen again at least on linux/vmware combo with 10.5.2.1 (799161) with ibm 1.4.2. (same build); and also during the 10.5.2.0 testing (once with ibm15 on linux/vmware; once with ibm 16 on XP).

          Show
          Myrna van Lunteren added a comment - - edited Seen again at least on linux/vmware combo with 10.5.2.1 (799161) with ibm 1.4.2. (same build); and also during the 10.5.2.0 testing (once with ibm15 on linux/vmware; once with ibm 16 on XP).

            People

            • Assignee:
              Mamta A. Satoor
              Reporter:
              Kathey Marsden
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development