Derby
  1. Derby
  2. DERBY-3106

securityMechansim=8 causes slowdown on some JVMs?

    Details

    • Type: Bug Bug
    • Status: Open
    • Priority: Major Major
    • Resolution: Unresolved
    • Affects Version/s: 10.2.2.0
    • Fix Version/s: None
    • Component/s: Network Client
    • Environment:
      IBM JVM 1.42, SLES 10 or SLES 10 SP1
    • Urgency:
      Normal
    • Issue & fix info:
      Repro attached
    • Bug behavior facts:
      Performance

      Description

      1. We have a Web App that uses Derby 10.2, doing client/server. It is a Java 1.4 app
      2. We run it extensively on Windows (JDK 1.4,1.5/Tomcat 4.1/5.5), SLES 9, SLES 10, OES, and NetWare
      3. Recently I added securityMechanism=8 to the JDBC URL to at least encrypt the password (it's all local right now, but it was a nicety). Extensive testing on Windows proved flawless.
      4. Immediately after releasing to Beta testers, we heard the "UI" was slow. I traced this specifically to pages that accessed Derby Connections (or built them into a pool - there are depressing reasons why we don't do this all the time currently).
      5. The issue only occurs on SLES 10/10 SP1. It occurred for about 80% of users, and was oddly intermittent. The slowdown did NOT occur on initial login, but after they added some entries (adding some fields to some tables effectively). From then on, the slowdown was rampant and survived restarts. Even the login (which queries some DBs) was very very slow
      6. A test JSP page was created, which basically will be attached, but did nothing more than create a Connection, do a simple query, iterate the result set. Then do the same thing without the security Mechanism. Then spit out benchmark numbers.

      On my box (Windows), the numbers were typically a total of less than 10 ms for the queries. On machines exhibiting the issue, they were 80 SECONDS!

      As soon as the securityMechanism=8 was removed, the issue disappeared.

      Now, I'm not really sure I should blame Derby. My offhand gut guess is there is something wrong with the IBM JVM 1.42, doing the encrypted password and Derby took a long time to timeout and then backed down to cleartext..

      But I don't have a lot of time to test this one out. So I'm mostly posting FYI.

      (Additional: Connection logging was performed and not that interesting. Telnet to derby server was quick - it appears it is all in the client negotiating the connection that the slow down occurs).

      1. goo.java
        2 kB
        Kathey Marsden
      2. goo.jsp
        2 kB
        mike bell

        Activity

        Hide
        mike bell added a comment -

        This is a very simple very lame jsp test that

        • Connects with url including secmech=8
        • does a simple query
        • iterate resultset
        • close connection

        and then the same thing without secmech=8

        with simple benchmarking (system.gettimeinmillis) between each step

        Show
        mike bell added a comment - This is a very simple very lame jsp test that Connects with url including secmech=8 does a simple query iterate resultset close connection and then the same thing without secmech=8 with simple benchmarking (system.gettimeinmillis) between each step
        Hide
        mike bell added a comment -

        I guess I should also mention.

        The reason why I unfairly (and perhaps wrongly) think it might be the IBM JVM, is because on other platforms (and older SLES) the SUN JVM was used.

        Show
        mike bell added a comment - I guess I should also mention. The reason why I unfairly (and perhaps wrongly) think it might be the IBM JVM, is because on other platforms (and older SLES) the SUN JVM was used.
        Hide
        Kathey Marsden added a comment -

        I am attaching a java reproduction as it may be more convenient than jsp for anyone working on this issue. I also added an initial database creation and boot, so as not to skew the results.

        With IBM 1.6 SR3 I saw the following measurements:
        Time for first database boot=2219
        Time with securityMechanism 8=4890
        Time with no securityMechnism=0

        With Sun 1.6 I saw:
        Time for first database boot=2265
        Time with securityMechanism 8=625
        Time with no securityMechnism=16

        It seems especially with the IBM JVM this is still an issue. It would be interesting to throw out the first connection and loop and take an average of a dozen connections or so.

        Show
        Kathey Marsden added a comment - I am attaching a java reproduction as it may be more convenient than jsp for anyone working on this issue. I also added an initial database creation and boot, so as not to skew the results. With IBM 1.6 SR3 I saw the following measurements: Time for first database boot=2219 Time with securityMechanism 8=4890 Time with no securityMechnism=0 With Sun 1.6 I saw: Time for first database boot=2265 Time with securityMechanism 8=625 Time with no securityMechnism=16 It seems especially with the IBM JVM this is still an issue. It would be interesting to throw out the first connection and loop and take an average of a dozen connections or so.
        Hide
        Kathey Marsden added a comment -

        Triaged for 10.5.2. Set normal urgency.

        Show
        Kathey Marsden added a comment - Triaged for 10.5.2. Set normal urgency.
        Hide
        mike bell added a comment -

        Kathey thanks. I've not had time to play with this for a long time, but as I recall at the time Derby was

        a) client ser ver
        b) not connection pooled (that's been resolved of course)

        As I recall, I did run that JSP in a loop a few times, and it didn't really matter. There were many JSP pages in the product that used Derby Connections (unpooled at the time), and nearly all slowed down. The slowdown was only noticeable after the first connection/creation, and then shutdown of the webapp. From then on, it was SLOW.

        I am surprised that while you were able to dupe a noticeable slow down ( 4.9 s vs .63 s with encryptiion on IBM vs SUN), but I had at the time an ever more dramatic slowdown of 80s. Admittedly this was with IBM JVM 1.42.\

        Anyway, just sharing my memories, for FWIW for whoever might grab this one

        Show
        mike bell added a comment - Kathey thanks. I've not had time to play with this for a long time, but as I recall at the time Derby was a) client ser ver b) not connection pooled (that's been resolved of course) As I recall, I did run that JSP in a loop a few times, and it didn't really matter. There were many JSP pages in the product that used Derby Connections (unpooled at the time), and nearly all slowed down. The slowdown was only noticeable after the first connection/creation, and then shutdown of the webapp. From then on, it was SLOW. I am surprised that while you were able to dupe a noticeable slow down ( 4.9 s vs .63 s with encryptiion on IBM vs SUN), but I had at the time an ever more dramatic slowdown of 80s. Admittedly this was with IBM JVM 1.42.\ Anyway, just sharing my memories, for FWIW for whoever might grab this one
        Hide
        Knut Anders Hatlen added a comment -

        I'm seeing something similar with Java SE for Embedded 7 on ARMv7/Linux. Not sure if the cause is the same, but the symptoms look similar enough that it's worth mentioning here.

        The first few invocations of the goo repro show fairly normal numbers (similar to the ones Kathey reported):

        Time for first database boot=1941
        Time with securityMechanism 8=305
        Time with no securityMechnism=29

        But after the first few invocations, it starts getting a lot slower:

        Time for first database boot=1922
        Time with securityMechanism 8=387912
        Time with no securityMechnism=33

        Time for first database boot=1917
        Time with securityMechanism 8=525695
        Time with no securityMechnism=41

        It looks like it's the calls to java.security.SecureRandom.generateSeed() in client.am.EncryptionManager and impl.drda.DecryptionManager that block for a very long time. My guess is that the operating system's entropy source is emptied and it takes time before it is back at the level of entropy needed for it to be able to generate truly random bits.

        This problem also makes NSSecurityMechanismTest take a very long time (hours) on that platform.

        Not sure if it's worth fixing, though. We don't recommend using securityMechanism=8 anymore (because of DERBY-4468/CVE-2009-4269), and in DERBY-5651 we're even discussing if we should remove that mechanism altogether.

        Show
        Knut Anders Hatlen added a comment - I'm seeing something similar with Java SE for Embedded 7 on ARMv7/Linux. Not sure if the cause is the same, but the symptoms look similar enough that it's worth mentioning here. The first few invocations of the goo repro show fairly normal numbers (similar to the ones Kathey reported): Time for first database boot=1941 Time with securityMechanism 8=305 Time with no securityMechnism=29 But after the first few invocations, it starts getting a lot slower: Time for first database boot=1922 Time with securityMechanism 8=387912 Time with no securityMechnism=33 Time for first database boot=1917 Time with securityMechanism 8=525695 Time with no securityMechnism=41 It looks like it's the calls to java.security.SecureRandom.generateSeed() in client.am.EncryptionManager and impl.drda.DecryptionManager that block for a very long time. My guess is that the operating system's entropy source is emptied and it takes time before it is back at the level of entropy needed for it to be able to generate truly random bits. This problem also makes NSSecurityMechanismTest take a very long time (hours) on that platform. Not sure if it's worth fixing, though. We don't recommend using securityMechanism=8 anymore (because of DERBY-4468 /CVE-2009-4269), and in DERBY-5651 we're even discussing if we should remove that mechanism altogether.

          People

          • Assignee:
            Unassigned
            Reporter:
            mike bell
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:

              Development