Remote Encryption Problem when the java samle is running on RedHat linux 9 and adoptium jdk17
zanisan opened this issue · 2 comments
Dear CypherTrust community,
i have a strange problem using the latest CADP_for_Java Version 8.15.0.001
we use CADP since many years running in java applications on Linux Redhat and with adopium openjdk.
We upgraded the CADP version from 8.3.1 to 8.15 and we experience extreme long response times with remote encryption but only if the java application runs on Linux Redhat.
I created a test application that is encrypting just one file (200KB) and created a standalone runnable jar.
When i start the test application on my windows 10 laptop the response times are acceptable (around 120ms in total to transfer/encrypt/receive the file) -> no problem
When i start the same test app (same application/same file/adoptium17.0.9 for linux) on our Linux Redhat 9 the response times are 28 seconds.
This latency is not due to network transfers, because if i use the same test application but the CADP verion 8.3.1 the response times go down to 300ms)
Do you have the possibility to reproduce this issue at your site? i would gladly try to reproduce it with your java sample FileEncryptionSample but i have multiple problems at runtime with your sample class so is not running on my eclipse at the moment.
I think I've been able to reproduce the issue with FileEncryptionSample.
I've noticed a randomly, ever-increasing delay to complete CryptUpdate iterations by looking at these two adjacent log lines while encrypting/decrypting large files:
$ grep -e "bufferSize confgured" -e "op=CryptUpdate" log_file.large.txt
02-12-2024 09:34:52.086 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:52.097 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:52.356 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:52.357 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:52.645 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:52.646 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:52.846 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:52.851 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:53.003 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:53.111 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:53.278 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:53.282 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:53.405 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:53.545 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:53.597 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:53.810 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:53.875 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:54.072 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:54.190 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:54.330 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:54.430 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:54.433 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:54.577 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:54.644 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:54.775 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:54.780 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:54.856 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:55.005 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:55.075 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:55.277 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:55.418 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:55.654 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:55.702 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:56.160 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:56.201 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:56.883 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:56.933 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:57.814 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:57.860 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:58.509 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:58.566 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:34:59.415 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:34:59.449 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:00.294 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:00.354 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:00.995 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:01.053 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:02.138 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:02.183 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:02.843 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:02.877 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:03.734 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:03.783 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:04.649 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:04.694 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:05.331 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:05.377 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:06.230 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:06.262 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:06.885 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:06.931 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:07.784 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 1d730606] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 09:35:09.513 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:09.516 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:09.584 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:09.589 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:09.679 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:09.683 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:09.817 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:09.825 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:09.923 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:09.934 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.003 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.016 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.046 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.051 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.109 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.112 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.158 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.162 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.210 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.215 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.276 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.284 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.347 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.381 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.546 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.566 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.705 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.713 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.872 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:10.880 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:10.933 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:11.148 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:11.185 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:11.827 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:11.849 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:12.487 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:12.529 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:13.154 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:13.188 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:13.878 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:13.946 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:14.583 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:14.633 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:15.258 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:15.285 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:15.910 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:15.951 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:16.577 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:16.621 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:17.247 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:17.284 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:17.914 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:17.933 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:18.558 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:18.580 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:19.210 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:19.230 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:19.858 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:19.879 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:20.508 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 09:35:20.555 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 09:35:21.186 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 3542162a] [-] [3] [op=CryptUpdate] [test] Success
$
Initially it takes a few milliseconds, but after a few iterations (in the example above it took 5 iterations while encrypting and 16 while decrypting) and until the task is completed it takes over 100 milliseconds, sometimes closer to 1 second.
The delay becomes noticeable only after a few dozen KBs because of the 8k buffer iteration through CryptUpdate, smaller files won't have any iteration so no delay, but if I try to encrypt/decrypt a 100k file I will consistently get several seconds of cumulated delay.
Here is how I compiled and executed the sample codes to generate the key and perform the encryption/decryption:
$ javac -cp log4j-core-2.20.0.jar:CADP_for_JAVA-8.15.0.001.jar:log4j-api-2.20.0.jar CryptoTool.java
$ java -Dcom.ingrian.security.nae.CADP_for_JAVA_Properties_Conf_Filename=CADP_for_JAVA.properties -cp '.:bcpkix-jdk15to18-1.76.jar:bcprov-jdk15to18-1.76.jar:bcutil-jdk15to18-1.76.jar:CADP_for_JAVA-8.15.0.001.jar:commons-codec-1.16.0.jar:commons-collections4-4.4.jar:commons-lang3-3.13.0.jar:cryptodatautility.jar:failureaccess-1.0.1.jar:gson-2.10.1.jar:guava-32.1.2-jre.jar:log4j-api-2.20.0.jar:log4j-core-2.20.0.jar:SafeNetVaultlessTokenization-8.10.0.000.jar' CryptoTool GENERATE -auth '|NAE|local_account|cadp4java:omissis' -key test -keysize 256 -alg AES -exportable -deletable
$ javac -cp log4j-core-2.20.0.jar:CADP_for_JAVA-8.15.0.001.jar:log4j-api-2.20.0.jar FileEncryptionSample.java
$ wget https://repo1.maven.org/maven2/com/sun/xml/bind/jaxb-impl/2.3.3/jaxb-impl-2.3.3.jar
$ wget https://repo1.maven.org/maven2/javax/xml/bind/jaxb-api/2.3.1/jaxb-api-2.3.1.jar
$ java -Dcom.ingrian.security.nae.CADP_for_JAVA_Properties_Conf_Filename=CADP_for_JAVA.properties -cp '.:bcpkix-jdk15to18-1.76.jar:bcprov-jdk15to18-1.76.jar:bcutil-jdk15to18-1.76.jar:CADP_for_JAVA-8.15.0.001.jar:commons-codec-1.16.0.jar:commons-collections4-4.4.jar:commons-lang3-3.13.0.jar:cryptodatautility.jar:failureaccess-1.0.1.jar:gson-2.10.1.jar:guava-32.1.2-jre.jar:log4j-api-2.20.0.jar:log4j-core-2.20.0.jar:SafeNetVaultlessTokenization-8.10.0.000.jar:jaxb-api-2.3.1.jar:jaxb-impl-2.3.3.jar' FileEncryptionSample '|NAE|local_account|cadp4java' 'omissis' test jaxb-api-2.3.1.jar jaxb-api-2.3.1.jar.encrypted jaxb-api-2.3.1.jar.decrypted
I have used the 128KB file jaxb-api-2.3.1.jar as an example input to encrypt/decrypt so anyone could reproduce the issue in their own lab with the same content easily.
I have successfully replicated the issue with the following combinations of versions:
OS: RHEL9 5.14.0-362.8.1.el9_3.x86_64
JVM: java-17-openjdk-17.0.9.0.9-2.el9.x86_64
CADP_for_Java: 610-000873-005_cadp_for_java_v8.15.0_180838.zip
OS: RHEL8 4.18.0-477.27.1.el8_8.x86_64
JVM: java-17-openjdk-17.0.10.0.7-2.el8.x86_64
CADP_for_Java: 610-000873-005_cadp_for_java_v8.15.0_180838.zip
OS: RHEL8 4.18.0-477.27.1.el8_8.x86_64
JVM: java-21-openjdk-21.0.2.0.13-1.rolling.el8.x86_64
CADP_for_Java: 610-000873-005_cadp_for_java_v8.15.0_180838.zip
OS: Debian12 6.1.0-18-amd64
JVM: openjdk-17-jdk-headless:amd64 17.0.10+7-1~deb12u1
CADP_for_Java: 610-000873-005_cadp_for_java_v8.15.0_180838.zip
However, I couldn't replicate the issue on Windows:
OS: WindowsServer2022 21H2 20348.1906
JVM: microsoft-jdk-17.0.10-windows-x64.msi (OpenJDK 17.0.10+7-LTS)
CADP_for_Java: 610-000873-005_cadp_for_java_v8.15.0_180838.zip
The output on Windows looks like this:
$ grep -e "bufferSize confgured" -e "op=CryptUpdate" log_file.windows.log
02-12-2024 17:06:55.082 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.082 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.113 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.113 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.144 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.144 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.160 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.175 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.191 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.191 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.207 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.207 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.222 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.222 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.238 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.238 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.238 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.238 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.253 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.253 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.269 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.269 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.269 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.269 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.285 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.285 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.300 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.300 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.316 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.316 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.332 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.332 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.332 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.332 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.347 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.347 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.363 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.363 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.363 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.363 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.378 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.378 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.378 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.378 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.394 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.394 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.394 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.410 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.410 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.410 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.425 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.425 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.425 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.425 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.442 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.442 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.442 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.442 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.457 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.457 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.457 [main] DEBUG ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.457 [main] INFO ingrian.internal.xml.XMLDbColumnIdRequest - invoke: remoteUpdate: [192.168.159.134, 4a194c39] [-] [1] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.535 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.535 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.550 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.550 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.567 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.567 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.582 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.582 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.582 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.597 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.597 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.597 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.613 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.613 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.628 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.628 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.628 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.628 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.644 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.644 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.660 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.660 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.660 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.660 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.676 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.676 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.691 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.691 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.691 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.691 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.707 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.707 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.707 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.722 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.722 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.722 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.738 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.738 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.754 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.754 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.754 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.769 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.769 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.769 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.785 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.785 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.800 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.800 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.800 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.800 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.816 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.816 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.832 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.832 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.832 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.847 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.847 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.847 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.863 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.863 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
02-12-2024 17:06:55.863 [main] DEBUG ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: bufferSize confgured to 8192
02-12-2024 17:06:55.863 [main] INFO ingrian.security.nae.CipherValidateVersionInitListener - invoke: remoteUpdate: [192.168.159.134, 11981797] [-] [3] [op=CryptUpdate] [test] Success
$
The delay for each iteration on Windows seems to be less than a millisecond, although from time to time it jumps to 15 milliseconds - but, overall, the performance is acceptable.
In my lab (all the clients and the CM running as VMs on the same laptop), any of the Linux runs will usually spend about 30 seconds doing the encryption/decryption routine while on Windows it's usually around 1 second.
I don't know enough about the library to understand the origin of the issue, but in relation to what @zanisan experienced and my own testing I'm guessing it is not a problem with the configuration (I have made no unnecessary changes, just NAE_IP.1, Protocol=ssl, Log_Level=DEBUG and Log_File) or the code (I have made no changes to FileEncryptionSample), and it only triggers on Linux, so it must be on the client side.
This performance issue seems to be with the CADP library and not this sample code. I have confirmed that there is a support ticket for this work and that it is being worked on so we will close this ticket related to the sample code in this repository as it has been determined that there is no issue there.