去年作ったファイル転送WebアプリをGlassFish4.1とJava8に載せ替えたんだけど、
それだけで、凄ーく遅くなったの。
載せ替える前はGlassFish4だからJava7で動いてたんだよね。
あ、ハードはfit-PC2iのWindows8(32bit)で動いてるよ。
実際に測定するとこんな感じ。
サーバー | 速度 | |
Java7 | GlassFish4.0 | 26000〜28000bps |
Java8 | GlassFish4.1 | 2600〜2800bps |
うん、超遅くなった。あり得ないよね、ほんと。
わたしが作った部分がおかしいのかなーとか思って、プログラムを見たんだけど、
ファイルの書き込みくらいしか重そうな処理がなったんだよね。
ファイルIOが遅いのかなーって思って、ファイルの書き込み処理を外すとこんな感じ。
サーバー | 速度 | |
Java7 | GlassFish4.0 | 26000〜28000bps |
Java8 | GlassFish4.1 | 2600〜2800bps |
変わんないし!全く変わんないし!
ファイル転送のWebアプリだから、ファイルの書き込み取っちゃったら、何も残らないのに……。
と言うことで、JavaとGlassFishに問題がないか探すことに。
まぁ、普通に考えると、GlassFish側かな?Javaなコアなところはみんな触ってるだろうし。
とはいえまずは実測実測。パフォーマンス測定の基本は実測だよね!
GlasFish4.1はJava7でも動くはずだから計ってみた。
サーバー | 速度 | |
Java7 | GlassFish4.1 | 26000〜28000bps |
あれ……。えーっと……。遅くならない……。
Javaのコアな部分に問題があるってこと……???(゜▽、゜
もうわたしにはわからない、わからないよ。
こうなったらもうプロファイル?を見るしかないよね!
と言うことで、NetBeansのプロファイル機能を見てみる。
うん、完全にSSLの復号化のところですっごい時間かかってるね。
同じあたりをJava7とJava8で比較してみる。
Java8は結構呼び出しを展開してみたんだけど、同じ呼び出しが延々深く続いてるだけみたい。
NetBeansが重くなって最後まで開けなかったけど。
ここから分かるのは、Java7の方は、『AES』とか『CihperBlockChaining』とかが見えるんだけど、
Java8の方は、『AES』の他に、『GaloisCounterMode』とか『GHASH』とかが見える。
使われている暗号化の方式が変わってる……?
Oracleのサイトを見ると、Java7からJava8になったときにGCMって言うのが増えてるんだね。
https://docs.oracle.com/javase/jp/8/technotes/guides/security/SunProviders.html
これか!これが悪さしてるのか!新しいのに遅いなんて!
と、決めつける前に、確認確認。
Java7とJava8とで、それぞれのGlassFish4.1のセキュリティ設定を確認してみる。
たしかに、Java8の方が多くなってる〜。
これでJava8の時の暗号化方式をGCM以外から選ぶように設定ッと。
測定しなおした結果はこんな感じ。
サーバー | 速度 | |
Java8 | GlassFish4.1 | 26000〜28000bps |
速くなった!原因はGCM、これだね!
GlassFish4.1が関係ないことを確認するために、
Java8で実際に検証コードを書いてみる。
こんな感じ。大きく差が出るだろうから、適当で良いよね。
CBC
int length = 200000000;
KeyGenerator keyGenerator = KeyGenerator.getInstance("AES");
Key key = keyGenerator.generateKey();
IvParameterSpec parameters = new IvParameterSpec(new byte[16]);
Cipher CBCEncrypter = Cipher.getInstance("AES/CBC/PKCS5Padding");
CBCEncrypter.init(Cipher.ENCRYPT_MODE, key, parameters);
Cipher CBCDecrypter = Cipher.getInstance("AES/CBC/PKCS5Padding");
CBCDecrypter.init(Cipher.DECRYPT_MODE, key, parameters);
byte[] targetBytes = new byte[length];
long time0 = System.currentTimeMillis();
byte[] encryptedBytes = CBCEncrypter.doFinal(targetBytes);
long time1 = System.currentTimeMillis();
byte[] decryptedBytes = CBCDecrypter.doFinal(encryptedBytes);
long time2 = System.currentTimeMillis();
System.out.println(Arrays.equals(targetBytes, decryptedBytes));
System.out.println("暗号化時間:" + (time1 - time0) + "ミリ秒");
System.out.println("復号化時間:" + (time2 - time1) + "ミリ秒");
GCM
int length = 200000000;
KeyGenerator keyGenerator = KeyGenerator.getInstance("AES");
Key key = keyGenerator.generateKey();
GCMParameterSpec parameters = new GCMParameterSpec(128, new byte[16]);
Cipher GCMEncrypter = Cipher.getInstance("AES/GCM/PKCS5Padding");
GCMEncrypter.init(Cipher.ENCRYPT_MODE, key, parameters);
Cipher GCMDecrypter = Cipher.getInstance("AES/GCM/PKCS5Padding");
GCMDecrypter.init(Cipher.DECRYPT_MODE, key, parameters);
byte[] targetBytes = new byte[length];
long time0 = System.currentTimeMillis();
byte[] encryptedBytes = GCMEncrypter.doFinal(targetBytes);
long time1 = System.currentTimeMillis();
byte[] decryptedBytes = GCMDecrypter.doFinal(encryptedBytes);
long time2 = System.currentTimeMillis();
System.out.println(Arrays.equals(targetBytes, decryptedBytes));
System.out.println("暗号化時間:" + (time1 - time0) + "ミリ秒");
System.out.println("復号化時間:" + (time2 - time1) + "ミリ秒");
測定結果は、こんな感じ〜。
# | バイト数 | 時間(ミリ秒) | ||||||
CBC | GCM | GCM/CBC | ||||||
暗号化 | 復号化 | 暗号化 | 復号化 | 暗号化 | 復号化 | AVG | ||
1 | 100000 | 16 | 24 | 160 | 96 | 10.0 | 4.0 | 7.0 |
2 | 100000 | 16 | 24 | 160 | 96 | 10.0 | 4.0 | 7.0 |
3 | 1000000 | 64 | 88 | 1000 | 915 | 15.6 | 10.4 | 13.0 |
4 | 1000000 | 56 | 88 | 1016 | 912 | 18.1 | 10.4 | 14.3 |
5 | 10000000 | 392 | 400 | 8483 | 7852 | 21.6 | 19.6 | 20.6 |
6 | 10000000 | 376 | 368 | 7881 | 8004 | 21.0 | 21.8 | 21.4 |
7 | 100000000 | 3060 | 3351 | 53760 | 68640 | 17.6 | 20.5 | 19.0 |
8 | 100000000 | 3065 | 3325 | 74182 | 72976 | 24.2 | 21.9 | 23.1 |
9 | 100000000 | 2720 | 3142 | 61908 | 64244 | 22.8 | 20.4 | 21.6 |
10 | 200000000 | 4886 | 5103 | 110236 | 102925 | 22.6 | 20.2 | 21.4 |
11 | 200000000 | 6267 | 6223 | 125277 | 110626 | 20.0 | 17.8 | 18.9 |
12 | 200000000 | 5658 | 6211 | 124878 | 124675 | 22.1 | 20.1 | 21.1 |
うん、サイズが小さいときも遅いけど、サイズが大きくなってくるとだいたい20倍くらい遅いね!これはひどい(゜▽、゜
GCMのWikipedia見た感じだと、速くなりそうなのにね。
遅いにしても限度って言うものがあると思うんだけど……。
もしかして、去年Windowsのアプリが遅くなったのも何か関係あったりするのかな?
暗号化は、WindowsのNativeなAPI使ってるとか……?
まぁ、とりあえず直ったから良いよね(゚ー゚)(。_。)(゚-゚)(。_。)ウンウン