Derby
  1. Derby
  2. DERBY-2933

When network server disconnects due to an I/O Exception it does not always log the exception that caused the error

    Details

    • Type: Bug Bug
    • Status: Open
    • Priority: Minor Minor
    • Resolution: Unresolved
    • Affects Version/s: 10.2.2.1
    • Fix Version/s: None
    • Component/s: Network Server
    • Urgency:
      Normal
    • Issue & fix info:
      Repro attached

      Description

      I found this issue when debugging my attempted fix for DERBY-2892. The I/O Exception that occurs in writeScalarStream is not logged. To reproduce apply the patch in DERBY-2892 and run the repro there.

      1. DERBY-2933_no_commit_diff.txt
        4 kB
        Kathey Marsden
      2. derby-2933_diff.txt
        5 kB
        Kathey Marsden
      3. derby-2933_stat.txt
        0.2 kB
        Kathey Marsden

        Issue Links

          Activity

          Hide
          Kathey Marsden added a comment -

          Reproducible case is in DERBY-2892

          Show
          Kathey Marsden added a comment - Reproducible case is in DERBY-2892
          Hide
          Kathey Marsden added a comment -

          Attached is a patch that logs the IO/exceptions and other events that cause markCommunicationsFailure to be called. This change caused testNetworkServerSecurityMechanism to start logging this error. I am investigating that, but the patch to turn on the logging should not be committed until this is resolved.

          testNetworkServerSecurityMechanism(org.apache.derbyTesting.functionTests.tests.derbynet.NSSecurityMechanismTest)
          java.lang.Exception: totalBytesRead < minimumBytesNeeded
          at org.apache.derby.impl.drda.DDMReader.fill(DDMReader.java:1936)
          at org.apache.derby.impl.drda.DDMReader.ensureALayerDataInBuffer(DDMReader.java:1651)
          at org.apache.derby.impl.drda.DDMReader.readDssHeader(DDMReader.java:321)
          at org.apache.derby.impl.drda.DRDAConnThread.processCommands(DRDAConnThread.java:677)
          at org.apache.derby.impl.drda.DRDAConnThread.run(DRDAConnThread.java:275)

          Show
          Kathey Marsden added a comment - Attached is a patch that logs the IO/exceptions and other events that cause markCommunicationsFailure to be called. This change caused testNetworkServerSecurityMechanism to start logging this error. I am investigating that, but the patch to turn on the logging should not be committed until this is resolved. testNetworkServerSecurityMechanism(org.apache.derbyTesting.functionTests.tests.derbynet.NSSecurityMechanismTest) java.lang.Exception: totalBytesRead < minimumBytesNeeded at org.apache.derby.impl.drda.DDMReader.fill(DDMReader.java:1936) at org.apache.derby.impl.drda.DDMReader.ensureALayerDataInBuffer(DDMReader.java:1651) at org.apache.derby.impl.drda.DDMReader.readDssHeader(DDMReader.java:321) at org.apache.derby.impl.drda.DRDAConnThread.processCommands(DRDAConnThread.java:677) at org.apache.derby.impl.drda.DRDAConnThread.run(DRDAConnThread.java:275)
          Hide
          Kathey Marsden added a comment -

          The error occurs whenever the datbase is shutdown and can be reproduced with this script.
          It seems there is some cleanup needed of DDMReader when a severe error occurs.

          ij> connect 'jdbc:derby://localhost:1527/wombat;create=true';
          ij> connect 'jdbc:derby://localhost:1527/;shutdown=true';
          totalBytesRead < minimumBytesNeeded
          java.lang.Exception: totalBytesRead < minimumBytesNeeded
          at org.apache.derby.impl.drda.DDMReader.fill(DDMReader.java:1936)
          at org.apache.derby.impl.drda.DDMReader.ensureALayerDataInBuffer(DDMReader.java:1651)
          at org.apache.derby.impl.drda.DDMReader.readDssHeader(DDMReader.java:321)
          at org.apache.derby.impl.drda.DRDAConnThread.processCommands(DRDAConnThread.java:680)
          at org.apache.derby.impl.drda.DRDAConnThread.run(DRDAConnThread.java:275)
          ERROR XJ015: DERBY SQL error: SQLCODE: -1, SQLSTATE: XJ015, SQLERRMC: Derby system shutdown.

          Show
          Kathey Marsden added a comment - The error occurs whenever the datbase is shutdown and can be reproduced with this script. It seems there is some cleanup needed of DDMReader when a severe error occurs. ij> connect 'jdbc:derby://localhost:1527/wombat;create=true'; ij> connect 'jdbc:derby://localhost:1527/;shutdown=true'; totalBytesRead < minimumBytesNeeded java.lang.Exception: totalBytesRead < minimumBytesNeeded at org.apache.derby.impl.drda.DDMReader.fill(DDMReader.java:1936) at org.apache.derby.impl.drda.DDMReader.ensureALayerDataInBuffer(DDMReader.java:1651) at org.apache.derby.impl.drda.DDMReader.readDssHeader(DDMReader.java:321) at org.apache.derby.impl.drda.DRDAConnThread.processCommands(DRDAConnThread.java:680) at org.apache.derby.impl.drda.DRDAConnThread.run(DRDAConnThread.java:275) ERROR XJ015: DERBY SQL error: SQLCODE: -1, SQLSTATE: XJ015, SQLERRMC: Derby system shutdown.
          Hide
          Kathey Marsden added a comment -

          Here is another attempt at a patch. I am not really all that pleased with it as I fear it may still gobble some unexpected exceptions. This patch is the same as the first except for it does not log an exception for 1) SocketExceptions which are usually the client disconnecting.
          2)The case where DDMReader.fill() expects bytes but gets none. This is the case when the database is shutdown.

          I'd appreciate if someone can take a look. At least the patch does have the advantage that it will log some of the exceptions that were not being logged before. It is just a question of whether that is good enough.

          Kathey

          Show
          Kathey Marsden added a comment - Here is another attempt at a patch. I am not really all that pleased with it as I fear it may still gobble some unexpected exceptions. This patch is the same as the first except for it does not log an exception for 1) SocketExceptions which are usually the client disconnecting. 2)The case where DDMReader.fill() expects bytes but gets none. This is the case when the database is shutdown. I'd appreciate if someone can take a look. At least the patch does have the advantage that it will log some of the exceptions that were not being logged before. It is just a question of whether that is good enough. Kathey
          Hide
          Kathey Marsden added a comment -

          Unassigning myself from this issue and reducing to minor. I fixed the error to log in writeScalarStream but there are still occassions where markCommunicationsFailure is called without logging, most notably when the server is brought down and active sessions are terminated. I left this as is. I am not sure if unexpected exceptions might still be left unlogged, so I am leaving this open.

          Kathey

          Show
          Kathey Marsden added a comment - Unassigning myself from this issue and reducing to minor. I fixed the error to log in writeScalarStream but there are still occassions where markCommunicationsFailure is called without logging, most notably when the server is brought down and active sessions are terminated. I left this as is. I am not sure if unexpected exceptions might still be left unlogged, so I am leaving this open. Kathey
          Hide
          Bernt M. Johnsen added a comment -

          The exception handling in the network server should be taken into consideration in DERBY-2412. That should probably solve this in a decent way.

          Show
          Bernt M. Johnsen added a comment - The exception handling in the network server should be taken into consideration in DERBY-2412 . That should probably solve this in a decent way.
          Hide
          Rick Hillegas added a comment -

          Triage for 10.5.2: Assign normal urgency; note that has reproducible test case.

          Show
          Rick Hillegas added a comment - Triage for 10.5.2: Assign normal urgency; note that has reproducible test case.

            People

            • Assignee:
              Unassigned
              Reporter:
              Kathey Marsden
            • Votes:
              0 Vote for this issue
              Watchers:
              0 Start watching this issue

              Dates

              • Created:
                Updated:

                Development