Derby
  1. Derby
  2. DERBY-2687

store/encryptDatabase.sql fails intermittently with ClassNotFoundException, Log Corrupted

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 10.2.2.1, 10.3.1.4
    • Fix Version/s: 10.8.3.0, 10.9.1.0
    • Component/s: Test
    • Environment:
    • Urgency:
      Normal
    • Issue & fix info:
      Patch Available
    • Bug behavior facts:
      Regression Test Failure

      Description

      Failure seen in derbyall/encryptionAll run on WinXP (10.2.2.1). So far unable to reproduce (standalone or as part of derbyall, encryptionAll or encryptionBlowfish).

      <method>
      store/encryptDatabase.sql
      </method>

      <signature>
      Failure details:

                      • Diff file derbyall/encryptionAll/encryptionBlowfish/encryptDatabase.diff
          • Start: encryptDatabase jdk1.4.2_08 encryptionAll:encryptionBlowfish 2007-05-21 05:07:55 ***
            95 del
            < ERROR XBM06: Startup failed. An encrypted database cannot be accessed without the correct boot password.
            95a95
            > ERROR XJ001: Java exception: 'ERROR XBM0U: No class was registered for identifier 15009.: java.lang.ClassNotFoundException'.
            Test Failed.
          • End: encryptDatabase jdk1.4.2_08 encryptionAll:encryptionBlowfish 2007-05-21 05:08:12 ***
            </signature>

      derby.log also reports "ERROR XSLA3: Log Corrupted, has invalid data in the log stream."

      1. derby.log
        48 kB
        John H. Embretsen
      2. wombat.zip
        444 kB
        John H. Embretsen
      3. tmp-82.zip
        591 kB
        Dag H. Wanvik
      4. derby-2687-1.diff
        36 kB
        Dag H. Wanvik
      5. derby-2687-1.stat
        1 kB
        Dag H. Wanvik
      6. derby-2687-2.diff
        36 kB
        Dag H. Wanvik
      7. derby-2687-2.stat
        1 kB
        Dag H. Wanvik

        Issue Links

          Activity

          John H. Embretsen created issue -
          Hide
          John H. Embretsen added a comment -

          Attached derby.log from the test run on Win XP against 10.2.2.1.

          The failure happened when executing the IJ command
          connect 'jdbc:derby:wombat;bootPassword=Saturday';
          (incorrect boot password, negative test).

          This failure does not seem to occur very often. Yet, similar failures have been observed in previous periodic regression testing, for example:
          http://dbtg.thresher.com/derby/test/Daily/jvm1.6/testing/testlog/sles/531991-encryptionAll_diff.txt

          The diff is not exectly the same, though, and since the derby.log file is apparently no longer available for that test run, it is hard to tell if there was a "Log Corrupted" message there as well.

          Show
          John H. Embretsen added a comment - Attached derby.log from the test run on Win XP against 10.2.2.1. The failure happened when executing the IJ command connect 'jdbc:derby:wombat;bootPassword=Saturday'; (incorrect boot password, negative test). This failure does not seem to occur very often. Yet, similar failures have been observed in previous periodic regression testing, for example: http://dbtg.thresher.com/derby/test/Daily/jvm1.6/testing/testlog/sles/531991-encryptionAll_diff.txt The diff is not exectly the same, though, and since the derby.log file is apparently no longer available for that test run, it is hard to tell if there was a "Log Corrupted" message there as well.
          John H. Embretsen made changes -
          Field Original Value New Value
          Attachment derby.log [ 12358084 ]
          Hide
          John H. Embretsen added a comment -

          Attached database (wombat.zip, 10.2) from the Win XP test run mentioned above.

          Show
          John H. Embretsen added a comment - Attached database (wombat.zip, 10.2) from the Win XP test run mentioned above.
          John H. Embretsen made changes -
          Attachment wombat.zip [ 12358091 ]
          Hide
          John H. Embretsen added a comment -

          Reports from other previous occurrences of this test failure may be found by googling something like:
          +"encryptDatabase" +"ClassNotFoundException" site:dbtg.thresher.com

          It seems that this test has been failing intermittently since (at least) may 2005 (SVN 169872), on various operating systems (including Solaris 9, Solaris 10 (x86 and SPARC), Red Hat Enterprise Linux, Windows XP), on various JVMs (including Sun 1.4.2, 1.5.0, 1.6.0), and in various encryption suites (such as encryptionAES, encryptionCFB, encryptionDES, encryptionECB, encryptionBlowfish).

          Show
          John H. Embretsen added a comment - Reports from other previous occurrences of this test failure may be found by googling something like: +"encryptDatabase" +"ClassNotFoundException" site:dbtg.thresher.com It seems that this test has been failing intermittently since (at least) may 2005 (SVN 169872), on various operating systems (including Solaris 9, Solaris 10 (x86 and SPARC), Red Hat Enterprise Linux, Windows XP), on various JVMs (including Sun 1.4.2, 1.5.0, 1.6.0), and in various encryption suites (such as encryptionAES, encryptionCFB, encryptionDES, encryptionECB, encryptionBlowfish).
          John H. Embretsen made changes -
          Environment Microsoft Windows XP Professional - 5.1.2600 Service Pack 2, Sun JVM 1.4.2_08-b03, 10.2.2.1
          SUSE Linux Enterprise Server 10 (x86_64) (Linux 2.6.16.21-0.8-smp), Sun JVM 1.6.0_01-b06, trunk (SVN 531991)
          Microsoft Windows XP Professional - 5.1.2600 Service Pack 2, Sun JVM 1.4.2_08-b03, 10.2.2.1.
          SUSE Linux Enterprise Server 10 (x86_64) (Linux 2.6.16.21-0.8-smp), Sun JVM 1.6.0_01-b06, trunk (SVN 531991).
          Solaris 10 x86, Sun JVM 1.5.0, SVN 371617 (2006-01-23).
          Solaris 9 SPARC, Sun JVM 1.5.0, SVN 169872 (2005-05-13).
          etc...
          Hide
          John H. Embretsen added a comment -

          Recently also seen in derbyall/encryptionAll/encryptionDES on SUSE Linux (sles) 2007-05-27, trunk @ SVN 541997, Sun JVM 1.6.0_01:
          http://dbtg.thresher.com/derby/test/Daily/jvm1.6/testing/testlog/sles/541997-derbyall_diff.txt

          Show
          John H. Embretsen added a comment - Recently also seen in derbyall/encryptionAll/encryptionDES on SUSE Linux (sles) 2007-05-27, trunk @ SVN 541997, Sun JVM 1.6.0_01: http://dbtg.thresher.com/derby/test/Daily/jvm1.6/testing/testlog/sles/541997-derbyall_diff.txt
          Mike Matrigali made changes -
          Component/s Store [ 11412 ]
          Dag H. Wanvik made changes -
          Derby Categories [Regression Test Failure]
          Dag H. Wanvik made changes -
          Component/s Regression Test Failure [ 12310664 ]
          Show
          Rick Hillegas added a comment - Might be related to this diff seen in the tinderbox tests: http://dbtg.foundry.sun.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/1051893-derbyall_diff.txt
          Hide
          Knut Anders Hatlen added a comment -

          The diff seen by Rick is identical to the one in John's comment from 24/May/07 06:56 AM. (The URL has changed after that. Here's where it can be found now: http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.6/testing/testlog/sles/531991-encryptionAll_diff.txt )

          The first discrepancy reported in those two runs, is a successful attempt to change the password using a wrong old password. From the out file in Rick's failed run:

          ij> connect 'jdbc:derby:wombat;bootPassword=Wednesday';
          ij> – switch back to old password
          call SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('bootPassword', 'Wednesday, Thursday');

          ... The password is sucessfully changed to "Thursday" (as expected) ...

          ij> – change the secret key
          – these should fail
          (...)
          ij> call SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('bootPassword', 'thursday , derbypwd');
          0 rows inserted/updated/deleted

          Here we're for some reason allowed to change the password from "thursday" to "derbypwd", even though the old password is "Thursday", not "thursday". This is where the diff starts.

          Show
          Knut Anders Hatlen added a comment - The diff seen by Rick is identical to the one in John's comment from 24/May/07 06:56 AM. (The URL has changed after that. Here's where it can be found now: http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.6/testing/testlog/sles/531991-encryptionAll_diff.txt ) The first discrepancy reported in those two runs, is a successful attempt to change the password using a wrong old password. From the out file in Rick's failed run: ij> connect 'jdbc:derby:wombat;bootPassword=Wednesday'; ij> – switch back to old password call SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('bootPassword', 'Wednesday, Thursday'); ... The password is sucessfully changed to "Thursday" (as expected) ... ij> – change the secret key – these should fail (...) ij> call SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('bootPassword', 'thursday , derbypwd'); 0 rows inserted/updated/deleted Here we're for some reason allowed to change the password from "thursday" to "derbypwd", even though the old password is "Thursday", not "thursday". This is where the diff starts.
          Kathey Marsden made changes -
          Labels derby_triage10_5_2
          Hide
          Dag H. Wanvik added a comment -

          See again last night:

          http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.6/testing/testlog/sol32/1242855-derbyall_diff.txt

          av svn 1242855

          sol32

          Sun Microsystems Inc.
          1.6.0_241242855
          2012-02-10 18:00:09 MET

          Failure Details:

                          • Diff file derbyall/encryptionAll/encryption/encryption/encryptDatabase.diff
              • Start: encryptDatabase jdk1.6.0_24 encryption:encryption 2012-02-10 22:44:01 ***
                91a92,94
                > ERROR XJ001: Java exception: 'ERROR XBM0U: No class was registered for identifier 30755.: java.lang.ClassNotFoundException'.
                > ij> connect 'jdbc:derby:wombat;bootPassword=Saturday';
                > ERROR XJ040: Failed to start database 'wombat' with class loader XXXX, see the next exception for details.
                93,95d95
                < ij> connect 'jdbc:derby:wombat;bootPassword=Saturday';
                < ERROR XJ040: Failed to start database 'wombat' with class loader XXXX, see the next exception for details.
                < ERROR XBM06: Startup failed. An encrypted database cannot be accessed without the correct boot password.
                Test Failed.
              • End: encryptDatabase jdk1.6.0_24 encryption:encryption 2012-02-10 22:44:06 ***
          Show
          Dag H. Wanvik added a comment - See again last night: http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.6/testing/testlog/sol32/1242855-derbyall_diff.txt av svn 1242855 sol32 Sun Microsystems Inc. 1.6.0_241242855 2012-02-10 18:00:09 MET Failure Details: Diff file derbyall/encryptionAll/encryption/encryption/encryptDatabase.diff Start: encryptDatabase jdk1.6.0_24 encryption:encryption 2012-02-10 22:44:01 *** 91a92,94 > ERROR XJ001: Java exception: 'ERROR XBM0U: No class was registered for identifier 30755.: java.lang.ClassNotFoundException'. > ij> connect 'jdbc:derby:wombat;bootPassword=Saturday'; > ERROR XJ040: Failed to start database 'wombat' with class loader XXXX, see the next exception for details. 93,95d95 < ij> connect 'jdbc:derby:wombat;bootPassword=Saturday'; < ERROR XJ040: Failed to start database 'wombat' with class loader XXXX, see the next exception for details. < ERROR XBM06: Startup failed. An encrypted database cannot be accessed without the correct boot password. Test Failed. End: encryptDatabase jdk1.6.0_24 encryption:encryption 2012-02-10 22:44:06 ***
          Hide
          Knut Anders Hatlen added a comment -

          I've had the test running in a loop for more than a day now (close to 19000 iterations) without seeing the failure. I'll keep it running for a while longer to see if it eventually reproduces. (Solaris 11, x86, java version "1.6.0_26")

          Show
          Knut Anders Hatlen added a comment - I've had the test running in a loop for more than a day now (close to 19000 iterations) without seeing the failure. I'll keep it running for a while longer to see if it eventually reproduces. (Solaris 11, x86, java version "1.6.0_26")
          Hide
          Dag H. Wanvik added a comment -

          I was able to reproduce on my laptop in attempt 82.

              • Start: encryptDatabase jdk1.6.0_26 2012-02-14 18:30:33 ***
                93a94
                > java.lang.ClassNotFoundException: ERROR XBM0U: No class was registered for identifier 44776.
                95 del
                < ERROR XBM06: Startup failed. An encrypted database cannot be accessed without the correct boot password.
                95a96
                > ERROR XJ001: Java exception: 'ERROR XBM0U: No class was registered for identifier 44776.: java.lang.ClassNotFoundException'.
                Test Failed.
              • End: encryptDatabase jdk1.6.0_26 2012-02-14 18:30:40 ***

          Enclosing a zip file with derby.log and the database.

          Show
          Dag H. Wanvik added a comment - I was able to reproduce on my laptop in attempt 82. Start: encryptDatabase jdk1.6.0_26 2012-02-14 18:30:33 *** 93a94 > java.lang.ClassNotFoundException: ERROR XBM0U: No class was registered for identifier 44776. 95 del < ERROR XBM06: Startup failed. An encrypted database cannot be accessed without the correct boot password. 95a96 > ERROR XJ001: Java exception: 'ERROR XBM0U: No class was registered for identifier 44776.: java.lang.ClassNotFoundException'. Test Failed. End: encryptDatabase jdk1.6.0_26 2012-02-14 18:30:40 *** Enclosing a zip file with derby.log and the database.
          Dag H. Wanvik made changes -
          Attachment tmp-82.zip [ 12514539 ]
          Hide
          Dag H. Wanvik added a comment -

          In my repro, it appears the recovery fails (RawStore:333) after the bootPassword has been verified (RawStore:301). Cf the derby.log line 1070: the stack shows we have passed the line 301 in RawStore which should check the bootPassword.

          It seems that a wrong bootPassword passes muster.

          In this case the bootPassword which appears to have been accepted is Saturday. It should have been changed by this time to derbypwd cf.

          call SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('bootPassword', 'Saturday,derbypwd');
          :
          connect 'jdbc:derby:;shutdown=true';
          <failed boot using Saturday: gets too far...?>

          We have done a shutdown of the engine. Could it be that the change of the encryption key wasn't committed prior to the engine shutdown, so that the persistence of the new key would need a log replay before its effective? We have seen before during the interrupt work that there are cases where checkpointing at shutdown may fail.

          Then, next time we try to boot, using derbypwd, it passes the bootpassword check with that (new new) boot password, so it appears that now the new encryption keys is in effect? One can still boot the database using the final bootpassword in the test, derbypwdxx.

          Show
          Dag H. Wanvik added a comment - In my repro, it appears the recovery fails (RawStore:333) after the bootPassword has been verified (RawStore:301). Cf the derby.log line 1070: the stack shows we have passed the line 301 in RawStore which should check the bootPassword. It seems that a wrong bootPassword passes muster. In this case the bootPassword which appears to have been accepted is Saturday. It should have been changed by this time to derbypwd cf. call SYSCS_UTIL.SYSCS_SET_DATABASE_PROPERTY('bootPassword', 'Saturday,derbypwd'); : connect 'jdbc:derby:;shutdown=true'; <failed boot using Saturday: gets too far...?> We have done a shutdown of the engine. Could it be that the change of the encryption key wasn't committed prior to the engine shutdown, so that the persistence of the new key would need a log replay before its effective? We have seen before during the interrupt work that there are cases where checkpointing at shutdown may fail. Then, next time we try to boot, using derbypwd, it passes the bootpassword check with that (new new) boot password, so it appears that now the new encryption keys is in effect? One can still boot the database using the final bootpassword in the test, derbypwdxx.
          Hide
          Dag H. Wanvik added a comment - - edited

          But note that the above is different than what Knut analyzed: that "thursday" was also accepted: That had never been a valid password, so perhaps the error lies somehow in that a wrong bootpassword can sometimes erroneously be accepted?
          Maybe that could explain why the recovery failed, but succeeded next time we tried to boot the same database (with the correct boorpassword)?

          Show
          Dag H. Wanvik added a comment - - edited But note that the above is different than what Knut analyzed: that "thursday" was also accepted: That had never been a valid password, so perhaps the error lies somehow in that a wrong bootpassword can sometimes erroneously be accepted? Maybe that could explain why the recovery failed, but succeeded next time we tried to boot the same database (with the correct boorpassword)?
          Hide
          Dag H. Wanvik added a comment - - edited

          A possible partial theory. We validate the root password by the following algorithm:

          1) retrieve the encrypted bootpassword from system.properties

          2) decrypt if using the supplied bootpassword (JCECipherFactory#getDatabaseSecretKey:
          byte[] generatedKey = decryptKey(keyString, encodedKeyCharLength, bootPassword);
          int checkKey = digest(generatedKey);

          The digest of the generated key is used to compare against the stored digest, cf. the last integer after the dash in this line from
          service.properties:

          encryptedBootPassword=257d676070c19170-36089

          i.e. 36089 in this case. The digest method comment that says: "no matter how long the digest is, condense it into an short".

          3) compare the computed digest with the stored one, e.g. we compare one short against another short, suggestion a chance of a false
          positive of 1/65536.

          I tried to comment out the check lines:
          if (checkKey != verifyKey)
          throw StandardException.newException(errorState);

          and then I see the issue if I use a wrong boot password (effectively making a false positive every time):

          java.lang.ClassNotFoundException: ERROR XBM0U: No class was registered for identifier 41229.

          So it seems we have a 1/65536 chance of getting a false positive in this check, but what I can't see yet is where the random element comes from. Why does this fail only now and then when we use the same bootpasswords (correct and wrong)?

          Show
          Dag H. Wanvik added a comment - - edited A possible partial theory. We validate the root password by the following algorithm: 1) retrieve the encrypted bootpassword from system.properties 2) decrypt if using the supplied bootpassword (JCECipherFactory#getDatabaseSecretKey: byte[] generatedKey = decryptKey(keyString, encodedKeyCharLength, bootPassword); int checkKey = digest(generatedKey); The digest of the generated key is used to compare against the stored digest, cf. the last integer after the dash in this line from service.properties: encryptedBootPassword=257d676070c19170-36089 i.e. 36089 in this case. The digest method comment that says: "no matter how long the digest is, condense it into an short". 3) compare the computed digest with the stored one, e.g. we compare one short against another short, suggestion a chance of a false positive of 1/65536. I tried to comment out the check lines: if (checkKey != verifyKey) throw StandardException.newException(errorState); and then I see the issue if I use a wrong boot password (effectively making a false positive every time): java.lang.ClassNotFoundException: ERROR XBM0U: No class was registered for identifier 41229. So it seems we have a 1/65536 chance of getting a false positive in this check, but what I can't see yet is where the random element comes from. Why does this fail only now and then when we use the same bootpasswords (correct and wrong)?
          Hide
          Dag H. Wanvik added a comment -

          A possible answer: could it have to do with the persistence of properties of service.properties, and the way its being updated?

          Show
          Dag H. Wanvik added a comment - A possible answer: could it have to do with the persistence of properties of service.properties, and the way its being updated?
          Hide
          Dag H. Wanvik added a comment -

          At least it seems the change value is not persisted immediately, cf. PropertyConglomerate#bootPasswordChange: it just saves the new value in the property map "serviceProperties"... bug? this isn't transaactional so why not save it?

          Show
          Dag H. Wanvik added a comment - At least it seems the change value is not persisted immediately, cf. PropertyConglomerate#bootPasswordChange: it just saves the new value in the property map "serviceProperties"... bug? this isn't transaactional so why not save it?
          Hide
          Dag H. Wanvik added a comment -

          When i save the value using PropertyConglomerate#saveProperty when its beign changed, it appears in queries, which we don't want:

          values SYSCS_UTIL.SYSCS_GET_DATABASE_PROPERTY('encryptedBootPassword');
          1
          --------------------
          b15f41ee2fea07a6-61286

          so the lack of saving the value so it wont be found in a scan seems intentional..

          Show
          Dag H. Wanvik added a comment - When i save the value using PropertyConglomerate#saveProperty when its beign changed, it appears in queries, which we don't want: values SYSCS_UTIL.SYSCS_GET_DATABASE_PROPERTY('encryptedBootPassword'); 1 -------------------- b15f41ee2fea07a6-61286 so the lack of saving the value so it wont be found in a scan seems intentional..
          Hide
          Knut Anders Hatlen added a comment -

          Sounds like you're closing in on the bug.

          > So it seems we have a 1/65536 chance of getting a false positive in
          > this check, but what I can't see yet is where the random element
          > comes from.

          The digest is based on the encryption key, not on the boot password.
          The encryption key will be generated when the database is created, and
          should vary between the test runs.

          Show
          Knut Anders Hatlen added a comment - Sounds like you're closing in on the bug. > So it seems we have a 1/65536 chance of getting a false positive in > this check, but what I can't see yet is where the random element > comes from. The digest is based on the encryption key, not on the boot password. The encryption key will be generated when the database is created, and should vary between the test runs.
          Hide
          Dag H. Wanvik added a comment -

          Thanks, Knut. That was the piece missing I was missing last night Well, that accounts from the wrong boots we have seen: the check done to allow a boot attempt only relies on the two byte digest.
          The case of the wrong password change allowed ("thursday" vs "Thursday"), that is more unlikely as far as I can see: in that case, we use
          the boot password to decrypt the key, and use that to generate an initialization vector IV (8 bytes), cf the method in JCECipherFactory:

          private byte[] generateIV(byte[] secretKey)

          There is a small change of a collision here too: we transform the bogus secretKey (8 bytes) to an IV, which is compared against the exisiting one produced with the correct key (decrypted with the correct boothashword at boot time). Note we only changed one bit in the boot hashword ('T'->'t'): that might increase the likelihood that we decoded a (albeit wrong) key, but similar, for which we would get the same IV as for the correct key.
          If so, the change of boot password would succeed. Depending on the uniformity or the computation of the IV hashing, the likelihood of this would vary, but its not impossible as far as I can see.

          Show
          Dag H. Wanvik added a comment - Thanks, Knut. That was the piece missing I was missing last night Well, that accounts from the wrong boots we have seen: the check done to allow a boot attempt only relies on the two byte digest. The case of the wrong password change allowed ("thursday" vs "Thursday"), that is more unlikely as far as I can see: in that case, we use the boot password to decrypt the key, and use that to generate an initialization vector IV (8 bytes), cf the method in JCECipherFactory: private byte[] generateIV(byte[] secretKey) There is a small change of a collision here too: we transform the bogus secretKey (8 bytes) to an IV, which is compared against the exisiting one produced with the correct key (decrypted with the correct boothashword at boot time). Note we only changed one bit in the boot hashword ('T'->'t'): that might increase the likelihood that we decoded a (albeit wrong) key, but similar, for which we would get the same IV as for the correct key. If so, the change of boot password would succeed. Depending on the uniformity or the computation of the IV hashing, the likelihood of this would vary, but its not impossible as far as I can see.
          Hide
          Dag H. Wanvik added a comment -

          Got another instance of the wrong boot type, this on attempt 12700... The frequency is in deed low, so the 1/65536 chance doesn't seem to contradict observations, at least. The "wrong password change" should be much more unlikely if the above analysis is correct, I think we have seen this only once.

          Show
          Dag H. Wanvik added a comment - Got another instance of the wrong boot type, this on attempt 12700... The frequency is in deed low, so the 1/65536 chance doesn't seem to contradict observations, at least. The "wrong password change" should be much more unlikely if the above analysis is correct, I think we have seen this only once .
          Hide
          Dag H. Wanvik added a comment -

          A possible solution for the "wrong boot" issue is to rewrite this test to JUnit and just accept XBM0U, since we know it will happen sometimes.
          That leaves the "wrong password change" issue, of course.

          Show
          Dag H. Wanvik added a comment - A possible solution for the "wrong boot" issue is to rewrite this test to JUnit and just accept XBM0U, since we know it will happen sometimes. That leaves the "wrong password change" issue, of course.
          Hide
          Knut Anders Hatlen added a comment -

          It eventually failed in my environment too, after 43016 iterations:

              • Start: encryptDatabase jdk1.6.0_26 2012-02-15 23:19:53 ***
                123 del
                < ERROR XBM06: Startup failed. An encrypted database cannot be accessed without the correct boot password.
                123a123
                > ERROR XJ001: Java exception: 'ERROR XBM0U: No class was registered for identifier 25751.: java.lang.ClassNotFoundException'.
                Test Failed.
              • End: encryptDatabase jdk1.6.0_26 2012-02-15 23:19:58 ***
          Show
          Knut Anders Hatlen added a comment - It eventually failed in my environment too, after 43016 iterations: Start: encryptDatabase jdk1.6.0_26 2012-02-15 23:19:53 *** 123 del < ERROR XBM06: Startup failed. An encrypted database cannot be accessed without the correct boot password. 123a123 > ERROR XJ001: Java exception: 'ERROR XBM0U: No class was registered for identifier 25751.: java.lang.ClassNotFoundException'. Test Failed. End: encryptDatabase jdk1.6.0_26 2012-02-15 23:19:58 ***
          Hide
          Knut Anders Hatlen added a comment -

          > A possible solution for the "wrong boot" issue is to rewrite this
          > test to JUnit and just accept XBM0U, since we know it will happen
          > sometimes.

          That would silence the test, but it might alarm users if they
          occasionally get "log corrupted" errors in their logs. Even though
          they see that it boots fine the next time, they may lose confidence in
          the integrity of the database.

          > That leaves the "wrong password change" issue, of course.

          Although the chances of collisions are smaller when changing boot
          password, I suspect that if a collision occurs, it ends up corrupting
          the database, since the input to the encryption function is not the
          original secret key, so it'll save an encryption key that cannot be
          used to decrypt the db pages.

          That is, it saves

          encrypt(decrypt(encrypt(secretKey, "Thursday"), "thursday"), "derbypwd");

          which cannot be decrypted to the original secret key using any of the
          three passwords (Thursday, thursday, derbypwd).

          Maybe we could start using the full digest for verification instead of
          the condensed 16 bit digest? That should solve both issues, but we'll
          need some extra logic to handle upgrades.

          Show
          Knut Anders Hatlen added a comment - > A possible solution for the "wrong boot" issue is to rewrite this > test to JUnit and just accept XBM0U, since we know it will happen > sometimes. That would silence the test, but it might alarm users if they occasionally get "log corrupted" errors in their logs. Even though they see that it boots fine the next time, they may lose confidence in the integrity of the database. > That leaves the "wrong password change" issue, of course. Although the chances of collisions are smaller when changing boot password, I suspect that if a collision occurs, it ends up corrupting the database, since the input to the encryption function is not the original secret key, so it'll save an encryption key that cannot be used to decrypt the db pages. That is, it saves encrypt(decrypt(encrypt(secretKey, "Thursday"), "thursday"), "derbypwd"); which cannot be decrypted to the original secret key using any of the three passwords (Thursday, thursday, derbypwd). Maybe we could start using the full digest for verification instead of the condensed 16 bit digest? That should solve both issues, but we'll need some extra logic to handle upgrades.
          Hide
          Knut Anders Hatlen added a comment -

          As to the randomness of the "wrong password change" issue, I noticed that both the case noticed by John and the one noticed by Rick happened in the encryptionECB suite, which set some extra properties to specify one particular encryption algorithm. I instrumented JCECipherProvider.java and found that the IV is not used when running that test. From its constructor:

          if (cipher.getIV() == null)
          ivUsed = false;

          getIV() returns null when running store/encryptDatabase.sql under the encryptionECB suite, and ivUsed is set to false. This makes verifyIV() a no-op, and the chance of collision is 2^-32 for that case too.

          Show
          Knut Anders Hatlen added a comment - As to the randomness of the "wrong password change" issue, I noticed that both the case noticed by John and the one noticed by Rick happened in the encryptionECB suite, which set some extra properties to specify one particular encryption algorithm. I instrumented JCECipherProvider.java and found that the IV is not used when running that test. From its constructor: if (cipher.getIV() == null) ivUsed = false; getIV() returns null when running store/encryptDatabase.sql under the encryptionECB suite, and ivUsed is set to false. This makes verifyIV() a no-op, and the chance of collision is 2^-32 for that case too.
          Hide
          Dag H. Wanvik added a comment - - edited

          I have rewritten encryptDatabase.sql to JUnit and made the test ignore the "wrong boot" issue. Even though this doesn't solve the "wrong password change", it's incremental improvement. I'll make a new issue for storing the full digest to reduce the collision chance for both issues. [Update: DERBY-5622].

          Show
          Dag H. Wanvik added a comment - - edited I have rewritten encryptDatabase.sql to JUnit and made the test ignore the "wrong boot" issue. Even though this doesn't solve the "wrong password change", it's incremental improvement. I'll make a new issue for storing the full digest to reduce the collision chance for both issues. [Update: DERBY-5622] .
          Dag H. Wanvik made changes -
          Link This issue relates to DERBY-5622 [ DERBY-5622 ]
          Hide
          Dag H. Wanvik added a comment -

          Uploading derby-2687-1 (conversion to JUnit, ignoring the boot issue), running regressions.

          Show
          Dag H. Wanvik added a comment - Uploading derby-2687-1 (conversion to JUnit, ignoring the boot issue), running regressions.
          Dag H. Wanvik made changes -
          Attachment derby-2687-1.diff [ 12515060 ]
          Attachment derby-2687-1.stat [ 12515061 ]
          Dag H. Wanvik made changes -
          Issue & fix info Patch Available [ 10102 ]
          Component/s Test [ 11413 ]
          Component/s Store [ 11412 ]
          Dag H. Wanvik made changes -
          Assignee Dag H. Wanvik [ dagw ]
          Dag H. Wanvik made changes -
          Status Open [ 1 ] In Progress [ 3 ]
          Hide
          Knut Anders Hatlen added a comment -

          Looks like a good improvement, I agree. Some small suggestions:

          • The method assertFailedStatement() could be replaced by BaseJDBCTestCase.assertStatementError().
          • In the catch block of assertFailedBoot(), the search for the SQLState might be expressed more concisely as:

          boolean found = Arrays.asList(accepted).contains(e.getSQLState());

          (Or perhaps factor out in a helper method that could be used by other tests? Seems useful enough, and already implemented in RolesConferredPrivilegesTest.assertSQLState().)

          • When checking the results of a query that returns a single value, assertSingleValueResultSet() is slightly less verbose than assertFullResultSet().
          • Perhaps you could add a comment that explains the purpose of the first line in testEncryption()?
          Show
          Knut Anders Hatlen added a comment - Looks like a good improvement, I agree. Some small suggestions: The method assertFailedStatement() could be replaced by BaseJDBCTestCase.assertStatementError(). In the catch block of assertFailedBoot(), the search for the SQLState might be expressed more concisely as: boolean found = Arrays.asList(accepted).contains(e.getSQLState()); (Or perhaps factor out in a helper method that could be used by other tests? Seems useful enough, and already implemented in RolesConferredPrivilegesTest.assertSQLState().) When checking the results of a query that returns a single value, assertSingleValueResultSet() is slightly less verbose than assertFullResultSet(). Perhaps you could add a comment that explains the purpose of the first line in testEncryption()?
          Hide
          Dag H. Wanvik added a comment -

          Thanks for looking at the patch, Knut. Sounds like good improvements you suggest. I'll spin a new rev.
          Regressions passed, btw.

          Show
          Dag H. Wanvik added a comment - Thanks for looking at the patch, Knut. Sounds like good improvements you suggest. I'll spin a new rev. Regressions passed, btw.
          Hide
          Dag H. Wanvik added a comment -

          Uploading #2 of the patch, addressing Knut's comments except the last: I removed the line altogether, it's no longer needed.

          Show
          Dag H. Wanvik added a comment - Uploading #2 of the patch, addressing Knut's comments except the last: I removed the line altogether, it's no longer needed.
          Dag H. Wanvik made changes -
          Attachment derby-2687-2.diff [ 12515319 ]
          Attachment derby-2687-2.stat [ 12515320 ]
          Hide
          Knut Anders Hatlen added a comment -

          Thanks, Dag. The #2 patch looks good to me.

          One final nit. In assertFailedBoot(), the newly introduced variable "l" is never used:

          + List l = Arrays.asList(accepted);

          Show
          Knut Anders Hatlen added a comment - Thanks, Dag. The #2 patch looks good to me. One final nit. In assertFailedBoot(), the newly introduced variable "l" is never used: + List l = Arrays.asList(accepted);
          Hide
          Dag H. Wanvik added a comment -

          Committed patch #2 (and removed the superfluous line) as svn 1292084, closing.
          If/when we see the "boot password change issue" again, please note it on DERBY-5622 (it's is a store issue, not a test issue).

          Show
          Dag H. Wanvik added a comment - Committed patch #2 (and removed the superfluous line) as svn 1292084, closing. If/when we see the "boot password change issue" again, please note it on DERBY-5622 (it's is a store issue, not a test issue).
          Dag H. Wanvik made changes -
          Status In Progress [ 3 ] Resolved [ 5 ]
          Fix Version/s 10.9.0.0 [ 12316344 ]
          Resolution Fixed [ 1 ]
          Hide
          Dag H. Wanvik added a comment -

          I don't backport this now (error it's infrequent and patch contains a new test), but it could be backported to 10.8 safely, I believe. If anyone thinks it should be backported, I can do it when the new test has been running on trunk for a while and nothing untoward happens.

          Show
          Dag H. Wanvik added a comment - I don't backport this now (error it's infrequent and patch contains a new test), but it could be backported to 10.8 safely, I believe. If anyone thinks it should be backported, I can do it when the new test has been running on trunk for a while and nothing untoward happens.
          Hide
          Kathey Marsden added a comment -

          reopen and assigning to myself temporarily for backport to 10.8. I won't go any further than that as it is just a testing issue.

          Show
          Kathey Marsden added a comment - reopen and assigning to myself temporarily for backport to 10.8. I won't go any further than that as it is just a testing issue.
          Kathey Marsden made changes -
          Resolution Fixed [ 1 ]
          Status Resolved [ 5 ] Reopened [ 4 ]
          Assignee Dag H. Wanvik [ dagw ] Kathey Marsden [ kmarsden ]
          Kathey Marsden made changes -
          Labels derby_triage10_5_2 derby_backport_reject_10_5
          Hide
          Kathey Marsden added a comment -

          re-resolving after backport to 10.8. This test change/conversion could go back further if it is found to interupt runs on older versions.

          Show
          Kathey Marsden added a comment - re-resolving after backport to 10.8. This test change/conversion could go back further if it is found to interupt runs on older versions.
          Kathey Marsden made changes -
          Status Reopened [ 4 ] Resolved [ 5 ]
          Assignee Kathey Marsden [ kmarsden ] Dag H. Wanvik [ dagw ]
          Fix Version/s 10.8.2.3 [ 12318540 ]
          Resolution Fixed [ 1 ]
          Kathey Marsden made changes -
          Fix Version/s 10.8.3.0 [ 12323456 ]
          Fix Version/s 10.8.2.3 [ 12318540 ]
          Gavin made changes -
          Workflow jira [ 12404749 ] Default workflow, editable Closed status [ 12802147 ]
          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]
          Knut Anders Hatlen made changes -
          Status Resolved [ 5 ] Closed [ 6 ]

            People

            • Assignee:
              Dag H. Wanvik
              Reporter:
              John H. Embretsen
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development