診斷 DB2 Java 應用程式效能問題：完整指南 (1)

前言

應用程式開發人員與資料庫管理員（DBA）每日面臨的最大挑戰之一，便是處理性能問題。雖然許多效能瓶頸源於資料庫伺服器端，但也有相當一部分問題其實發生在用戶端應用程式層。本文將深入探討如何從 Java 應用程式用戶端的角度，診斷並隔離 IBM DB2 for Linux, UNIX, and Windows 環境下的效能問題。只要找準根因，解決方案往往就在不遠處。

問題診斷與 DB2 架構簡介

本文旨在協助開發人員與 DBA 排除部署 Java 應用程式時常見的效能問題，如程式無回應（Hang）或回應緩慢。要有效排除故障，必須先對 DB2 架構、DB2 應用程式驅動程式及常見組件有清晰理解。DB2 用戶端由多層組成，每個組件都有獨立的追蹤工具，可提供不同層面的診斷資訊。因此，在介紹各種診斷工具前，我們先來看看 DB2 的用戶端-伺服器架構。

DB2 用戶端/伺服器架構

圖 1 展示了 DB2 在用戶端與伺服器端使用的軟體堆疊。連接 DB2 主要有兩種方式：

• 方式一（Client 1）： 最常見的配置。在應用程式所在機器上安裝 DB2 Runtime Client，其中包含 Universal JDBC Type 2 Driver（JCC T2）。
• 方式二（Client 2）： 無需安裝 DB2 用戶端。改用 Universal JDBC Type 4 Driver（JCC T4），僅需將 db2jcc.jar 與授權檔 db2jcc_license_*.jar 加入應用程式的 CLASSPATH 中。

這兩種驅動程式均透過開放標準 Distributed Relational Database Architecture (DRDA) 與 DB2 資料庫伺服器通訊。

應用層介面詳解

圖 2 詳細列出了應用層可使用的介面類型。大多數應用程式透過 DB2 Call Level Interface (CLI) 存取資料庫。JCC 驅動程式專供 Java 應用程式使用。當問題發生時，視應用程式類型而定，開發人員可收集下列追蹤資訊的組合：

• CLI Trace： 追蹤大多數應用程式經由的 CLI 層。
• DB2 Trace： 追蹤用戶端應用程式下方及 DRDA 通訊層的 DB2 內部運作，亦可用於伺服器端問題。
• JCC Trace： 專為使用 DB2 Universal JDBC Driver 的應用程式設計的獨立追蹤工具。
• JDBC Trace： 追蹤舊版 JDBC Type 2 Driver，但較少使用，因其呼叫會向下傳遞至 CLI 層。

故障診斷關鍵概念

• 採用自上而下的方法，先理解整體環境與配置，再逐層深入。
• 釐清應用程式執行位置、資料庫所在位置、各系統平台、作業系統版本與 DB2 修補包級別。
• 盡可能簡化環境：嘗試在用戶端命令列直接執行查詢、或在伺服器端本地執行，觀察行為是否一致。
• 留意近期軟硬體變更。
• 在理解環境並簡化問題域後，再善用追蹤功能向下探索根本原因。
• 檢視用戶端、伺服器端應用程式日誌與 DB2 日誌中的相關訊息。

Developer Workbench 偵錯功能概覽

Developer Workbench 提供完整的開發環境，支援 SQL 與 Java 程序的開發與偵錯。建立預存程序時，應啟用偵錯模式（圖 3），接著在程式碼中設定中斷點，透過 Debug 對話框（圖 4）啟動偵錯。偵錯器會在每個中斷點暫停，顯示變數當前狀態（圖 5、6）。

雖然 Developer Workbench 方便開發，但遇到效能問題時，開發人員可能難以定位是哪個 Java 程式碼片段導致瓶頸。此時需透過 DB2 Trace 功能深入隔離問題來源。

CLI 追蹤概覽

IBM ODBC 與 CLI 驅動程式是 DB2 的可呼叫 SQL 介面。JDBC Type 2、DB2 Perl、PHP PDO、Ruby IBM_DB、.Net/ADO/OLEDB 提供者均建構於此基礎之上。DB2 CLI Trace 內建於驅動程式中，所有直接或間接存取 CLI 層的應用程式均可使用。CLI Trace 包含豐富的時間資訊，是診斷應用程式效能問題的利器。

解讀 CLI Trace 時間資訊

CLI Trace 中每個函式呼叫皆顯示「向外箭頭」（-->）與「向內箭頭」（<---）：

• 向外箭頭： 上次 CLI 呼叫至今，在應用程式端花費的時間。
• 向內箭頭： 在 DB2 用戶端外部花費的時間，包含網路來回時間與伺服器端處理時間。

範例 1：SQLExecute() 執行時間分析

SQLPrepareW( hStmt=1:1, pszSqlStr="select * from EMPLOYEE", cbSqlStr=31 )
 --> Time elapsed - +1.728000E-003 seconds
...
SQLExecute( hStmt=1:1 )
 --> Time elapsed - +2.145000E-003 seconds
 sqlccsend( Handle - 186081616 )
 sqlccsend( ulBytes - 487 )
 sqlccsend( ) rc - 0, time elASPed - +4.500000E-005
 sqlccrecv( timeout - +0.000000E+000 )
 sqlccrecv( ulBytes - 34736 ) - rc - 0, time elapsed - +1.823593E+001
...
SQLExecute( )
 <--- SQL_SUCCESS Time elapsed - +1.828213E+001 seconds

上例中 SQLExecute() 總耗時約 18 秒（1.828213E+001），主要為 sqlccrecv() 等待伺服器回傳資料（約 18.2 秒）。若將相同 SQL 在伺服器端 CLP 執行耗時遠小於此，則瓶頸極可能在網路層；若伺服器端同樣緩慢，則 DBA 需調優伺服器與 SQL。

範例 2：應用程式端延遲

SQLGetConnectAttr( hDbc=0:1, fOption=SQL_ATTR_AUTOCOMMIT, ... )
 --> Time elapsed - +1.407000E-003 seconds
...
SQLColAttributesW( hStmt=1:1, iCol=1, fDescType=SQL_DESC_SCHEMA_NAME, ... )
 --> Time elapsed - +1.260248E+002 seconds   <-- 約 126 秒延遲發生在應用程式端
 sqlccsend( ... )
 sqlccrecv( ... ) - rc - 0, time elapsed - +1.311000E-003
SQLColAttributesW( ... )
 <--- SQL_SUCCESS Time elapsed - +4.869600E-002 seconds

此處 SQLGetConnectAttr() 與 SQLColAttributesW() 之間間隔 126 秒，顯示應用程式邏輯本身有嚴重延遲，開發人員需檢視應用程式碼。

範例 3：連接階段延遲

SQLDriverConnect( hDbc=0:1, hwnd=0:0, szConnStrIn="DSN=sample;UID=ming;PWD=********;...", ... )
 --> Time elapsed - +1.806000E-003 seconds
...
sqlccrecv( ulBytes - 249 ) - rc - 0, time elapsed - +4.629900E-002
...
SQLDriverConnect( ... )
 <--- SQL_SUCCESS Time elapsed - +5.569619E+001 seconds  <-- 連接耗時約 55 秒

若僅在連接階段觀察到此類延遲，可能為認證延遲症狀。

CLI 追蹤關鍵字建議

調查效能問題時，建議啟用 TRACECOMM 並搭配 TRACETIMESTAMP 關鍵字，將額外時間資訊寫入追蹤檔，利於識別延遲點。

DB2 追蹤功能概覽

DB2 Trace 可追蹤用戶端應用程式下方的層次，也可用於伺服器端。利用帶時間戳記的 DB2 Trace 可發現網路緩慢問題。

收集帶時間戳記的 DB2 Trace 步驟

1. 執行 db2trc on -t -f trc.dmp 啟動追蹤（-t 為時間戳記）。
2. 從 CLP 執行 SQL 重現問題。
3. 執行 db2trc off 停止追蹤，產生二進位 dump 檔 trc.dmp。
4. 同修補包級別下將 dump 流化與格式化：
   db2trc flw -t trc.dmp trc.flw（帶時間戳記流檔）
   db2trc fmt trc.dmp trc.fmt（格式化檔）
   db2trc fmt -c trc.dmp trc_drda.fmt（DRDA 追蹤）

流檔時間戳記分析

流檔第二欄為時間戳記，格式 ssss:nnnnnnnnn（秒:奈秒）。範例：

5572283 1485:587835949 | | | | | sqlccrecv data [probe 120]
5572284 1485:587837095 | | | | | | sqlcctcprecv entry
...
6059823 1570:670189615 | | | | | | | tcprecv data [probe 2]
6059824 1570:670198964 | | | | | | | tcprecv exit

tcprecv() 為 OS TCP/IP recv() 的封裝。上例中 tcprecv() 耗時約 85 秒（1570 - 1485），包含伺服器回應與網路傳輸。若伺服器端 CLP 執行同樣 SQL 遠快於此，應懷疑網路問題，請網管協助調查。

返回碼解釋

可使用 db2diag -rc <hex_code> 解讀 DB2 Trace 或 db2diag.log 中的返回碼。範例：

E:db2v8BIN>db2diag -rc fffffb95
Input ECF string 'fffffb95' parsed as 0xFFFFFB95 (-1131)。
ZRC class : Unexpected Operating System error (Class Index: 3)
Sqlcode -1131: SQL1131N DARI (Stored Procedure) process has been terminated abnormally.

DB2 Universal JDBC Driver (JCC) 追蹤概覽

當需判斷錯誤發生前的操作序列、效能問題或 Hang 狀態時，需使用 JCC Trace。JCC Trace 標頭提供豐富環境資訊：作業系統、環境變數、連接 Userid、JDK 版本與廠商、JCC Driver 版本與 JDBC 屬性、遠端 DB2 版本等。各 JCC 版本對應特定 DB2 修補包（表 1、2），產品識別碼對應平台（表 3）。

JCC Trace 範例解析

[ibm][db2][jcc] BEGIN TRACE_DRIVER_CONFIGURATION
[ibm][db2][jcc] Driver: IBM DB2 JDBC Universal Driver Architecture 2.10.62
[ibm][db2][jcc] Java Runtime Environment version 1.4.2_07
[ibm][db2][jcc] Operating system name = SunOS
[ibm][db2][jcc] User's account name = admin
[ibm][db2][jcc] Loaded global properties file: .../DB2JccConfiguration.properties
...
[ibm][db2][jcc] END TRACE_DRIVER_CONFIGURATION
[ibm][db2][jcc] BEGIN TRACE_CONNECTS
[ibm][db2][jcc] Attempting connection to test.ibm.com:50000/SAMPLE
[ibm][db2][jcc] Using properties: { traceFile/tmp/jcctrace.txt, user=DB2INST1, password=******** }
[ibm][db2][jcc] END TRACE_CONNECTS
...
[ibm][db2][jcc][Connection@16fa474] Successfully connected to server jdbc:db2://test.ibm.com:50000/SAMPLE
[ibm][db2][jcc][Connection@16fa474] Database product version: DSN08015 (DB2 for z/OS v8)
[ibm][db2][jcc][Connection@16fa474] DB2 Application Correlator: G41E4EB2.GA90.C0E39670F334.0000

此範例顯示 JCC Type 4 應用程式在 Solaris 上以用戶 admin 執行，使用 DB2INST1 連接至 z/OS 上的 DB2 v8 (DSN08015)。

Java 效能問題分類與診斷策略

效能問題通常分為間歇性與非間歇性。間歇性問題難以重現，可使用 db2pd -catch 搭配 db2cos 腳本，在特定錯誤（如 SQL1224）發生時自動收集診斷資訊。非間歇性問題較易診斷，可透過追蹤收集詳細資訊。Java 應用程式效能問題可歸為四類：

1. 執行緩慢
2. Hang（無回應）
3. 非 DB2 問題
4. 錯誤訊息（最易診斷，依錯誤碼收集對應追蹤即可）

下節示範前三類的診斷方法。

Java 程序實作與呼叫機制

DB2 預設在資料庫引擎外部啟動 db2fmp (Fenced Mode Process) 進程執行隔離的 Java 程序（預存程序或 UDF），防止未經驗證的使用者代碼導致資料庫核心異常終止。Java 程序可定義為 FENCED 或 UNFENCED、THREADSAFE 或 NOT THREADSAFE。預設為 THREADSAFE，以執行緒形式在 db2fmp 中運行。隔離用戶的資源限制由其用戶限制決定（列表 9 示範修改隔離用戶）。

/home/db2inst1/sqllib/adm: ls -la .fenced
-rw-r--r-- 1 nobody nobody 0 Jun 20 16:49 .fenced
/home/db2inst1/: db2stop
/home/db2inst1/: chown db2fenc1 /home/db2inst1/sqllib/adm/.fenced
/home/db2inst1/: db2start
/home/db2inst1/sqllib/adm: ls -la .fenced
-rw-r--r-- 1 db2fenc1 fencgrp 0 Jun 20 16:55 .fenced

應用程式連接 DB2 時，會分配一或多個 db2agent 處理查詢。呼叫 Java 程序時，db2agent 與 db2fmp 透過 Fenced Mode Communication Pool 通訊，其大小由 DB2_FMP_COMM_HEAPSZ 決定，影響並發程序上限。圖 7 展示呼叫流程。

診斷 Java 程序執行緩慢

首先判斷問題在用戶端還是伺服器端。可從用戶端 CLP 呼叫預存程序，若回應時間仍長，則非應用程式問題。接著在伺服器端 CLP 執行，若仍緩慢，則為伺服器端配置、調優或存取計劃不佳問題。若伺服器端正常，則問題在用戶端代碼或網路。此時收集帶時間戳記的 DB2 Trace，找出耗時最久的函式。若使用參數標記，需收集 JDBC/JCC Trace 捕捉輸入參數。

在 Java 程序中加入除錯代碼

找出緩慢程序後，開發人員可在 Java 程序中插入除錯代碼定位瓶頸。最簡單方法是插入 INSERT 陳述式記錄時間戳記到除錯表（列表 10、11）。

connect to sample;
create table sp_debug(sp_name varchar(100), time timestamp, trace_point integer, desc varchar(100));
terminate;

debug_st.execute("INSERT INTO SP_DEBUG values('test_Javasp3', current timestamp, 1,'entry')");
...
debug_st.execute("INSERT INTO SP_DEBUG values('test_Javasp3', current timestamp, 2,'prepare')");
...
debug_st.execute("INSERT INTO SP_DEBUG values('test_Javasp3', current timestamp, 3,'executeUpdate')");
/* 故意造成 Hang */
if( input == 11) { while(true); }
debug_st.execute("INSERT INTO SP_DEBUG values('test_Javasp3', current timestamp, 4,'done if')");
debug_st.execute("INSERT INTO SP_DEBUG values('test_Javasp3', current timestamp, 10,'exit')");

執行後查詢 SP_DEBUG 表即可看到各階段時間戳記（表 4）。缺點是需資料庫連線才能寫入。

寫入檔案的除錯方式

另一種方式是將除錯資訊寫入檔案（列表 12），可在程序定義中加入除錯參數控制啟用。需注意 debugOut.flush() 確保緩衝區即時寫入磁碟，否則 Hang 發生時輸出可能為空。執行後產生 sp_debug.txt（列表 13）。

Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - entry
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - preparing query
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - executed query
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - loop i=1
...
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - exit

診斷 Java 預存程序 Hang 問題

當 Java 應用程式或 DB2 Java 程序 Hang 時，可產生 javacore (Java Dump) 定位 Hang 點。需先設定 IBM JDK 環境變數（列表 14：AIX 範例）。

export JAVA_DUMP_OPTS="ONINTERRUPT(JAVADUMP),ONANYSIGNAL(JavaDUMP)"
export IBM_JavaCOREDIR=/db1/j2ma
db2set DB2ENVLIST="IBM_JAVACOREDIR Java_DUMP_OPTS"
ulimit -a  # 確認 coredump=unlimited
db2stop; db2start

收集用戶端 JCC Trace 確認輸入參數

[jcc][Time:2007-06-20-17:39:30.967][Thread:main][PreparedStatement@1fc2fb]
setInt (1, 11) called
[jcc][Time:2007-06-20-17:39:30.967][Thread:main][PreparedStatement@1fc2fb]
executeUpdate () called
[jcc] [t4][time:2007-06-20-17:39:30.967][thread:main][tracepoint:1][Request.flush]
[jcc][t4] SEND BUFFER: EXCSQLSTT ... SQLDTA ... (輸入值 11 以十六進位 0x0B 顯示於 SQLDTA 緩衝區)
[jcc][t4] [time:2007-06-20-17:39:30.967][thread:main][tracepoint:101]Request flushed.

Trace 顯示最後發送 EXCSQLSTT (Execute SQL Statement) 與 SQLDTA (SQL Data)，輸入值為 11，之後無回應，需調查伺服器端。

伺服器端定位 db2agent 與 db2fmp

透過應用程式快照找到協調代理程式 db2agent PID（列表 16：PID 340630）。再用 db2pd -fmp 找到對應的 db2fmp PID 與執行緒 ID（列表 17：PID 313092, Thread 2571 (0xA0B)）。

產生 Trap 檔與 Javacore

對 db2fmp PID 發送信號（AIX 為 kill -36）產生 trap 檔（列表 18），但資訊有限。利用已啟用的 Javacore 機制，對 db2fmp PID 發送 kill -QUIT，從 db2diag.log 擷取 Javacore（列表 19）。

kill -QUIT <PID of db2fmp>
grep MESSAGE /home/j2ma/sqllib/db2dump/db2diag.log > Javadump.txt

在 Javacore 中搜尋 native ID:0xA0B（即十進位 2571），可見該執行緒堆疊停留在 TEST_JavaSP.java:31 的 while(true); 無窮迴圈（列表 20、21），確認 Hang 原因。

診斷 Java 應用程式網路問題

環境：用戶端 Windows DB2 v9.1 執行舊版 JDBC Type 2 應用程式；伺服器 AIX DB2 v8.x 執行預存程序。應用程式插入值 9、10 正常，插入 11 後 Hang（列表 22）。

收集用戶端並發 CLI、DB2、DRDA Trace（啟用時間戳記）。CLI Trace 顯示呼叫 CALL TEST_JavaSP(?)，參數綁定一次，SQLExecute() 執行三次，對應輸入值 9、10、11（列表 23、24、25）。第三次 rgbValue=11 後 SQLExecute() 追蹤中斷，無 <--- 返回。

簡化環境驗證

建立 DB2 腳本 test.db2（列表 26）在伺服器端直接執行相同呼叫。若伺服器端腳本也 Hang，則確定問題在預存程序本身（如輸入值 11 觸發無窮迴圈），而非網路或用戶端代碼。

connect to sample user db2inst1 using 12345678;
call test_Javasp(9);
call test_Javasp(10);
call test_Javasp(11);
terminate;