Skip to content

Profiling for crypter's decryption for ALTS Channel. #6761

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
veblush opened this issue Feb 26, 2020 · 6 comments · Fixed by #7049
Closed

Profiling for crypter's decryption for ALTS Channel. #6761

veblush opened this issue Feb 26, 2020 · 6 comments · Fixed by #7049

Comments

@veblush
Copy link
Contributor

veblush commented Feb 26, 2020

Under heavy traffic using ALTS, I briefly profiled the client to see where the cpu time went through VisualVM. It seems that it spent significant time running javax.crypto.ShortBufferException.<init> ()

Hot spots (VisualVM)

io.netty.channel.epoll.Native.epollWait0[native] ()	23,995 ms (89.6%)	23,995 ms (9.4%)
org.conscrypt.NativeCrypto.EVP_AEAD_CTX_open[native] ()	994 ms (3.7%)	994 ms (0.4%)
io.netty.channel.unix.FileDescriptor.readAddress[native] ()	891 ms (3.3%)	891 ms (0.4%)
> javax.crypto.ShortBufferException.<init> ()	390 ms (1.5%)	390 ms (0.2%)
org.conscrypt.NativeCrypto.EVP_aead_aes_128_gcm[native] ()	208 ms (0.8%)	208 ms (0.1%)
io.netty.util.internal.PlatformDependent0.copyMemoryWithSafePointPolling ()	201 ms (0.8%)	201 ms (0.1%)

Callstack for javax.crypto.ShortBufferException. (VisualVM)

io.grpc.alts.internal.AltsTsiFrameProtector$Unprotector.handlePayload ()	296 ms (4.5%)	296 ms (4.5%)
 ...
  io.grpc.alts.internal.AesGcmAeadCrypter.decryptAad ()	196 ms (3%)	196 ms (3%)
   javax.crypto.Cipher.doFinal ()	196 ms (3%)	196 ms (3%)
    javax.crypto.CipherSpi.engineDoFinal ()	196 ms (3%)	196 ms (3%)
     javax.crypto.CipherSpi.bufferCrypt ()	196 ms (3%)	196 ms (3%)
      org.conscrypt.OpenSSLCipher$EVP_AEAD.engineDoFinal ()	196 ms (3%)	196 ms (3%)
       org.conscrypt.OpenSSLCipher.engineDoFinal ()	98.8 ms (1.5%)	98.8 ms (1.5%)
        javax.crypto.ShortBufferException.<init> ()	97.2 ms (1.5%)	97.2 ms (1.5%)

Not sure how much these numbers reflect reality but it seems that there is room to improve. The reason why ShortBufferException is created and thrown is to trigger the caller to allocate a bigger output buffer. (code) Once it's caught, the caller CipherSpi will create a temporary big enough buffer, decrypt the data into it by recalling the cipher, and copy it into the origianl output buffer. (code)

Since this routine is being heavily called, it'd be great to have some optimization not to have ShortBufferException and cost caused by a temporary buffering.

Environment

gRPC Java: 1.27.1
Conscrypt: 1.4.1
OpenJDK 64-Bit: 1.8.0_242

@sanjaypujare
Copy link
Contributor

Interesting. Just wondering, what optimization can gRPC do here? The interaction you described is between Conscrypt and Javax.crypto and I didn't see a way gRPC can avoid/minimize the ShortBufferException.

@veblush
Copy link
Contributor Author

veblush commented Feb 26, 2020

If there is a way for AesGcmAeadCrypter to control an output buffer, it can be done in gRPC. Actually OpenSSL and Conscrypt don't too much thing to maintain buffer. Usually they just use given buffers from callers. In this case, gRPC's AesGcmAeadCrypter.

@sanjaypujare
Copy link
Contributor

Okay, looks like it is the plaintext parameter to AesGcmAeadCrypter.decrypt() then.

@veblush
Copy link
Contributor Author

veblush commented Mar 4, 2020

With help of @ejona86, I ran a benchmark again with the change on AltsTsiFrameProtector to use directBuffer instead of heapBuffer to avoid ShortBufferException. But it turns out that it does harm more than good. This definitely removes the usage of ShortBufferException but it makes Conscrypt to copy a bigger size of output buffer when crossing the boundary of JNI.

@ejona86
Copy link
Member

ejona86 commented Mar 10, 2020

Closing, since it seems there isn't any better method for gRPC at the moment. That isn't to say there isn't an optimization that could be done here, but it seems like it will need noticeable changes to Conscrypt first

@ejona86 ejona86 closed this as completed Mar 10, 2020
@veblush
Copy link
Contributor Author

veblush commented Apr 24, 2020

Note that Java 11 addressed this problem with JDK-8178374.

ejona86 pushed a commit that referenced this issue May 20, 2020
To avoid having too many ShortBufferException thrown in ALTS code path on Java 8, we came up with this workaround creating new managed buffer, filling it, and passing it to underlying Conscrypt not to hit the code path throwing the exception. This might look to introduce another inefficiency but it's more like making it explicit because Conscrypt will do for non-managed buffer which gRPC uses.

Fix: #6761
dfawley pushed a commit to dfawley/grpc-java that referenced this issue Jan 15, 2021
To avoid having too many ShortBufferException thrown in ALTS code path on Java 8, we came up with this workaround creating new managed buffer, filling it, and passing it to underlying Conscrypt not to hit the code path throwing the exception. This might look to introduce another inefficiency but it's more like making it explicit because Conscrypt will do for non-managed buffer which gRPC uses.

Fix: grpc#6761
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Jun 4, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants