LoginSignup
4
3

More than 5 years have passed since last update.

JavaEEで何か作っていろいろやってみる

Posted at

使い勝手ではなく作るのが簡単な家計簿WEBアプリケーションをJavaEEで開発する。
できる限りコンテナ任せにして作って動かしてみる。
以下のようなものはいったん対象外。

  • テンプレート機能
  • 多言語対応(リソースバンドル)
  • バリデーション・コンバータ
  • CDI
  • インターセプタ

前提環境

開発

  • IDE: Eclipse 2018-12 (4.10.0) (Photon)
  • JavaEE: WebSphere Liberty
  • RDBMS: Db2 V11.1

実行環境

  • JavaEE: WebSphere Traditional Base
  • RDBMS: Db2 V11.1

環境セットアップ

Eclipse

  1. 動的Webプロジェクトを作成
  2. プロジェクトを選択し、[Alt]+[Enter]でプロパティを開く
  3. プロジェクト・ファセットでJavaServer FacesJPAを有効にする。 image.png これでweb.xmlFaces Servletサーブレットが登録され、さらに永続性プロバイダ関連のpersistence.xmlが作成される。

web.xml

Context Parameter

image.png
javax.faces.PROJECT_STAGEを定義しておく。Developmentだと画面にExceptionのスタックトレースなどが表示されるようになる。アプリケーションからもこの値を取得してLoggerのログレベルを変更したりもできる。

CommonBean.java
    public CommonBean() {
        this.logger = Logger.getLogger(this.getClass().getName());
        ConsoleHandler handler = new ConsoleHandler();
        handler.setFormatter(new SimpleFormatter());
        if (FacesContext.getCurrentInstance().getExternalContext().getInitParameter("javax.faces.PROJECT_STAGE")
                .equals("Development")) {
            handler.setLevel(Level.ALL);
            this.logger.addHandler(handler);
            this.logger.setLevel(Level.ALL);
        } else {
            handler.setLevel(Level.INFO);
            this.logger.addHandler(handler);
            this.logger.setLevel(Level.INFO);
        }
    }

ServletContextはFacesContextのstaticなメソッドから取得可能。

Login Configuration

image.png
認証方法をFORMにして、ログインページ・ログインエラーページとも/faces/index.xhtmlにする。

Security Constraint

image.png
役割名kakeibouserでのみ動作を許可する。

Security Constraint -> Web Resource Collection

image.png
リソース制限をかけるのは/faces/main配下すべて。

persistence.xml

永続性ユニット名

image.png
kakeiboというPersistence Unit名をつけた。

接続

image.png
JavaEEコンテナが提供するデータソースを使用するので、JTAデータソースにJavaEEサーバで定義したデータソースのJNDI名を指定する。

スキーマ生成

image.png
ビルド時にDBへアクセスして表のドロップや作成をしてくれるよう設定しておく。
DDL文も別途出力可能。

アプリケーションのつくり

機能

image.png
画面は3つのみ。登録画面と参照画面はログイン後にアクセス可能とする。
参照画面では、アクセスした日に属する月と年のトータル出費額と最近の明細数件を表示する。既存データの編集機能は省略。

ER図

image.png
Entityクラスを作って自動生成したものをリバースエンジニアリングしてER図化したもの。
いつどんな買い物をしたかを表すKakeiboテーブルがあり、何をいくついくらで買ったかを表すMeisaiテーブルを複数含む。

エンティティクラス(DBのテーブル相当)

家計簿エンティティ(Kakeibo)

Kakeibo.java
@Entity
@NamedQueries({
    @NamedQuery(name = CommonBean.NQ_FIND_PERIOD, query = "select k from Kakeibo k where k.userid = :username and k.timestamp between :notbefore and :notafter")
})
public class Kakeibo {
    @Id @GeneratedValue
    private Long id;
    private String userid;
    @JoinColumn()
    @OneToMany(cascade = CascadeType.ALL)
    private List<Meisai> receipts;
    @Temporal(TemporalType.DATE)
    private Date timestamp;
//accessors

クラスをテーブルにするには、@Entityを付与する。
@NamedQueriesで名前付きクエリ(@NamedQuery)を定義可能。ビジネスロジックで必要となるSQL(JPQL)を作っておく。
主キー(@Id)であるidは自動生成(@GeneratedValue)する(先にER図に示した通り、何も指定しないとSEQUENCEテーブルが作成される)。
One to Manyの関係はListのプロパティを持たせるだけ(List<Meisai> receipts)。
結合はデフォルトだとテーブル結合となるので、@JoinColumnを付与してカラム結合を指示する。
さらに@OneToMany(cascade = CascadeType.ALL)を指定し、親レコードへの操作を子へも伝搬させるよう指示する。
時刻を表すtimestampには@Temporal(TemporalType.DATE)を付与して日付であることを永続性プロバイダへ指示する。

明細エンティティ(Meisai)

Meisai.java
@Entity
public class Meisai {
    @Id @GeneratedValue
    private Long id;
    private String itemName;
    private Integer quantity;
    private BigDecimal price;
    @Transient
    private BigDecimal totalPrice;
//accessors

こちらはもっとシンプル。個数(quantity)と単価(price)から導出可能なtotalPrice@Transientを付与して、DBへは格納しない。

EJB(ビジネスロジックとDBアクセス担当)

登録EJB(TourokuEJB)

TourokuEJB.java
@Stateless
public class TourokuEJB extends CommonBean {
    @PersistenceContext(unitName = PU_NAME)
    EntityManager em;

    public void doPersist(Kakeibo kakeibo) {
        try {
            em.persist(kakeibo);
        } catch(Exception e) {
            e.printStackTrace();
        }
    }
}

たったこれだけ。@StatelessでステートレスなEJBであることを指示し、@PersistenceContextEntityManagerを注入してもらい、em.persist()KakeiboオブジェクトをDBへINSERTする。SQLは書かなくてよい。

参照EJB(DashboardEJB)

Dashboard.java
@Stateless
public class DashboardEJB extends CommonBean {
    @PersistenceContext(unitName = PU_NAME)
    private EntityManager em;
    private Query q;
    private Calendar cal;
    private Date gantan;
    private Date shonichi;
    private Date today;

    public DashboardEJB() {
        cal = GregorianCalendar.getInstance();
        cal.setTime(new Date());
        today = cal.getTime();
        int year = cal.get(GregorianCalendar.YEAR);
        int month = cal.get(GregorianCalendar.MONTH);
        int day = cal.get(GregorianCalendar.DAY_OF_MONTH);
        cal.set(year, month, day, 0, 0, 0);
        cal.set(GregorianCalendar.MILLISECOND, 0);
        cal.set(year, GregorianCalendar.JANUARY, 1);
        gantan = cal.getTime();
        cal.set(year, month, 1);
        shonichi = cal.getTime();
        if(logger.isLoggable(Level.FINE)) {
            logger.log(Level.FINE, "today: " + today);
            logger.log(Level.FINE, "gantan: " + gantan);
            logger.log(Level.FINE, "shonichi: " + shonichi);
        }
    }

    //ある期間の合計金額を算出
    public BigDecimal getTotalPayment(String username, Date notbefore, Date notafter) {
        q = em.createNamedQuery(NQ_FIND_PERIOD)
                .setParameter("username", username)
                .setParameter("notbefore", notbefore, TemporalType.DATE)
                .setParameter("notafter", notafter, TemporalType.DATE);

        List<Kakeibo> klist = (List<Kakeibo>) q.getResultList();
        if(logger.isLoggable(Level.FINE)) {
            logger.log(Level.FINE, "not before: " + q.getParameterValue("notbefore"));
            logger.log(Level.FINE, "not after: " + q.getParameterValue("notafter"));
            logger.log(Level.FINE, q.toString() + " returned " + klist.size());
        }
        BigDecimal total = new BigDecimal(0);
        for(Kakeibo k : (List<Kakeibo>) klist) {
            for(Meisai m : (List<Meisai>) k.getReceipts()) {
                total = total.add(m.getTotalPrice());
            }
        }
        if(logger.isLoggable(Level.FINE)) {
            logger.log(Level.FINE, "calculated payment: " + total);
        }
        return total;
    }
    //今年の合計金額を算出
    public BigDecimal getTotalOfThisYear(String username) {
        return getTotalPayment(username, gantan, today);
    }
    //今月の合計金額を算出
    public BigDecimal getTotalOfThisMonth(String username) {
        return getTotalPayment(username, shonichi, today);
    }
    //最近の明細を取得
    public Map<Date, List<Meisai>> getSuperMeisai(String username, int maxres) {
        String sql = "select k from Kakeibo k where k.userid = :username order by k.timestamp desc";
        q = em.createQuery(sql).setMaxResults(maxres).setParameter("username", username);
        LinkedHashMap<Date, List<Meisai>> map = new LinkedHashMap<Date, List<Meisai>>();
        for(Kakeibo k : (List<Kakeibo>) q.getResultList()) {
            map.put(k.getTimestamp(), k.getReceipts());
        }
        return map;
    }
}

コンストラクタ内でやっているのは日付の計算(1月1日や月初の日付を保存)。1セッションごとに同じ計算をするので、かなり無駄はある。
あとは、いわゆるビジネスロジックであるところの参照画面で使う今年と今月の総支出額を返すメソッドと、最近の明細を返すメソッドを定義している。
JPQLで名前付きクエリへ日付型をパラメタとして渡す場合、setParameter("paramName", date, TemporalType.DATE)のようにどの型なのかを明示する(指定しないと0件が返ってきて結構はまった)。

ここではあえてSQLの集約関数(sum)を使用せず、レコードをAPサーバ側に全部持ってきてAPサーバ側でトータルの金額を勘定する、というロジックにしている(AP側が暇そうなので)。

バッキングビーン(プレゼンテーション層とビジネスロジック層のつなぎ役)

JSFではXHTML(Facelets)とこのバッキングビーンとを合わせてプレゼンテーション層を構成し、ビジネスロジック層(EJB)とをつなぐ。サーブレットは書かない(すでに組み込まれている)。

ログイン処理(LoginBean)

LoginBean.java
@Named
@RequestScoped
public class LoginBean extends CommonBean {
    private String username;
    private String password;

    public String login() {
        //logout first
        HttpServletRequest request = getRequest();
        try {
            if(request.isUserInRole(ROLE_NAME_USER)) {
                request.logout();
            }
            request.login(username, password);
            HttpSession session = request.getSession();
            session.setAttribute(SES_ATTR_USER_NAME, request.getUserPrincipal().getName());
            if(logger.isLoggable(Level.FINE)) {
                logger.log(Level.FINE, session.getAttribute(SES_ATTR_USER_NAME) + " logged in");
            }
        }
        catch(Exception e) {
            e.printStackTrace();
            return null;
        }
        return "main/register.xhtml?faces-redirect=true";
    }

    public String logout() {
        HttpServletRequest request = getRequest();
        try {
            if(logger.isLoggable(Level.FINE)) {
                logger.log(Level.FINE, request.getUserPrincipal().getName() + " is logging out");
            }
            request.logout();
        }
        catch(Exception e) {
            e.printStackTrace();
            return null;
        }
        return "/index?faces-redirect=true";
    }
// accessors

こちらもアノテーション@Named@RequestScopedを付与するだけでコンテナマネージドなビーンとして登録され、Faceletsからバインド可能になる。
ログイン・ログアウトはHttpServletRequestlogin()/logout()メソッドを呼ぶだけ。ユーザ管理は基本的にコンテナが提供する機能でやってもらう。

登録処理(TourokuBean)

TourokuBean.java
@Named
@ViewScoped
public class TourokuBean extends CommonBean implements Serializable {
    private boolean showDetails;
    private String date;
    private List<Meisai> details;
    private String item;
    private Integer quantity;
    private BigDecimal price;
    private String username;
    @EJB
    private TourokuEJB ejb;
    public TourokuBean() {
        showDetails = false;
        details = new ArrayList<Meisai>();
        username = getSessionUser();
        if(logger.isLoggable(Level.FINE)) {
            logger.log(Level.INFO, "username: " + username);
        }
    }
    public String next() throws ParseException {
        Kakeibo k = new Kakeibo();
        k.setReceipts(details);
        k.setTimestamp(new SimpleDateFormat("yyyyMMdd").parse(date));
        k.setUserid(username);
        if(logger.isLoggable(Level.FINE)) {
            logger.log(Level.FINE, k.toString());
        }
        ejb.doPersist(k);
        return "register?faces-redirect=true";
    }

    public void makeDetail() {
        showDetails = true;
        if(logger.isLoggable(Level.FINE)) {
            logger.log(Level.FINE, "date: " + date);
        }
        Meisai meisai = new Meisai();
        meisai.setItemName(item);
        meisai.setQuantity(quantity);
        meisai.setPrice(price);
        details.add(meisai);
        if(logger.isLoggable(Level.FINE)) {
            logger.log(Level.FINE, meisai + " added");
        }
    }
// accessors

EJBの呼び出しは、@EJBでEJBインスタンスを注入してもらって使用する。Ajaxで一件ずつ送ってメモリ上に明細を確保(List<Meisai>add())するので、@ViewScopedとしSerializableを実装する。

参照処理(DashboardBean)

DashboardBean.java
@Named
@ViewScoped
public class DashboardBean extends CommonBean implements Serializable {
    private String username;
    private BigDecimal totalOfYear;
    private BigDecimal totalOfMonth;
    private LinkedHashMap<Date, List<Meisai>> recent;

    @EJB
    private DashboardEJB ejb;

    @PostConstruct
    public void init() {
        username = getSessionUser();
        if (logger.isLoggable(Level.FINE)) {
            logger.log(Level.FINE, "start processing post construction for " + username);
        }
        totalOfYear = ejb.getTotalOfThisYear(username);
        totalOfMonth = ejb.getTotalOfThisMonth(username);
        recent = (LinkedHashMap<Date, List<Meisai>>) ejb.getSuperMeisai(username, NUM_RECENT_RETRIEVE);
        if (logger.isLoggable(Level.FINE)) {
            logger.log(Level.FINE, "end of post construction for " + username);
        }
    }
// accessors

参照系画面のバッキングビーンでも同様に@EJBで注入したEJBオブジェクトを介して呼び出す。
画面アクセス時にEJB呼び出しを行うため、@PostConstructで引数なしのpublic voidinit()メソッドを定義して、EJBのビジネスメソッドを呼び出す。
コンストラクタ実行時(つまりインスタンス生成時)にはEJBオブジェクトは注入されないので、@PostConstructなタイミングでないと使えない。

画面(XHTML)

ログイン画面(index.xhtml)

image.png

index.xhtml
--- 省略 ---
                    <table class="table">
                        <h:form>
                            <tr>
                            <td><h:outputLabel for="username">ユーザID</h:outputLabel></td>
                            <td><h:inputText id="username" required="true" value="#{loginBean.username}"/></td>
                            </tr>
                            <tr>
                            <td><h:outputLabel for="password">パスワード</h:outputLabel></td>
                            <td><h:inputSecret id="password" required="true" value="#{loginBean.password}"/></td>
                            </tr>
                            <tr><td><h:commandButton  value="login" styleClass="btn btn-primary" action="#{loginBean.login()}"/></td></tr>
                        </h:form>
                    </table>
--- 省略 ---
    <h:form>
    <p class="alert">
    <h:commandButton styleClass="btn btn-danger" action="#{loginBean.logout()}" value="logoff"/>
    </p>
    </h:form>
--- 省略 ---

インプット部品は<h:outputXXX>のようなFaceletsタグで表す。このページにFaceletsサーブレット経由でアクセスすれば、HTMLにレンダリングしてクライアントへ返してくれる。サーブレットを経由しないと、ほぼそのまんま返ってくる。
ページからバッキングビーンのメソッドへはEL式(#{})でアクセスできる。値にプロパティ名を入れていても、実際にはアクセッサメソッドを介してバインドされる。

登録画面(/main/register.xhtml)

image.png

register.xhtml
        <h:form>
            <h:outputLabel for="date">日付</h:outputLabel>
            <h:inputText id="date" value="#{tourokuBean.date}" />
            <!-- ajaxで一件ずつ登録 -->
            <h:outputLabel for="item">品目</h:outputLabel>
            <h:inputText id="item" value="#{tourokuBean.item}" />
            <h:outputLabel for="quantity">個数</h:outputLabel>
            <h:inputText id="quantity" value="#{tourokuBean.quantity}" />
            <h:outputLabel for="price">単価</h:outputLabel>
            <h:inputText id="price" value="#{tourokuBean.price}" />
            <h:commandButton value="明細追加" styleClass="btn btn-primary"
                action="#{tourokuBean.makeDetail()}">
                <f:ajax execute="@all" render="meisaitable" />
            </h:commandButton>
            <h:commandButton value="登録" styleClass="btn btn-primary"
                action="#{tourokuBean.next()}" />
        </h:form>
--- 省略 ---
        <h:dataTable id="meisaitable" value="#{tourokuBean.details}" var="m"
            styleClass="table table-bordered">
            <h:column>
                <f:facet name="header">品名</f:facet>#{m.itemName}<f:facet
                    name="footer">&nbsp;</f:facet>
            </h:column>
            <h:column>
                <f:facet name="header">個数</f:facet>#{m.quantity}<f:facet
                    name="footer">&nbsp;</f:facet>
            </h:column>
            <h:column>
                <f:facet name="header">単価</f:facet>#{m.price}<f:facet name="footer">&nbsp;</f:facet>
            </h:column>
            <h:column>
                <f:facet name="header">小計</f:facet>#{m.price * m.quantity}<f:facet
                    name="footer">&nbsp;</f:facet>
            </h:column>
        </h:dataTable>
--- 省略 ---

このページは主に二つの部分からなる。
一つ目のフォームが入力用、二つ目のdataTableは入力した明細表示用となる。Ajaxで明細追加時にそこだけ更新する。
<f:ajax>execute=@allでフォーム内のデータをすべて送信し、render="meisaitable"dataTableを再描画させる。
dataTableは繰り返し対応のテーブル。valueListオブジェクトをバインドし、varで指定した名前を使ってListの要素にアクセスできる。
日付はなんと手入力である(実用を考えれば<input type="date" jsf:id="date" value="#{backingBean.date}/>のようにHTML5要素をパススルーさせるか、または、<h:inputText p:type="date" value="#{backingBean.date}"/>のように属性をパススルーさせる。)。

参照画面(dashboard.xhtml)

image.png

dashboard.xhtml
        <h2>#{dashboardBean.username}さんの家計簿サマリー</h2>
        <p class="alert alert-info">
            今年の支出は、
            <h:outputText value="#{dashboardBean.totalOfYear}" />
            円です。
        </p>
        <p class="alert alert-info">
            今月の支出は、
            <h:outputText value="#{dashboardBean.totalOfMonth}" />
            円です。
        </p>
--- 省略 ---
        <c:forEach items="#{dashboardBean.recentmap.keySet()}" var="key">
            <h3>
                <h:outputText value="#{key}" />
            </h3>
            <h:dataTable value="#{dashboardBean.recentmap.get(key)}" var="m"
                styleClass="table table-striped">
                <h:column>
                    <f:facet name="header">商品</f:facet>#{m.itemName}</h:column>
                <h:column>
                    <f:facet name="header">数量</f:facet>#{m.quantity}</h:column>
                <h:column>
                    <f:facet name="header">単価</f:facet>#{m.price}</h:column>
                <h:column>
                    <f:facet name="header">小計</f:facet>#{m.quantity * m.price}</h:column>
            </h:dataTable>
        </c:forEach>

今年と今月の総出費額を表示し、最近の明細を<c:forEach>で繰り返し表示する。繰り返しの中身はdataTableを使っている。recentmap<Date, List<Meisai>>というデータ構造になっているので、<c:forEach>を使ってMapの要素(List<Meisai>)を取得する。

動かしてみる(負荷テスト)

測定環境

こうしてできたアプリケーションを以下のような環境へデプロイし、負荷をかけてみる。
image.png
一般的なユーザを一種類定義する。このユーザは以下のような振る舞いをする。

  1. ログイン
  2. 3項目の明細からなる家計簿を2項目作って登録
  3. ダッシュボードを参照
  4. ログアウト

これを多重度を変えながら一定期間繰り返し、スループットとリソースの消費状況を確認する。

JMeterシナリオ

プロキシ設定

いちから手作業でリクエスト(サンプラー)を定義していくのは面倒なので、ブラウザで操作した内容をJMeterに記録する。これにはNon-Testエレメントの「HTTP プロキシサーバ」を使う。
スクリーンショット 2019-03-24 20.24.12.png
記録したものを登録するスレッドグループを選び、「開始」を押す。するとオレオレ証明書の情報が表示されるので次へ進む(今回はHTTPSを使わないので無視するが、HTTPSセッションもオレオレ証明書でオフロードして記録してくれる。ブラウザには相手が怪しい旨の表示が出てくる)。

ブラウザの設定とキャプチャ

FireFoxの場合は「設定」の「ネットワーク設定」でプロキシサーバを設定する(localhostでポートは8888)。
スクリーンショット 2019-03-28 22.23.14.png
あとは普通にトップ画面から操作していけば、リクエストをキャプチャしてシナリオを作ってくれる。

動的要素の編集

Faceletsを使っていると、javax.faces.ViewStateというフォーム要素が隠し項目(hidden)として追加されるので、これを後処理の正規表現で拾って後続リクエストのパラメタに入れてやる必要がある。
スクリーンショット 2019-03-24 20.23.25.png

  • 参照名:viewId(後続リクエストで参照する変数名)
  • 正規表現:name="javax.faces.ViewState".value="(.)" auto
  • テンプレート:$1$(複数の後方参照パターンがある場合の参照。たとえば2か所あって順番を逆にしたければ$2$$1$のようにする)
  • 一致番号:1(取得するパターン番号)

後続リクエストのパラメータで、javax.faces.ViewState${viewId}を指定する。
あとはチューニングパラメタである多重度(スレッド数)と時間を実行時に指定できるよう変数にしておく。

スクリーンショット 2019-03-24 20.26.13.png
変数は${__P(変数名)}のように書いておいて、実行時に-J変数名=値という風に指定する(分散テストでJMeterサーバ使用する場合は-G変数名=値)。
このケースで例えば5多重を300秒継続するには、以下のようにする。

jmeter -n -t test.jmx -JTHREAD_NUMBER=5 -JDURATION_SECOND=300 -l shot5-300.jtl -e -o ./shot5.300
  • -n: Non-GUIモード
  • -t: テスト計画ファイル(jmxファイル)を指定
  • -l: テストの結果ログ(GUI画面のリスナーから開ける)保存(空である必要あり)
  • -o: HTMLのレポート出力ディレクトリ(空である必要あり)

サーバ側取得項目

テストショットごとに以下の項目を取得しておく。

AP/DB共通

  • pidstat -d -h 1: ディスク入出力状況(プロセス単位)
  • pidstat -u -I -h 1: CPU使用状況(プロセス単位)
  • pidstat -r -h 1: メモリ使用状況(プロセス単位)
  • sar -o sar.bin 1: 各種リソース使用状況(システム全体)

その他必要に応じてvmstatiostatといったものも。

Db2

  • db2 "call monreport.dbsummary(60)": サマリ情報(指定した秒数の間で取得)
  • db2 "call monreport.pkgcache(1)": CPUをよく使ったSQLの情報(指定した分の間の情報)

その他必要に応じてsysibmadm.mon_pkg_cache_summaryで詳細なSQL情報取得等。

WAS

  • 管理コンソールからTivoli Performance Viewerを使用して適宜リソースの使用量を把握
  • GCログ

結果

image.png
横軸が多重度。やらなくてもある程度想像できることに、まったくスループットが伸びない。にもかかわらずCPU使用率は増加傾向にある。

スループット低下要因の探求

JMeterレポートから

リクエスト単位、つまりどのページのアクセスに時間がかかっているかはクライアント側でもわかる。
スクリーンショット 2019-03-31 10.44.06.png
リスナーの「統計レポート」からテスト実行時に出力した"jtl"ファイルを参照。
"resiter.xhtml"、"dashboard.xhtml"といったDBアクセスのあるページでレスポンスが悪くなり、結果としてスループットが伸びない状況がある程度うかがえる。

WASの要求メトリックから

image.png
WAS側で統計をとるには、管理コンソールから「モニターおよびチューニング」-「要求メトリック」を使う。
計測対象コンポーネントに今回使っている"EJB"、"JDBC"、"サーブレット"を有効にし、トレースレベルを「パフォーマンス・デバッグ」にしてWASを再起動する。
計測結果は「標準ログ」つまり、"SystemOut.log"に出力する。
これで再度50多重で負荷をかける。

メトリック情報はメッセージコード"PMRM0003I"を含む。CSVにするには以下のようにすればよい。

cat SystemOut*.log | perl -e '
print("parent:ver,ip,time,pid,reqid,event,current:ver,ip,time,pid,reqid,event,type,detail,etime\n");
while(<STDIN>) {
    $line = $_;
    chomp $line;
    if($line =~ m/parent:ver=(\d*),ip=(.*),time=(\d*),pid=(\d*),reqid=(\d*),event=(\d*) - current:ver=(\d*),ip=(.*),time=(\d*),pid=(\d*),reqid=(\d*),event=(\d*) type=(.*) detail=(.*) elapsed=(\d*)/) {
       print("$1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,\"$14\",$15\n");
    }
}'

image.png
表計算ソフトで開き、処理時間(etime)の降順に並べ替えれば、もうおおよその検討がついて、データの登録に時間がかかっていることがわかる。あえてAP側で処理していた年間の総支出額計算も1秒以上かかっているが、思ったほどひどくない(しかもこのテストは1ユーザだけでやっているので1年の支出が1億円近いスーパーヘビーユーザのような状態)。

DB側の情報

やはりというかDBアクセスで時間がかかっていることがよくわかったので、さらにDb2の統計情報(monreport.dbsummary()の結果)を見てみる。

monreport.dbsummary(40多重)
  Wait times                                                                      
  --------------------------------------------------------------------------------

  -- Wait time as a percentage of elapsed time --                                 

                                           %    Wait time/Total time              
                                           ---  ----------------------------------
  For requests                             53   150370/280110                     
  For activities                           23   30664/130321                      

  -- Time waiting for next client request --                                      

  CLIENT_IDLE_WAIT_TIME               = 1227123                                   
  CLIENT_IDLE_WAIT_TIME per second    = 30678                                     

  -- Detailed breakdown of TOTAL_WAIT_TIME --                                     

                                %    Total                                        
                                ---  ---------------------------------------------
  TOTAL_WAIT_TIME               100  150370                                       

  I/O wait time                                                                   
    POOL_READ_TIME              0    0                                            
    POOL_WRITE_TIME             0    0                                            
    DIRECT_READ_TIME            0    3                                            
    DIRECT_WRITE_TIME           0    1                                            
    LOG_DISK_WAIT_TIME          5    7871                                         
  LOCK_WAIT_TIME                70   105321                                       
  AGENT_WAIT_TIME               0    0                                            
  Network and FCM                                                                 
    TCPIP_SEND_WAIT_TIME        3    5796                                         
    TCPIP_RECV_WAIT_TIME        0    256                                          
    IPC_SEND_WAIT_TIME          0    1                                            
    IPC_RECV_WAIT_TIME          0    0                                            
    FCM_SEND_WAIT_TIME          0    0                                            
    FCM_RECV_WAIT_TIME          0    0                                            
  WLM_QUEUE_TIME_TOTAL          0    0                                            
  CF_WAIT_TIME                  0    0                                            
  RECLAIM_WAIT_TIME             0    0                                            
  SMP_RECLAIM_WAIT_TIME         0    0                                            

見てみるとリクエスト単位の待ち時間が53%と長い。その待ち時間の内訳がどうなっているかというと、70%がロック待ち(LOCK_WAIT_TIME)と圧倒的になっている。
初めにER図に示した通り、@Entity@Id @GeneratedValueでは、シーケンス用のテーブルを作ってその中の1レコードですべてのIDを管理しようとする(正確には@GeneratedValue(strategy = GenerationType.AUTO)がデフォルトなのでRDBMSにも依存)。
今回作った2エンティティともにこのテーブルの同一レコードを参照して値を取得するので、明細2項目を持った家計簿レコードを1件挿入するのに3つのシーケンス番号が必要になる(1人が3回ロックして番号を取得する必要がある)。
なお、バッファプールヒット率は100%達成。トランザクションログへの書き出し待ちも全体の2%程度におさまっている。

パフォーマンス改善その1

2テーブル分のシーケンスを1テーブルの1レコードで管理しているのでこれを緩和してみる。@Idを以下のように書き換える。アップデート時、つまり番号をもらうときにテーブルロックせずに行ロックしてくれれば全体としてのロック待ち時間は減らせるはず。

Kakeibo.java
    @TableGenerator(name = "KAKEIBO_SEQ", table = "SEQ_GEN")
    @Id @GeneratedValue(strategy = GenerationType.TABLE, generator = "KAKEIBO_SEQ")
    private Long id;
Meisai.java
    @TableGenerator(name = "MEISAI_SEQ", table = "SEQ_GEN")
    @Id @GeneratedValue(strategy = GenerationType.TABLE, generator = "MEISAI_SEQ")
    private Long id;

いずれも、@GeneratedValuestrategyGenerationType.TABLEを明示しつつ、generatorでシーケンス生成の名前を指定する。さらに@TableGeneratorでシーケンス生成テーブル情報を指定する。今回は1テーブルで別行管理とした。エンティティクラス以外への影響はないが、DBオブジェクトの再作成は必要になる。

同様に40多重の負荷をかけて違いを見てみる。

項目 変化
tps 251.5 810.8 322 %
CPU(AP) 65.61 66.99 102 %
CPU(DB) 62.45 39.16 63 %

スループットは約3倍になった。副作用でDBでのCPU使用率も40 %近く削減された。これだけ違えばt検定するまでもない。dbsummaryも確認する。

monreport.dbsummary
  Wait times                                                                      
  --------------------------------------------------------------------------------

  -- Wait time as a percentage of elapsed time --                                 

                                           %    Wait time/Total time              
                                           ---  ----------------------------------
  For requests                             41   58755/140777                      
  For activities                           19   16062/84530                       

  -- Time waiting for next client request --                                      

  CLIENT_IDLE_WAIT_TIME               = 1815750                                   
  CLIENT_IDLE_WAIT_TIME per second    = 45393                                     

  -- Detailed breakdown of TOTAL_WAIT_TIME --                                     

                                %    Total                                        
                                ---  ---------------------------------------------
  TOTAL_WAIT_TIME               100  58755                                        

  I/O wait time                                                                   
    POOL_READ_TIME              0    499                                          
    POOL_WRITE_TIME             0    0                                            
    DIRECT_READ_TIME            0    0                                            
    DIRECT_WRITE_TIME           0    0                                            
    LOG_DISK_WAIT_TIME          13   7800                                         
  LOCK_WAIT_TIME                66   38964                                        
  AGENT_WAIT_TIME               0    0                                            
  Network and FCM                                                                 
    TCPIP_SEND_WAIT_TIME        7    4600                                         
    TCPIP_RECV_WAIT_TIME        0    128                                          
    IPC_SEND_WAIT_TIME          0    0                                            
    IPC_RECV_WAIT_TIME          0    0                                            
    FCM_SEND_WAIT_TIME          0    0                                            
    FCM_RECV_WAIT_TIME          0    0                                            
  WLM_QUEUE_TIME_TOTAL          0    0                                            
  CF_WAIT_TIME                  0    0                                            
  RECLAIM_WAIT_TIME             0    0                                            
  SMP_RECLAIM_WAIT_TIME         0    0

待ち時間が150,370 msから58,755 msへと、60 %程度削減されたことがわかる。

パフォーマンス改善その2

いっそシーケンステーブルを使ったID管理をやめてみる。Db2はオートナンバリング機能があるのでこれを使う。

Kakeibo.java
    @Id @GeneratedValue(strategy = GenerationType.IDENTITY)
    private Long id;
Meisai.java
    @Id @GeneratedValue(strategy = GenerationType.IDENTITY)
    private Long id;

@GeneratedValue(strategy = GenerationType.IDENTITY)に変更する。DDLは以下のようになる。

createTable.sql
CREATE TABLE MEISAI (ID BIGINT GENERATED ALWAYS AS IDENTITY NOT NULL, ITEMNAME VARCHAR(255), PRICE DECIMAL(15), QUANTITY INTEGER, receipts_id BIGINT, PRIMARY KEY (ID))
CREATE TABLE KAKEIBO (ID BIGINT GENERATED ALWAYS AS IDENTITY NOT NULL, TIMESTAMP DATE, USERID VARCHAR(255), PRIMARY KEY (ID))
ALTER TABLE MEISAI ADD CONSTRAINT MEISAI_receipts_id FOREIGN KEY (receipts_id) REFERENCES KAKEIBO (ID)

同様に40多重の負荷をかけて違いを見てみると、今度は720.6 tpsと若干落ちてしまった。3回ずつ計測してt検定した結果からも、このケースではDb2の機能で自動採番するよりも、テーブル管理にしたほうがパフォーマンスはよい。

というわけで、何もかもデフォルトだとさすがにどうなるかわからないので、各アノテーションがどのような実装になるのか、使用するRDBMSの得意な管理スキーム等を意識するのが吉。

4
3
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
4
3