投稿日： 2019年4月30日
最終更新日： 2023年3月28日

【SpringBoot2】UUIDを自動採番してX-Request-Idとしてlogbackのログに埋め込む方法【MDC】

YouTubeも見てね♪

ねこじゃすり

ワタオカねこじゃすりライトグレー

created by Rinker

PEPPY(ペピイ)

¥3,850 (2024/04/03 21:33:13時点 Amazon調べ-詳細)

猫を魅了する魔法の装備品！

Anker PowerCor

Anker PowerCore モバイルバッテリー 20000mAh iPhone iPad Android

created by Rinker

Anker

¥4,990 (2024/04/03 21:42:08時点 Amazon調べ-詳細)

旅行には必須の大容量モバイルバッテリー！

【最新機種】GoPro hero11 Black

【日本国内正規品】 GoPro hero11 Black

created by Rinker

GoPro(ゴープロ)

¥62,000 (2024/04/03 21:42:08時点 Amazon調べ-詳細)

最新機種でVlogの思い出を撮影しよう！

[ノースフェイス] THE NORTH FACE メンズアウターマウンテンライトジャケット

created by Rinker

THE NORTH FACE(ザノースフェイス)

¥33,430 (2024/04/03 21:42:09時点 Amazon調べ-詳細)

防水暴風で耐久性抜群なので旅行で大活躍です！

ペヤングソースやきそば 120g×18個

created by Rinker

ペヤング

¥2,600 (2024/04/03 21:42:16時点 Amazon調べ-詳細)

とりあえず保存食として買っておけば間違いなし！

レッドブルエナジードリンク 250ml×24本

created by Rinker

Red Bull(レッドブル)

¥4,000 (2024/04/03 21:42:12時点 Amazon調べ-詳細)

翼を授けよう！

Bauhutte ( バウヒュッテ ) 昇降式 L字デスクブラック BHD-670H-BK

created by Rinker

Bauhutte(バウヒュッテ)

¥14,935 (2024/04/03 21:42:10時点 Amazon調べ-詳細)

メインデスクの横に置くのにぴったりなおしゃれな可動式ラック！

1 サーバーログを漁りやすくしよう
- 1.1 リクエストを特定するIDは重要
- 1.2 MDCとは？
2 手順
3 終わりに

サーバーログを漁りやすくしよう

リクエストを特定するIDは重要

APIシステムやWebシステムを開発していると、システム障害や調査のためにログを漁ることは頻繁にあると思います。

その際に、同一リクエスト内のログを絞りこむための情報をあらかじめログのパターンに仕込んでおかないと、他のリクエストのログと混合してしまい厳密な調査が出来ません。

しかし、SpringBootとLogbackを使っていれば、ライブラリを追加する事無くMDCと言う機能を使って簡単にログに独自の値を埋め込む事が可能です。

MDCとは？

MDCとは、Mapped Diagnostic Contextsという機能の事を指し、ログ情報に対して独自の情報を付与して出力する事が可能になります。

実際には、SLF4jの機能ですが、Logback自体もSLF4jの作者が作ったライブラリなので同様の機能が搭載されています。

今回は、Filterで自動採番したUUIDをMDCとしてログパターンに埋め込む方法をご紹介致します♪

手順

Filterの準備

まずは、MDCにUUIDを追加するFilterクラスを用意しましょう。

package tech.blogenist.service.account.api.infrastructure.filter.x_request_id;

import java.io.IOException;
import java.util.UUID;

import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;

import org.slf4j.MDC;

public class MdcXRequestIdFilter implements Filter
{
    public static final String KEY = "x-request-id"; //logback内から取得する際のキー

    @Override
    public void doFilter( ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain )
            throws IOException, ServletException
    {
        UUID uuid = UUID.randomUUID();//UUIDの発行
        try
        {
            MDC.put( KEY, uuid.toString() );// MDCに追加
            filterChain.doFilter( servletRequest, servletResponse );
        }finally
        {
            MDC.remove( KEY );
        }
    }
}

package tech.blogenist.service.account.api.infrastructure.filter.x_request_id;

import java.io.IOException;

import java.util.UUID;

import javax.servlet.Filter;

import javax.servlet.FilterChain;

import javax.servlet.ServletException;

import javax.servlet.ServletRequest;

import javax.servlet.ServletResponse;

import org.slf4j.MDC;

public class MdcXRequestIdFilter implements Filter

{

public static final String KEY = "x-request-id"; //logback内から取得する際のキー

@Override

public void doFilter( ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain )

throws IOException, ServletException

{

UUID uuid = UUID.randomUUID();//UUIDの発行

try

{

MDC.put( KEY, uuid.toString() );// MDCに追加

filterChain.doFilter( servletRequest, servletResponse );

}finally

{

MDC.remove( KEY );

}

Configクラスの実装

次に、上記のクラスを@Configurationで適用させましょう。

package tech.blogenist.service.account.api.infrastructure.filter.x_request_id;

import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class XRequestIdFilterConfig
{

    @Bean
    public MdcXRequestIdFilter mdcXRequestIdFilter()
    {
        MdcXRequestIdFilter filter = new MdcXRequestIdFilter();
        return filter;
    }
}

package tech.blogenist.service.account.api.infrastructure.filter.x_request_id;

import org.springframework.context.annotation.Bean;

import org.springframework.context.annotation.Configuration;

@Configuration

public class XRequestIdFilterConfig

{

@Bean

public MdcXRequestIdFilter mdcXRequestIdFilter()

{

MdcXRequestIdFilter filter = new MdcXRequestIdFilter();

return filter;

}

logbackのパターンを修正

では、実際にlogbackのパターンにFilterクラスで追加したx-request-idを埋め込んでみましょう。

...
<!-- %X{x-request-id}を追加 -->
	<property name="FORMAT" value="[%-5level] [%X{x-request-id}] [%d{yyyy-MM-dd HH:mm:ss.SSS}] [%logger{36}] - %msg%n" />
...

...

...

確認

では、実際にサーバーを起動してリクエストを投げてみましょう。

ちなみに、FilterにてMDCを追加しているので、起動ログは以下のように空白となりますので気をつけてください。

[INFO ] [] [2019-04-30 20:11:40.848] [t.b.s.account.AccountApplication] - Started AccountApplication in 2.575 seconds (JVM running for 23.541)

リクエストを投げると以下のようなログが出力されると思います。

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.005] [o.h.q.c.internal.CriteriaQueryImpl] - Rendered criteria query -> select generatedAlias0 from CurrentAccountInfomationsTableEntity as generatedAlias0 where generatedAlias0.accountId=:param0
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.005] [org.hibernate.SQL] - select currentacc0_.account_id as account_1_2_, currentacc0_.account_infomation_id as account_4_2_, currentacc0_.created_at as created_2_2_, currentacc0_.updated_at as updated_3_2_ from account.current_account_infomations currentacc0_ where currentacc0_.account_id=?
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.010] [org.hibernate.loader.Loader] - Result set row: 0
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.010] [org.hibernate.loader.Loader] - Result row: EntityKey[tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.011] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.011] [org.hibernate.SQL] - select accountinf0_.id as id1_0_0_, accountinf0_.account_id as account_7_0_0_, accountinf0_.age as age2_0_0_, accountinf0_.created_at as created_3_0_0_, accountinf0_.display_name as display_4_0_0_, accountinf0_.name as name5_0_0_, accountinf0_.sex_type as sex_type8_0_0_, accountinf0_.updated_at as updated_6_0_0_, accountsta1_.id as id1_1_1_, accountsta1_.created_at as created_2_1_1_, accountsta1_.updated_at as updated_3_1_1_, sextypesta2_.type as type1_3_2_, sextypesta2_.name as name2_3_2_ from account.account_infomations accountinf0_ left outer join account.accounts accountsta1_ on accountinf0_.account_id=accountsta1_.id left outer join account.sex_types sextypesta2_ on accountinf0_.sex_type=sextypesta2_.type where accountinf0_.id=?
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.014] [o.h.l.p.e.p.i.ResultSetProcessorImpl] - Starting ResultSet row #0
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.014] [o.h.l.p.e.p.i.EntityReferenceInitializerImpl] - On call to EntityIdentifierReaderImpl#resolve, EntityKey was already known; should only happen on root returns with an optional identifier specified
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.015] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#component[value]{value=20002}]
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.016] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#component[value]{value=20002}]
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.016] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.AccountsTableEntity#component[value]{value=10001}]
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.016] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.AccountsTableEntity#component[value]{value=10001}]
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.017] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.SexTypesTableEntity#component[type]{type=MALE}]
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.017] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.SexTypesTableEntity#component[type]{type=MALE}]
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.017] [o.h.r.j.i.ResourceRegistryStandardImpl] - HHH000387: ResultSet's statement was not registered
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.018] [o.h.l.e.p.AbstractLoadPlanBasedEntityLoader] - Done entity load : tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#AccountInfomationIdValue(value=20002)
[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.018] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.005] [o.h.q.c.internal.CriteriaQueryImpl] - Rendered criteria query -> select generatedAlias0 from CurrentAccountInfomationsTableEntity as generatedAlias0 where generatedAlias0.accountId=:param0

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.005] [org.hibernate.SQL] - select currentacc0_.account_id as account_1_2_, currentacc0_.account_infomation_id as account_4_2_, currentacc0_.created_at as created_2_2_, currentacc0_.updated_at as updated_3_2_ from account.current_account_infomations currentacc0_ where currentacc0_.account_id=?

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.010] [org.hibernate.loader.Loader] - Result set row: 0

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.010] [org.hibernate.loader.Loader] - Result row: EntityKey[tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.011] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.011] [org.hibernate.SQL] - select accountinf0_.id as id1_0_0_, accountinf0_.account_id as account_7_0_0_, accountinf0_.age as age2_0_0_, accountinf0_.created_at as created_3_0_0_, accountinf0_.display_name as display_4_0_0_, accountinf0_.name as name5_0_0_, accountinf0_.sex_type as sex_type8_0_0_, accountinf0_.updated_at as updated_6_0_0_, accountsta1_.id as id1_1_1_, accountsta1_.created_at as created_2_1_1_, accountsta1_.updated_at as updated_3_1_1_, sextypesta2_.type as type1_3_2_, sextypesta2_.name as name2_3_2_ from account.account_infomations accountinf0_ left outer join account.accounts accountsta1_ on accountinf0_.account_id=accountsta1_.id left outer join account.sex_types sextypesta2_ on accountinf0_.sex_type=sextypesta2_.type where accountinf0_.id=?

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.014] [o.h.l.p.e.p.i.ResultSetProcessorImpl] - Starting ResultSet row #0

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.014] [o.h.l.p.e.p.i.EntityReferenceInitializerImpl] - On call to EntityIdentifierReaderImpl#resolve, EntityKey was already known; should only happen on root returns with an optional identifier specified

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.015] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#component[value]{value=20002}]

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.016] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#component[value]{value=20002}]

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.016] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.AccountsTableEntity#component[value]{value=10001}]

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.017] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.SexTypesTableEntity#component[type]{type=MALE}]

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.017] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.SexTypesTableEntity#component[type]{type=MALE}]

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.017] [o.h.r.j.i.ResourceRegistryStandardImpl] - HHH000387: ResultSet's statement was not registered

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.018] [o.h.l.e.p.AbstractLoadPlanBasedEntityLoader] - Done entity load : tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#AccountInfomationIdValue(value=20002)

[DEBUG] [f31e75fa-e295-4318-b395-8daf9dc9ed3e] [2019-04-30 20:19:34.018] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]

念のため、もう一度同じリクエストを投げてみましょう。

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.232] [o.h.q.c.internal.CriteriaQueryImpl] - Rendered criteria query -> select generatedAlias0 from CurrentAccountInfomationsTableEntity as generatedAlias0 where generatedAlias0.accountId=:param0
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.232] [org.hibernate.SQL] - select currentacc0_.account_id as account_1_2_, currentacc0_.account_infomation_id as account_4_2_, currentacc0_.created_at as created_2_2_, currentacc0_.updated_at as updated_3_2_ from account.current_account_infomations currentacc0_ where currentacc0_.account_id=?
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.235] [org.hibernate.loader.Loader] - Result set row: 0
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.235] [org.hibernate.loader.Loader] - Result row: EntityKey[tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.237] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.237] [org.hibernate.SQL] - select accountinf0_.id as id1_0_0_, accountinf0_.account_id as account_7_0_0_, accountinf0_.age as age2_0_0_, accountinf0_.created_at as created_3_0_0_, accountinf0_.display_name as display_4_0_0_, accountinf0_.name as name5_0_0_, accountinf0_.sex_type as sex_type8_0_0_, accountinf0_.updated_at as updated_6_0_0_, accountsta1_.id as id1_1_1_, accountsta1_.created_at as created_2_1_1_, accountsta1_.updated_at as updated_3_1_1_, sextypesta2_.type as type1_3_2_, sextypesta2_.name as name2_3_2_ from account.account_infomations accountinf0_ left outer join account.accounts accountsta1_ on accountinf0_.account_id=accountsta1_.id left outer join account.sex_types sextypesta2_ on accountinf0_.sex_type=sextypesta2_.type where accountinf0_.id=?
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.241] [o.h.l.p.e.p.i.ResultSetProcessorImpl] - Starting ResultSet row #0
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.242] [o.h.l.p.e.p.i.EntityReferenceInitializerImpl] - On call to EntityIdentifierReaderImpl#resolve, EntityKey was already known; should only happen on root returns with an optional identifier specified
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.242] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#component[value]{value=20002}]
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#component[value]{value=20002}]
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.AccountsTableEntity#component[value]{value=10001}]
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.AccountsTableEntity#component[value]{value=10001}]
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.SexTypesTableEntity#component[type]{type=MALE}]
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.SexTypesTableEntity#component[type]{type=MALE}]
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.r.j.i.ResourceRegistryStandardImpl] - HHH000387: ResultSet's statement was not registered
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.l.e.p.AbstractLoadPlanBasedEntityLoader] - Done entity load : tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#AccountInfomationIdValue(value=20002)
[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.232] [o.h.q.c.internal.CriteriaQueryImpl] - Rendered criteria query -> select generatedAlias0 from CurrentAccountInfomationsTableEntity as generatedAlias0 where generatedAlias0.accountId=:param0

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.232] [org.hibernate.SQL] - select currentacc0_.account_id as account_1_2_, currentacc0_.account_infomation_id as account_4_2_, currentacc0_.created_at as created_2_2_, currentacc0_.updated_at as updated_3_2_ from account.current_account_infomations currentacc0_ where currentacc0_.account_id=?

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.235] [org.hibernate.loader.Loader] - Result set row: 0

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.235] [org.hibernate.loader.Loader] - Result row: EntityKey[tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.237] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.237] [org.hibernate.SQL] - select accountinf0_.id as id1_0_0_, accountinf0_.account_id as account_7_0_0_, accountinf0_.age as age2_0_0_, accountinf0_.created_at as created_3_0_0_, accountinf0_.display_name as display_4_0_0_, accountinf0_.name as name5_0_0_, accountinf0_.sex_type as sex_type8_0_0_, accountinf0_.updated_at as updated_6_0_0_, accountsta1_.id as id1_1_1_, accountsta1_.created_at as created_2_1_1_, accountsta1_.updated_at as updated_3_1_1_, sextypesta2_.type as type1_3_2_, sextypesta2_.name as name2_3_2_ from account.account_infomations accountinf0_ left outer join account.accounts accountsta1_ on accountinf0_.account_id=accountsta1_.id left outer join account.sex_types sextypesta2_ on accountinf0_.sex_type=sextypesta2_.type where accountinf0_.id=?

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.241] [o.h.l.p.e.p.i.ResultSetProcessorImpl] - Starting ResultSet row #0

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.242] [o.h.l.p.e.p.i.EntityReferenceInitializerImpl] - On call to EntityIdentifierReaderImpl#resolve, EntityKey was already known; should only happen on root returns with an optional identifier specified

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.242] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#component[value]{value=20002}]

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#component[value]{value=20002}]

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.engine.internal.TwoPhaseLoad] - Resolving associations for [tech.blogenist.service.account.entity.db.account.AccountsTableEntity#component[value]{value=10001}]

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.r.j.i.ResourceRegistryStandardImpl] - HHH000387: ResultSet's statement was not registered

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.l.e.p.AbstractLoadPlanBasedEntityLoader] - Done entity load : tech.blogenist.service.account.entity.db.account.AccountInfomationsTableEntity#AccountInfomationIdValue(value=20002)

[DEBUG] [5b6faa3d-17e4-4401-86cc-2663f2dccc96] [2019-04-30 20:20:29.243] [o.h.engine.internal.TwoPhaseLoad] - Done materializing entity [tech.blogenist.service.account.entity.db.account.CurrentAccountInfomationsTableEntity#component[value]{value=10001}]

正しくUUIDが採番されていますね♪