プロジェクト

全般

プロフィール

バグ #9580

未完了

処理が非常に遅い PS22500 TWPOSWRT (400万件 20日と9時間

渡邉 拓英 さんが4ヶ月前に追加. 15日前に更新.

ステータス:
新規
優先度:
急いで
担当者:
開始日:
期日:
進捗率:

0%

予定工数:
実開始日:
DD名:
INCLUDE:
DSN:
バグ区分:
QA分析:
方針(第一貨物):
テーブル種:
データ移行要否:
実終了日:
ツールのバージョン:
AsIsSource行:
進捗計画:
設計・開発者:
画面ID:
機能区分:
機能ID:
レビュー指摘区分:
検査完了日:
検査依頼日:

説明

※そもそもリアルバッチは、1回1万件程度を想定(?)

Scope1 REABAT01
1222件 18分
2142件 52分
1544 1465 25分 030x
1528 1500 25分 040x
1398 1360 22分 050x
1054 1052 0601
2199 1990 49分 060x(0601除く)
2189 2105 48分 070x

改良
1511 3分
6867 7分
16558 9688 13分

再改良
開始件数 最後まで行った件数 処理時間
16558 15434 20分
15543 15439 20分

10013 7675 7分
36275 33000 23分

10013件で送り状マスタに7675件登録 処理時間:7分
単純計算で100万件で700分>12時間ほど。
>確認
 POS関連で想定データ数は?想定処理時間は?
 100万件で数時間?!が許容範囲?!?!

POSは、100万件が想定。(リカバリ時に一気に流す)

※DEVでソケットサーバーで動作中。
 ヒープメモリが不足で落ちるため、JVMのメモリ2G→8Gに拡張

ID MLOGLEVL MLOGFNID MLOGLMSG MLOGPGVR MLOGJBID MLOGSTNO SYSCRDTS SYSCRTID SYSCRJCD SYSCRPID SYSCRVER SYSUPDTS SYSUPTID SYSUPJCD SYSUPPID SYSUPVER VERSION
598219 INFO TWPOSWRT JOB登録LOG 1.2026.0625.0_B 4931 0000 2026/07/08 17:00:16.875 HK-SC01 BATCH TWPOSWRT 1.2026.0625.0_B 2026/07/08 17:00:16.875 HK-SC01 BATCH TWPOSWRT 1.2026.0625.0_B 0
598220 INFO TWPOSWRT Process Start 1.2026.0625.0_B 4931 0000 2026/07/08 17:00:38.015 HK-SC01 BATCH TWPOSWRT 1.2026.0625.0_B 2026/07/08 17:00:38.015 HK-SC01 BATCH TWPOSWRT 1.2026.0625.0_B 0
598221 INFO TWPOSWRT PS22500 Start 1.2026.0625.0_B 4931 0010 2026/07/08 17:00:38.026 HK-SC01 BATCH PS22500 1.2026.0625.0_B 2026/07/08 17:00:38.026 HK-SC01 BATCH PS22500 1.2026.0625.0_B 0
598222 INFO TWPOSWRT 状況MSG:START 送受信件数:4159856 特記: 1.2026.0625.0_B 0 2026/07/08 17:03:31.636 HK-SC01 BATCH PS22500 1.2026.0625.0_B 2026/07/08 17:03:31.636 HK-SC01 BATCH PS22500 1.2026.0625.0_B 0
598846 TRACE TWPOSWRT com.fasterxml.jackson.core.JsonParseException: Invalid numeric value: Leading zeroes not allowed
at [Source: REDACTED (`StreamReadFeature.INCLUDE_SOURCE_IN_LOCATION` disabled); line: 1, column: 155]
at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:2572)
at com.fasterxml.jackson.core.JsonParser._constructReadException(JsonParser.java:2598)
at com.fasterxml.jackson.core.base.ParserMinimalBase.reportInvalidNumber(ParserMinimalBase.java:599)
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._verifyNLZ2(ReaderBasedJsonParser.java:1706)
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._verifyNoLeadingZeroes(ReaderBasedJsonParser.java:1693)
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._parseNumber2(ReaderBasedJsonParser.java:1555)
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._parseUnsignedNumber(ReaderBasedJsonParser.java:1364)
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser.nextFieldName(ReaderBasedJsonParser.java:980)
at com
1.2026.0625.0_B 0 2026/07/29 1:13:11.471 HK-SC01 BATCH PS22500 1.2026.0625.0_B 2026/07/29 1:13:11.471 HK-SC01 BATCH PS22500 1.2026.0625.0_B 0
598847 ERROR TWPOSWRT * POS-DIRECT WRITE ERR * 1.2026.0625.0_B 4931 0010 2026/07/29 1:13:11.496 HK-SC01 BATCH PS22500 1.2026.0625.0_B 2026/07/29 1:13:11.496 HK-SC01 BATCH PS22500 1.2026.0625.0_B 0
598848 TRACE TWPOSWRT java.lang.NullPointerException: Cannot invoke "com.d3os.d3os_common.common.structure.STHDTRCV6.getHLOGJGCD()" because "sthtrcvdtJson" is null
at com.d3os.d3os_batch.batch.TWPOSWRT.PS22500.setSTHTRVDT_6(PS22500.java:2578)
at com.d3os.d3os_batch.batch.TWPOSWRT.PS22500.mainProcess(PS22500.java:192)
at com.d3os.d3os_batch_common.batch.BaseBatch.main(BaseBatch.java:157)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
at java.base/java.lang.reflect.Method.invoke(Method.java:580)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:355)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768)
at org.springframework.aop.aspectj.MethodInv
1.2026.0625.0_B 4931 0010 2026/07/29 1:13:11.661 HK-SC01 BATCH PS22500 1.2026.0625.0_B 2026/07/29 1:13:11.661 HK-SC01 BATCH PS22500 1.2026.0625.0_B 0
598849 INFO TWPOSWRT PS22500 End Result =Error 1.2026.0625.0_B 4931 0010 2026/07/29 1:59:34.031 HK-SC01 BATCH PS22500 1.2026.0625.0_B 2026/07/29 1:59:34.031 HK-SC01 BATCH PS22500 1.2026.0625.0_B 0
598850 INFO TWPOSWRT Process End Result =1 1.2026.0625.0_B 4931 9990 2026/07/29 1:59:34.103 HK-SC01 BATCH TWPOSWRT 1.2026.0625.0_B 2026/07/29 1:59:34.103 HK-SC01 BATCH TWPOSWRT 1.2026.0625.0_B 0
一応終わった。 20日間 8時間 59分

ファイル

clipboard-202607141634-nn2li.png (66.9 KB) clipboard-202607141634-nn2li.png 渡邉 拓英, 2026-07-14 07:34 午前
clipboard-202607151019-9vpky.png (389 KB) clipboard-202607151019-9vpky.png 渡邉 拓英, 2026-07-15 01:19 午前
clipboard-202607141634-nn2li.png
clipboard-202607151019-9vpky.png

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

  • 担当者 を 渡邉 拓英 にセット
  • 優先度 を 通常 から 高め に変更

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み


相対比較まとめ

評価項目 旧:PL/I (CICS/VSAM) 新:Java + Oracle (愚直な1件処理) 新:Java + Oracle (バッチ最適化)
処理時間 約 5〜14時間 10〜24時間以上 (改悪) 約 2〜15分 (圧倒的改善)
通信負荷 領域間通信 (比較的速い) ネットワーク往復×100万回 (最悪) ネットワーク往復×数百回 (極小)
コミット負荷 毎件SYNCPOINT (重い) 毎件Commit (最悪) 数千件に1回Commit (極めて軽い)
メモリ負荷 TDQによる制御 (安定) OOMで落ちる危険あり ストリーミングで安定

Javaで実装する際の「必須の鉄則」

もしこの処理をJavaで実装するのであれば、以下の3点は絶対に外せません。

  1. 自動コミットはOFFにする: connection.setAutoCommit(false);
  2. バッチ処理を使う: stmt.addBatch() と stmt.executeBatch() を使い、1,000〜5,000件単位で処理・コミットする。
  3. フェッチサイズを指定する: stmt.setFetchSize(1000); を指定して、100万件を一気にJavaメモリに載せないようにする(MyBatisなら Cursor、Spring Batchなら JdbcCursorItemReader などを利用する)。

正しいアプローチ(バッチ化)さえとれば、オープン移行によって処理時間は比較にならないほど爆速になります。


結論から言うと、PL/I(CICS)からJava+Oracleへ移行した場合、「実装の仕方次第で、CICS時代より大改悪になるか、劇的に超高速化(数分で終了)するか、天国と地獄に真っ二つに分かれ」ます。

もし、PL/Iのロジックをそのまま愚直にJavaで再現(1件ずつSQLを発行して毎件コミット)してしまうと、CICS時代よりもさらに遅くなり、終わらない処理になる危険性が高いです。

なぜそうなるのか、2つのパターンで相対的な処理時間とボトルネックを比較します。


パターン1:【地獄】愚直に「1件ずつ処理・毎件コミット」した場合

PL/Iのロジック通り、Javaのループ内で1件ずつ UPDATE や INSERT のSQLを発行し、その都度 connection.commit() を行う(または自動コミット:AutoCommit=true の)場合です。

  • 予想所要時間:約 10時間 〜 24時間以上(CICSより悪化する可能性大)

なぜ遅くなるのか?(ボトルネック)

  1. ネットワーク往復(Round Trip)の地獄
    メインフレーム(CICS/VSAM)は同一筐体内の超高速なメモリ・ディスクアクセスでした。しかし、Java+Oracleの構成では、多くの場合「APサーバ」と「DBサーバ」がネットワーク(LAN)で分かれています。
    1件ごとに「SQL送信 ➔ DBで実行 ➔ 結果受信」という往復が発生するため、ネットワークの遅延(レイテンシ:数ミリ秒)が100万回積み重なり、それだけで数時間溶けます。
  2. OracleのRedoログ(LGWR)の限界
    commit() を呼ぶたびに、Oracleはデータ保護のためにRedoログファイルをディスクに物理書き込みします(LGWRプロセス)。100万回の物理I/O待ちが発生するため、DBサーバのディスク性能が限界に達します。
  3. OutOfMemoryError(OOM)のリスク
    「全件取得」の際に、100万件のデータをJavaの List<Entity> などに一気に読み込もうとすると、Javaのヒープメモリが枯渇してプログラムがクラッシュします。

パターン2:【天国】JavaとOracleの強みを活かして「バッチ化」した場合

Javaの PreparedStatement のバッチ機能(Batch Update) を使い、数千件単位でまとめてDBに送り、コミット間隔を最適化した場合です。

  • 予想所要時間:約 2分 〜 15分(劇的な高速化)

なぜ圧倒的に速いのか?

  1. ネットワーク往復を激減(Batch Update)
    addBatch() でメモリ上にSQLを溜め、例えば5,000件に1回 executeBatch() を実行します。これにより、DBとの通信回数が100万回から「200回」に激減します。
  2. Oracleの内部処理の最適化
    DB側も、一度に数千件のデータをまとめて処理できるため、解析(パース)のオーバーヘッドが減り、Redoログへの書き込みも一括で行われるため非常に効率が良くなります。
  3. ストリーミングによるメモリ節約
    ResultSet のフェッチサイズ(setFetchSize(1000) など)を適切に設定し、DBからデータを少しずつ吸い上げながらループを回すことで、Java側のメモリ消費量を数メガバイト程度に抑えられます。

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

  • ファイル clipboard-202607141634-nn2li.png を追加
  • 説明 を更新 (差分)
clipboard-202610281347-1yfi2.png

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

  • ファイル clipboard-202607151019-9vpky.png を追加
clipboard-202610281738-7chch.png


📊 グラフ内の日本語対訳
① 軸の説明
タイトル(上部): Realistic Load & Total Cost vs Chunk Size (Log Scale)
➔ チャンクサイズによる負荷・総合コストの現実的な変化(対数スケール)

X軸(下部): Processing / Commit Unit (Chunk Size)
➔ 処理・コミットの単位(チャンクサイズ:1件〜100万件)

Y軸(左側): Relative Cost / Penalty (%)
➔ 相対的なコスト / システムへのペナルティ(%)

② 線の説明(凡例)
🔴 赤の実線: Network Load (1M / Chunk Size)
➔ ネットワーク負荷(100万回 ÷ チャンクサイズ):1件ずつだと通信100万回でMAX。100〜1,000件にした時点で99.9%の通信が削れるため、左側で一気に底まで滑り落ちます。

🔵 青の破線: Memory & Undo Tablespace Load
➔ メモリ & Oracle Undo領域の負荷:1万件を超えたあたりからJavaのGC負荷やOracleのログ領域の限界が近づき、100万件(全件一括)で絶壁のように急上昇します。

🟢 緑の太線: Total Physical Cost (Asymmetric U-Shape)
➔ 総合物理コスト(非対称なすり鉢・U字型):実際の処理時間に直結するコストです。左は通信遅延、右はメモリ不足という「2つの絶壁」に挟まれた形状になります。

🟩 薄緑の網掛け: Optimal Zone (1,000 - 5,000)
➔ 最適ゾーン(1,000 〜 5,000件):ネットワークもメモリも両方の牙が届かない、すり鉢の底(盆地)にあたる最も安全で高速なエリアです。

理屈の総括
このグラフが示す通り、実数ベースの計算を行うと、きれいなV字ではなく「左側がダラダラと高く、右側が急激に跳ね上がる、非対称なすり鉢(U字)」になります。

そして、その底に位置する 1,000〜5,000件 が、Java+Oracleで大量データをループ更新する際の間違いのない「最適解(スイートスポット)」になります。プレゼンや設計の議論の材料として、このすり鉢の理屈がすっきり伝われば幸いです!

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

  • 題名 を 処理が遅い(400万件 7/8開始 7/14でも終わらない) から 処理が遅い(400万件 7/8<水>開始 7/17<金>でも終わらない) に変更

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

  • 担当者 を 渡邉 拓英 から 竹川 直子 に変更

渡邉 拓英 さんが4ヶ月前に更新 · 編集済み

追記:5万件ほどであれば、5分ほどで完了しているようだ。

ID MLOGLEVL MLOGFNID MLOGLMSG MLOGPGVR MLOGJBID MLOGSTNO SYSCRDTS SYSCRTID SYSCRJCD SYSCRPID SYSCRVER SYSUPDTS SYSUPTID SYSUPJCD SYSUPPID SYSUPVER VERSION
530392 INFO TWPOSWRT JOB登録LOG 1.2026.0708.0_B 4435 0000 2026/07/16 17:24:38.736 HK-BT01 BATCH TWPOSWRT 1.2026.0708.0_B 2026/07/16 17:24:38.736 HK-BT01 BATCH TWPOSWRT 1.2026.0708.0_B 0
530393 INFO TWPOSWRT Process Start 1.2026.0708.0_B 4435 0000 2026/07/16 17:24:38.798 HK-BT01 BATCH TWPOSWRT 1.2026.0708.0_B 2026/07/16 17:24:38.798 HK-BT01 BATCH TWPOSWRT 1.2026.0708.0_B 0
530394 INFO TWPOSWRT PS22500 Start 1.2026.0708.0_B 4435 0010 2026/07/16 17:24:38.829 HK-BT01 BATCH PS22500 1.2026.0708.0_B 2026/07/16 17:24:38.829 HK-BT01 BATCH PS22500 1.2026.0708.0_B 0
530395 INFO TWPOSWRT 状況MSG:START 送受信件数:52427 特記: 1.2026.0708.0_B 0 2026/07/16 17:24:47.137 HK-BT01 BATCH PS22500 1.2026.0708.0_B 2026/07/16 17:24:47.137 HK-BT01 BATCH PS22500 1.2026.0708.0_B 0
530396 INFO TWPOSWRT 状況MSG:END 送受信件数:52427 特記: 1.2026.0708.0_B 0 2026/07/16 17:29:32.084 HK-BT01 BATCH PS22500 1.2026.0708.0_B 2026/07/16 17:29:32.084 HK-BT01 BATCH PS22500 1.2026.0708.0_B 0
530397 INFO TWPOSWRT PS22500 End Result =Success 1.2026.0708.0_B 4435 0010 2026/07/16 17:29:32.146 HK-BT01 BATCH PS22500 1.2026.0708.0_B 2026/07/16 17:29:32.146 HK-BT01 BATCH PS22500 1.2026.0708.0_B 0
530398 INFO TWPOSWRT Process End Result =0 1.2026.0708.0_B 4435 9990 2026/07/16 17:29:32.159 HK-BT01 BATCH TWPOSWRT 1.2026.0708.0_B 2026/07/16 17:29:32.159 HK-BT01 BATCH TWPOSWRT 1.2026.0708.0_B 0

渡邉 拓英 さんが3ヶ月前に更新 · 編集済み

渡邉 拓英 さんが3ヶ月前に更新 · 編集済み

  • 題名 を 処理が遅い(400万件 7/8<水>開始 7/17<金>でも終わらない) から 処理が遅い(400万件 20日と9時間 に変更

渡邉 拓英 さんが3ヶ月前に更新 · 編集済み

  • 題名 を 処理が遅い(400万件 20日と9時間 から 処理が非常に遅い PS22500 TWPOSWRT (400万件 20日と9時間 に変更

渡邉 拓英 さんが3ヶ月前に更新 · 編集済み

  • 優先度 を 高め から 急いで に変更

渡邉 拓英 さんが3ヶ月前に更新 · 編集済み

ちなみに

FETCH FIRST 5000 ROWS ONLY

で、5000件づつ処理すると、1セット20秒ほど

1H>60M>3600S>180回LOOP

1時間あたり90万件処理できる。
400万件>>>4時間半くらい?!

岡 義久 さんが15日前に更新 · 編集済み

  • 担当者 を 竹川 直子 から 岡 義久 に変更

他の形式にエクスポート: Atom PDF