Derby
  1. Derby
  2. DERBY-4322

intermittent test failure in derbynet/runtimeinfo

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 10.5.2.0
    • Fix Version/s: 10.5.3.1, 10.6.1.0
    • Component/s: Test
    • Labels:
      None
    • Environment:
      Linux/VMware with IBM 1.5 or 1.6; IBM iseries (AS 400/ V5R4M0) with IBM 1.6

      Description

      A few times in regression testing of builds of the 10.5 branch, and also with the testing cycle of 10.5.2.0 on iseries I've seen failures in derbynet/runtimeinfo.

      They look like differences in the Session id and timing differences in return of text to the client.
      For instance, this is with ibm 1.6 on iseries:
      ---------------------------------------
      5 del
      < Session # :2
      5a5
      > Session # :52
      12 del
      < Session # :3
      12a12
      > Session # :86
      23 del
      < Session # :2
      23a23
      > Session # :52
      32 del
      < Session # :4
      32a32
      > Session # :88
      41 del
      < Session # :5
      41a41
      > Session # :90
      48 del
      < Session # :6
      48a48
      > Session # :113
      58 del
      < Session # :7
      58a58
      > Session # :117
      ---------------------------------------

      And this is an example of a failure on linux/vmware on 7/15/09 (10.5.1.2 revision: 794133)

      ---------------------------------------
      5 del
      < Session # :2
      5a5,6
      > Session # :89
      > Session # :62
      12d12
      < Session # :3
      23 del
      < Session # :2
      23a23
      > Session # :90
      29a30,38
      > SYSLH0002 VALUES(2)
      > SYSLH0001 SELECT count from sys.systables
      > Session # :62
      > Database :wombat;create=true
      > User :APP
      > # Statements:2
      > Prepared Statement Information:
      > Stmt ID SQLText
      > ------------- -----------
      32 del
      < Session # :4
      32a41
      > Session # :92
      35,43d43
      < # Statements:2
      < Prepared Statement Information:
      < Stmt ID SQLText
      < ------------- -----------
      < SYSLH0002 VALUES(2)
      < SYSLH0001 SELECT count from sys.systables
      < Session # :5
      < Database :wombat;create=true
      < User :APP
      48 del
      < Session # :6
      48a48
      > Session # :101
      58 del
      < Session # :7
      58a58
      > Session # :108
      ---------------------------------------

      It seems to me these are fairly innocent, and if they are, then possibly the solution is to backport the conversion of runtimeinfo to junit to 10.5. (see DERBY-3834, revisions 792001 and 792254.)

      1. DERBY-4322.diff
        3 kB
        Myrna van Lunteren

        Activity

        Hide
        Myrna van Lunteren added a comment -

        Because I heard of another possible instance of this test failure, I looked back at the history of that 7/15/09 test run, and it may be of interest that the test derbynet/DerbyNetAutoStart failed just before:
        -------------------------
        [...]
        Test Failed.

            • End: runtimeinfo jdk1.4.2 DerbyNetClient derbynetmats:derbynetmats 2009-07-16 01:47:06 ***
                        • Diff file derbyall/derbynetclientmats/DerbyNetClient/derbynetmats/derbynetmats/DerbyNetAutoStart.diff
            • Start: DerbyNetAutoStart jdk1.4.2 DerbyNetClient derbynetmats:derbynetmats 2009-07-16 01:39:22 ***
              1a2,3
              > Could not access database through the network server.
              > The connection was refused because the database database1 was not found.
              2a5,6
              > Could not access database through the network server.
              > java.net.ConnectException : Error connecting to server xxxFILTERED_HOSTNAMExxx on port 31415 with message Connection refused.
              6 del
              < PASSED.
              6 add
              > java.sql.SQLException: The connection was refused because the database database1 was not found.
              > Caused by: org.apache.derby.client.am.DisconnectException: The connection was refused because the database database1 was not found.
              > ... 6 more
              > Server start failed: The connection was refused because the database database1 was not found.
              > FAILED.
              Test Failed.
              -------------------------
              So perhaps something is still hanging around holding on to session numbers?
        Show
        Myrna van Lunteren added a comment - Because I heard of another possible instance of this test failure, I looked back at the history of that 7/15/09 test run, and it may be of interest that the test derbynet/DerbyNetAutoStart failed just before: ------------------------- [...] Test Failed. End: runtimeinfo jdk1.4.2 DerbyNetClient derbynetmats:derbynetmats 2009-07-16 01:47:06 *** Diff file derbyall/derbynetclientmats/DerbyNetClient/derbynetmats/derbynetmats/DerbyNetAutoStart.diff Start: DerbyNetAutoStart jdk1.4.2 DerbyNetClient derbynetmats:derbynetmats 2009-07-16 01:39:22 *** 1a2,3 > Could not access database through the network server. > The connection was refused because the database database1 was not found. 2a5,6 > Could not access database through the network server. > java.net.ConnectException : Error connecting to server xxxFILTERED_HOSTNAMExxx on port 31415 with message Connection refused. 6 del < PASSED. 6 add > java.sql.SQLException: The connection was refused because the database database1 was not found. > Caused by: org.apache.derby.client.am.DisconnectException: The connection was refused because the database database1 was not found. > ... 6 more > Server start failed: The connection was refused because the database database1 was not found. > FAILED. Test Failed. ------------------------- So perhaps something is still hanging around holding on to session numbers?
        Hide
        Myrna van Lunteren added a comment -

        Assuming the problem is really with DerbyNetAutoStart, here's a patch that tries to slow things down and ensure that the server process gets destroyed.
        I ran DerbyNetAutoStart (successfully) only so far.

        Show
        Myrna van Lunteren added a comment - Assuming the problem is really with DerbyNetAutoStart, here's a patch that tries to slow things down and ensure that the server process gets destroyed. I ran DerbyNetAutoStart (successfully) only so far.
        Hide
        Kathey Marsden added a comment -

        Ran derbyall and committed Myrna's patch. I will resolve the issue assuming this is the problem and it can be reopened if it does not correct the problem.

        The theory is that this failure is caused by a problem in the previous test DerbyNetAutostart which launches a process to start the server and can be left pinging if the check for the server in the launching process, does not allow enough time for the server to come up. The pings increment the session number as seen by runtimeinfo. So the changes are to DerbyNetAutoStart and are to

        1) Make sure the server launching process retries enough times for the launched process comes up.
        2) Make sure if something does go wrong, the launched process is destroyed

        Show
        Kathey Marsden added a comment - Ran derbyall and committed Myrna's patch. I will resolve the issue assuming this is the problem and it can be reopened if it does not correct the problem. The theory is that this failure is caused by a problem in the previous test DerbyNetAutostart which launches a process to start the server and can be left pinging if the check for the server in the launching process, does not allow enough time for the server to come up. The pings increment the session number as seen by runtimeinfo. So the changes are to DerbyNetAutoStart and are to 1) Make sure the server launching process retries enough times for the launched process comes up. 2) Make sure if something does go wrong, the launched process is destroyed
        Hide
        Myrna van Lunteren added a comment -

        Thanks for the test run & commit Kathey.
        I backported revision 925377 to 10.5, ran derbynetclientmats to be sure, and committed with revision 926246.

        Show
        Myrna van Lunteren added a comment - Thanks for the test run & commit Kathey. I backported revision 925377 to 10.5, ran derbynetclientmats to be sure, and committed with revision 926246.

          People

          • Assignee:
            Myrna van Lunteren
            Reporter:
            Myrna van Lunteren
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development