BCrypt very slow in app engine application

Go To StackoverFlow.com

4

I'm developing a GWT/app engine application, using Eclipse. The below problem occurred after upgrading to app engine 1.6.4 from 1.6.3. After the upgrade, I my application would not work at all. Unfortunately, I had deleted my old app engine plugins, so I was unable to rollback to 1.6.3. After 2 hours of banging my head against the wall, I decided to recreate my Eclipse project. The project worked again, except for the following anomaly:

I'm using BCrypt to implement one-way hash encoding of passwords. Before yesterday, this worked fine, with password encodes and checks occurring very fast -- probably in a few milliseconds. Now these operations take on the order of 2 minutes! Using the debugger, I paused the application to see if I could figure out what was going on. Each time I pause, I get a stack trace such as the following:

    Thread [798744730@qtp-2080190228-3] (Suspended) 
    Class<T>.forName0(String, boolean, ClassLoader) line: not available [native method] 
    Class<T>.forName(String) line: 186  
    RuntimeHelper.checkRestricted(boolean, String, String, String) line: 63 
    Runtime.checkRestricted(boolean, String, String, String) line: 63   
    BCrypt.encipher(int[], int) line: 496   
    BCrypt.key(byte[]) line: 558    
    BCrypt.crypt_raw(byte[], byte[], int) line: 622 
    BCrypt.hashpw(String, String) line: 681 
    BCrypt.checkpw(String, String) line: 749

BCrypt.encipher() is as follows: (line 496 is shown below in a line comment)

private final void encipher(int lr[], int off) {
    int i, n, l = lr[off], r = lr[off + 1];

    l ^= P[0];
    for (i = 0; i <= BLOWFISH_NUM_ROUNDS - 2;) {
        // Feistel substitution on left word
        n = S[(l >> 24) & 0xff];
        n += S[0x100 | ((l >> 16) & 0xff)];
        n ^= S[0x200 | ((l >> 8) & 0xff)];
        n += S[0x300 | (l & 0xff)];
        r ^= n ^ P[++i];  //*** LINE 496 *****

        // Feistel substitution on right word
        n = S[(r >> 24) & 0xff];
        n += S[0x100 | ((r >> 16) & 0xff)];
        n ^= S[0x200 | ((r >> 8) & 0xff)];
        n += S[0x300 | (r & 0xff)];
        l ^= n ^ P[++i];
    }
    lr[off] = r ^ P[BLOWFISH_NUM_ROUNDS + 1];
    lr[off + 1] = l;
}

Depending on when I pause the debugger, different lines in BCrypt are the caller to Runtime.checkRestricted(), but it appears that Runtime.checkRestricted() is called continuously. Since this is called in embedded loops, I'm thinking that this is the cause. I then went on a hunt as to how to avoid this checkRestricted() call from happening. No luck.

I have a somewhat complicated application structure that contains three Google web applications (Eclipse projects). I'll call them:

Base

Store

App

where Store depends upon Base, and App depends upon both Store and Base. I use an Ant task to build the Base and Store projects into JAR files and copy them to the App/war/WEB-INF/lib folder.

Originally, I had BCrypt in its own Eclipse project and my ANT task would also JAR this and copy it to App/war/WEB-INF/lib. This was working fine for the past few months until now. To try to work around the current problem, I tried moving the BCrypt class (it contains only 1 class) directly into the Base project, with the same result, then into the Store project, again with the same result. Since my app currently calls BCrypt methods only from the Store project, I figured either of this might work. They did, functionally, but still taking 2 minutes to complete an encipher() call.

From the stack trace, Runtime or RuntimeHelper return Source Not Found when I click on them, and I can find nothing about them in Google searches.

Questions:

Why is every line in BCrypt subjected to a checkRestricted() call? This doesn't seem normal.

More importantly, any idea on how to fix this problem?

I don't know what to look at next. Any ideas would be very welcome, even if you don't know the ultimate solution.

Thanks very much.

Rick

2012-04-03 20:18
by ptflix
I decided to try a fresh install with a new Google web app. I get the same problem. I think there may be a problem with either GWT 2.4.0 or app engine 1.6.4. Downloaded and installed the newest Eclipse Indigo. Setup Google Software site and installed the Google Eclipse plugin, GWT 2.4.0, and app engine 1.6.4. Created a new Google web application, copied the BCrypt.java file into my server folder. Made a call from the demo app's GreetingServiceImpl.greetServer() GWT RPC method to BCrypt.hashpw("adminadmin", BCrypt.gensalt()); This method call took 1-2 minutes to complete - ptflix 2012-04-03 22:37
Same problem here. App Engine 1.6.4 freezes Bcrypt. Any help appreciate - Florian 2012-04-04 08:29
"Hey guys, bcrypt is slow." That's the point...ta.speot.is 2012-04-04 09:19
Is this in the devappserver? Does it occur in production? My hunch is that the devappserver gained additional checks to emulate the production infrastructure; dev_appserver's emphasis is on correctness over performance - Nick Johnson 2012-04-05 06:15


2

I just created a ticket at the GAE code project: http://code.google.com/p/googleappengine/issues/detail?id=7277&thanks=7277&ts=1333530915

Maybe, we get an answer there as using BCrypt is also provided by an official tutorial: http://code.google.com/p/google-web-toolkit-incubator/wiki/LoginSecurityFAQ

Google fixed the bug and released a new version (1.6.4.1) today: http://code.google.com/p/googleappengine/downloads/detail?name=appengine-java-sdk-1.6.4.1.zip

2012-04-04 09:16
by Florian
I've done some more testing. It appears that BCrypt makes a lot of method calls within the call to BCrypt.hashpw(). Each method call results in a call to RuntimeHelper.checkRestricted(). Since I stupidly deleted my app engine 1.6.3 plugin, can someone else try this with 1.6.3 to see if this really did get broken with 1.6.4? I suspect that it has, since I had no performance problem prior to 1.6.4. Or perhaps it was gwt 2.4.0 that did it? I didn't notice if gwt upgraded at the same time, but I also deleted my older gwt plugins from Eclipse. Well, I won't do that again - ptflix 2012-04-04 13:44
Well, well. I found a copy of eclipse in my backups that had app engine 1.6.3. Tried it and as I thought -- it works. So 1.6.4 has a serious bug. Hopefully, Google will respond to the bug report posted by florian. http://code.google.com/p/googleappengine/issues/detail?can=2&start=0&num=100&q=&colspec=ID%20Type%20Component%20Status%20Stars%20Summary%20Language%20Priority%20Owner%20Log&groupby=&sort=&id=727 - ptflix 2012-04-05 03:37


0

Yes. There is a regression in 1.6.4

See Is google app engine 1.6.4 slower in local? Comments there by Googlers working on the GAE SDK.

2012-04-05 07:45
by timbo
Ads