Blog

初心者が知っておくべきJavaの障害調査

こんにちは。テックブログ編集長の N です。

新年度が始まりましたね。

昨年度に引き続き、ココネでの技術的な取り組みやエンジニアの生活などなど発信して参りますので、どうぞよろしくお願いいたします!

 

 

今回はあるサービスで行った Java の障害対応についてのお話を紹介します。

サーバーエンジニアなら常識、とも思われるかもしれませんが、お付き合いいただければ幸いです。

 

 

概要

あるサービスで週に 1 回程度 Java プロセスが落ちる現象がありました。
原因は Out Of Memory でした。

 

java.lang.OutOfMemoryError: Java heap space

 

つまるところ、ヒープ領域の不足ですが、根本の原因がよくわかりませんでした。

調査・修正

ということで調査することにしました。

 

事前作業

あらかじめ JVM オプションに下記を追加( + 再起動)して、GC ログと OOME が発生した時のヒープダンプを出力するようにしておきます。

 

-XX:+HeapDumpOnOutOfMemoryError
-verbose:gc
-Xloggc:<path>
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps

 

GC ログを解析してみる

概要で記述したログ内の OOME によりヒープに原因があることは明白ですが、まずは GC ログを見てみることにしました。

 

https://github.com/chewiebug/GCViewer/wiki/Changelog

 

上記 URL より GCViewer 最新版 jar(今回は 1.37 )をダウンロードし、下記で起動します。

 

$ java -jar gcviewer-1.37-SNAPSHOT.jar

 

起動したら、対象の GC ログをドラッグ&ドロップ

 

 

 

OLD ヒープが右肩上がりに増えていて、FullGC が発生(黒の縦線部分)しても空きがほぼ増えておらず、最終的にメモリリークが発生していることがわかりました。

 

ヒープダンプの解析

次に、ヒープダンプを解析します。
OOME が発生した時のヒープダンプを利用しても良いですが、手動でヒープダンプを取る場合について記述します。

 

jcmd コマンドで pid を確認

(JDK 8以降)

$ jcmd
11857 sun.tools.jcmd.JCmd
1018 core.jar
ヒープダンプ生成
$ jcmd 1018 GC.heap_dump mydump.hprof
1018:
Heap dump file created

 

これで生成された内容を Memory Analyzer( https://www.eclipse.org/mat/ ) で確認します。

Memory Analyzer はメモリ使用率の高い部分をリークと推測して教えてくれるアプリケーションです。

・ 起動後、file > Open Heap Dumpから取得したダンプファイルを指定
・ 読み込み完了後のダイアログで Leak Suspects Report を選択

※ サイズが大きいヒープダンプファイルを扱う場合は、MemoryAnalyzer.ini の設定でヒープサイズを増やしておく必要があります。

 

すると、以下の状態を確認できました。

 

 

今回は PoolingHttpClientConnetcionManager が 2,640 個のインスタンスを保持していて、約 85 % の容量を占めていたことがわかりました。

 

続けて、Dominator Treeから該当のオブジェクト PoolingHttpClientConnetcionManager を検索します。

また、適当なオブジェクトを 1 つ選び、右クリック> Path to GC Roots > with all referencesを選択します。

 

 

 

 

 

今回は AWS SDK(V2)、および、Apache の HttpClient を利用している箇所に問題がありそうだと推測できます。
該当ソースを確認します。

 

ソースコードの確認

public class AWSS3Util {
    private static Logger logger = org.slf4j.LoggerFactory.getLogger(AWSS3Util.class);

    @Async
    public void putUploadToken(S3SettingCredential s3SettingCredential, String id, String token, String tokenPrefix, Date tokenExpireDate) {
        String s3Region = s3SettingCredential.getS3region();
        String s3AccessKey = s3SettingCredential.getS3accesskey();
        String s3SecretKey = s3SettingCredential.getS3secret();
        String s3BucketName = s3SettingCredential.getS3bucket();

        String stringObjKeyName = "token-store/" + tokenPrefix + "/" + token;

        try {

            AwsBasicCredentials awsCreds = AwsBasicCredentials.create(s3AccessKey, s3SecretKey);

            Region region = Region.of(s3Region);
            S3Client s3client = S3Client.builder().region(region)
                    .credentialsProvider(StaticCredentialsProvider.create(awsCreds))
                    .build();

            String content = id + ":" + new Date().getTime();
            byte[] buffer = StandardCharsets.UTF_8.encode(content).array();

            HashMap<String, String> metadata = new HashMap<>();
            metadata.put("x-amz-meta-title", "cocone-token:" + tokenExpireDate.getTime());

            PutObjectRequest request = PutObjectRequest.builder()
                    .bucket(s3BucketName)
                    .key(stringObjKeyName)
                    .contentType("plain/text")
                    .metadata(metadata)
                    .acl(ObjectCannedACL.PUBLIC_READ)
                    .build();
            s3client.putObject(request, RequestBody.fromBytes(buffer));

            logger.debug("AWSS3Util putUploadToken upload success [ID:{}], [TOKEN:{}]", id, token);

        } catch (SdkClientException e) {
            logger.error("AWSS3Util putUploadToken upload SdkClientException fail [ID:{}], [TOKEN:{}]", id, token);
            e.printStackTrace();
        } catch (Exception e) {
            logger.error("AWSS3Util putUploadToken upload Exception fail [ID:{}], [TOKEN:{}]", id, token);
            e.printStackTrace();
        }
    }
}

 

上記コード中の関数 putUploadToken は、ユーザーがログインした際に発行されたトークンを S3 にアップロードする際などに使用していました。

 

S3Client.builder() を呼び出すと、インスタンスが生成されます。

また、この putUploadToken を確認してみると、s3Client が関数中で明示的に close されていないことがわかります。

 

つまり、ユーザーがログインするたびにインスタンスが生成され、HttpClient(s3client)が close されないまま残り続け、 GC の対象にもならず、最終的には OOME を引き起こしていたということです。

もはやホラーですね。閉じましょう。

修正結果

putUploadToken の修正後のコードを示します。

finally 節を追加して close するようにしました。

 

@Async
public void putUploadToken(S3SettingCredential s3SettingCredential, String id, String token, String tokenPrefix, Date tokenExpireDate) {
    String s3Region = s3SettingCredential.getS3region();
    String s3AccessKey = s3SettingCredential.getS3accesskey();
    String s3SecretKey = s3SettingCredential.getS3secret();
    String s3BucketName = s3SettingCredential.getS3bucket();

    AwsBasicCredentials awsCreds = AwsBasicCredentials.create(s3AccessKey,s3SecretKey);
    Region region = Region.of(s3Region);

    S3Client s3client = S3Client.builder().region(region)
            .credentialsProvider(StaticCredentialsProvider.create(awsCreds))
            .build();

    String stringObjKeyName = "token-store/" + tokenPrefix + "/" + token;

    try {

        String content = id + ":" + new Date().getTime();
        byte[] buffer = StandardCharsets.UTF_8.encode(content).array();

        HashMap<String, String> metadata = new HashMap<>();
        metadata.put("x-amz-meta-title", "cocone-token:" + tokenExpireDate.getTime());

        PutObjectRequest request = PutObjectRequest.builder()
                .bucket(s3BucketName)
                .key(stringObjKeyName)
                .contentType("plain/text")
                .metadata(metadata)
                .acl(ObjectCannedACL.PUBLIC_READ)
                .build();
        s3client.putObject(request, RequestBody.fromBytes(buffer));

        logger.debug("AWSS3Util putUploadToken upload success [ID:{}], [TOKEN:{}]", id, token);

    } catch (SdkClientException e) {
        logger.error("AWSS3Util putUploadToken upload SdkClientException fail [ID:{}], [TOKEN:{}]", id, token);
        e.printStackTrace();
    } catch (Exception e) {
        logger.error("AWSS3Util putUploadToken upload Exception fail [ID:{}], [TOKEN:{}]", id, token);
        e.printStackTrace();
    } finally {
        if (s3client != null) {
            s3Client.close();
        }
    }
}

上記コード反映後の結果です。

 

 

 

※ 途中でJVM のヒープサイズに誤りがあることに気づき、4G → 2G に変更しています。

安定しました。

(新しく取得したヒープダンプでは別の箇所がメモリリークと推測されていますが、今回は取り上げません)

 

補足

https://docs.aws.amazon.com/ja_jp/sdk-for-java/latest/developer-guide/creating-clients.html

“Service clients in the SDK are thread-safe. For best performance, treat them as long-lived objects. Each client has its own connection pool resource that is released when the client is garbage collected. The clients in the AWS SDK for Java 2.0 now extend the AutoClosable interface. For best practices, explicitly close a client by calling the close method.”


今回取り上げたサービスでは、アクセスキー、シークレットキー、およびリージョンは全て同一のものを使用しています。

 

・ AWS SDKのサービスクライアントはスレッドセーフ
・ 最高のパフォーマンスを得るには、存続期間の長いオブジェクトとして処理する必要がある

 

そのため、一度 S3Client を生成したら、以降その S3Client を close せず使い回すように修正することで、よりパフォーマンスをあげることができます。

 

public class AWSS3Util {
    private static Logger logger = org.slf4j.LoggerFactory.getLogger(AWSS3Util.class);

    private static S3Client s3Client;
    private void initS3Client(S3SettingCredential s3SettingCredential) {
        String s3Region = s3SettingCredential.getS3region();
        String s3AccessKey = s3SettingCredential.getS3accesskey();
        String s3SecretKey = s3SettingCredential.getS3secret();

        AwsBasicCredentials awsCreds = AwsBasicCredentials.create(
                s3AccessKey,
                s3SecretKey);
        Region region = Region.of(s3Region);
        s3Client = S3Client.builder().region(region)
                .credentialsProvider(StaticCredentialsProvider.create(awsCreds))
                .build();
    }
    @Async
    public void putUploadToken(S3SettingCredential s3SettingCredential, String id, String token, String tokenPrefix, Date tokenExpireDate) {

        String s3BucketName = s3SettingCredential.getS3bucket();
        String stringObjKeyName = "token-store/" + tokenPrefix + "/" + token;

        try {

            String content = id + ":" + new Date().getTime();
            byte[] buffer = StandardCharsets.UTF_8.encode(content).array();

            HashMap<String, String> metadata = new HashMap<>();
            metadata.put("x-amz-meta-title", "cocone-token:" + tokenExpireDate.getTime());

            PutObjectRequest request = PutObjectRequest.builder()
                    .bucket(s3BucketName)
                    .key(stringObjKeyName)
                    .contentType("plain/text")
                    .metadata(metadata)
                    .acl(ObjectCannedACL.PUBLIC_READ)
                    .build();
            if (s3Client == null) {
                initS3Client(s3SettingCredential);
            }

            s3Client.putObject(request, RequestBody.fromBytes(buffer));

            logger.debug("AWSS3Util putUploadToken upload success [ID:{}], [TOKEN:{}]", id, token);

        } catch (SdkClientException e) {
            logger.error("AWSS3Util putUploadToken upload SdkClientException fail [ID:{}], [TOKEN:{}]", id, token);
            e.printStackTrace();
        } catch (Exception e) {
            logger.error("AWSS3Util putUploadToken upload Exception fail [ID:{}], [TOKEN:{}]", id, token);
            e.printStackTrace();
        }
    }

}

この修正の後、改めてGCログ、ヒープダンプを取得・解析したところ、1回目の修正とほぼ同等の結果を得ることができました。

 

そもそも何故このようなコードで実装されていたのか?

https://docs.aws.amazon.com/ja_jp/AmazonS3/latest/dev/UploadObjSingleOpJava.html

こちらのサンプルを流用したことで、close が行われない状態で実装されてしまったようでした(このサンプルでは明示的にクライアント が close されていません)。

 

import com.amazonaws.AmazonServiceException;
import com.amazonaws.SdkClientException;
import com.amazonaws.regions.Regions;
import com.amazonaws.services.s3.AmazonS3;
import com.amazonaws.services.s3.AmazonS3ClientBuilder;
import com.amazonaws.services.s3.model.ObjectMetadata;
import com.amazonaws.services.s3.model.PutObjectRequest;

import java.io.File;
import java.io.IOException;

public class UploadObject {

    public static void main(String[] args) throws IOException {
        Regions clientRegion = Regions.DEFAULT_REGION;
        String bucketName = "*** Bucket name ***";
        String stringObjKeyName = "*** String object key name ***";
        String fileObjKeyName = "*** File object key name ***";
        String fileName = "*** Path to file to upload ***";

        try {
            //This code expects that you have AWS credentials set up per:
            // https://docs.aws.amazon.com/sdk-for-java/v1/developer-guide/setup-credentials.html
            AmazonS3 s3Client = AmazonS3ClientBuilder.standard()
                    .withRegion(clientRegion)
                    .build();

            // Upload a text string as a new object.
            s3Client.putObject(bucketName, stringObjKeyName, "Uploaded String Object");

            // Upload a file as a new object with ContentType and title specified.
            PutObjectRequest request = new PutObjectRequest(bucketName, fileObjKeyName, new File(fileName));
            ObjectMetadata metadata = new ObjectMetadata();
            metadata.setContentType("plain/text");
            metadata.addUserMetadata("title", "someTitle");
            request.setMetadata(metadata);
            s3Client.putObject(request);
        } catch (AmazonServiceException e) {
            // The call was transmitted successfully, but Amazon S3 couldn't process 
            // it, so it returned an error response.
            e.printStackTrace();
        } catch (SdkClientException e) {
            // Amazon S3 couldn't be contacted for a response, or the client
            // couldn't parse the response from Amazon S3.
            e.printStackTrace();
        }
    }
}

 

最後に

今回は Java 初心者が知っておくべき障害調査の手段のうちの 1 つとその原因について示しました。

 

悩むよりもまずは GC ログの確認とヒープダンプの解析を、特にヒープダンプは悩むより気軽に取れ(ただし容量には気をつけて)、developer guideがあればよく読みましょう(サンプルだけを鵜呑みにして実装しない)、ということで。

この記事が Java サーバー開発初心者の方への助けになればと思います。

 

Popular posts

Category

Tag

Category

Tag

%d人のブロガーが「いいね」をつけました。