應用程序開發人員和數據庫管理員每天面臨的一項挑戰就是處理性能問題。雖然很多性能問題與數據庫服務器有關，但也有一些性能問題與客戶機應用程序有關。本文深入分析如何從應用程序客戶機的角度診斷和隔離性能問題。您將學習如何排除使用 IBM® DB2® for Linux®, UNIX®, and Windows® 數據庫的 Java™ 應用程序中出現的性能問題。一旦理解了性能問題的根源所在，離找到解決方案也就不遠了。
問題診斷和 DB2 架構簡介
本文的目的是幫助應用程序開發人員或數據庫管理員排除和診斷在部署 Java 應用程序時可能遇到的常見性能問題。其中包括常見的應用程序開發問題，例如掛起或者響應緩慢。
很好地理解 DB2 架構、DB2 應用程序驅動程序和常見的 DB2 組件，對於有效地排除和診斷 Java 應用程序的問題很重要。DB2 客戶端由幾個層組成，每個組件都有它自己的跟蹤實用程序，用於提供獨特的信息，以幫助診斷不同類型的應用程序問題。所以在開始討論不同的診斷工具之前，我們首先來看看 DB2 的客戶機-服務器架構。
圖 1 給出了 DB2 在客戶端和服務器端使用的軟件棧。 有兩種方法可以連接到 DB2。圖 1 中描繪的 Client 1 是最常用的配置。在此，諸如 DB2 Runtime Client 之類的 DB2 客戶機是與應用程序一起安裝的。DB2 Runtime ClIEnt 還包括 Universal JDBC Type 2 driver（也稱 JCC T2）。
第二種方法，即 圖 1 中描繪的 ClIEnt 2，不需要安裝 DB2 客戶機。 它不使用 DB2 客戶機，而是使用 Universal JDBC Type 4 driver（也稱 JCC T4），後者可以單獨下載。為了使用 JCC T4 driver，應用程序開發人員必須在應用程序使用的 CLASSPATH 中包括 db2jcc.jar 和許可文件 db2jcc_license_*.jar。這兩種類型的客戶機都使用一種稱作 Distributed Relational Database Architecture™（DRDA®）的開放數據庫通信標准與 DB2 數據庫服務器通信。
圖 1. DB2 客戶機/服務器架構
DB2 客戶機提供很多類型的應用程序接口。圖 2 顯示了應用層，其中詳述了可以與 DB2 一起使用的應用程序類型。其中大多數應用程序都通過 DB2 Call Level Interface（CLI）。JCC 驅動程序只限於 Java 應用程序，因為這是一個基於 Java 的應用程序。當出現問題時，取決於使用的應用程序的類型，應用程序開發人員可以收集下面描述的跟蹤信息的組合。
Call Level Interface (CLI) Trace：大多數應用程序通過 CLI 層。
DB2 跟蹤：在用戶應用程序下和在 DRDA 通信層跟蹤 DB2 客戶端的內部工作情況。也可用於跟蹤服務器端的問題。
JCC 跟蹤：這是用於使用 DB2 Universal JDBC Driver 的應用程序的一個單獨的跟蹤實用程序。
JDBC 跟蹤：跟蹤遺留 JDBC Type 2 driver；但是不常用，因為對這一層的調用將被向下傳遞到 CLI 層。
圖 2. 應用層詳圖
下面是在故障診斷時要記住的一些關鍵概念：
使用自上而下的方法進行故障診斷，而不是盯著細節，試圖弄清楚那些細節是否與當前問題有關。
理解環境和配置。
應用程序在哪裡運行？
數據庫駐留在哪裡？
每個系統上使用何種平台、何種操作系統和什麼版本（修復包級別）的 DB2？
盡可能地簡化環境和應用程序。
從應用程序的外面執行相同的查詢是否會表現出相同的行為？
與從客戶端運行查詢相比，從服務器運行查詢是否可以產生相同的響應？
注意最近的任何軟件或硬件的變化。
只有在理解了環境並簡化了問題域之後，才使用可用的跟蹤功能向下探索以發現根本原因。
在客戶端和服務器端應用程序以及 DB2 日志中查找相應的消息。
Developer Workbench 調試功能概述
Developer Workbench 提供一個全面的開發環境，為 SQL 和 Java 例程的開發和調試提供了便利。當創建一個存儲過程時，應該在調適模式下創建例程。
圖 3. 為新的存儲過程啟用調試
現在可以在存儲過程中創建一些斷點，然後單擊 Debug 對話框開始調試。
圖 4. Debug 對話框
在下面的屏幕快照中，調試器在每個斷點處停下，並顯示程序中的變量的當前狀態。
圖 5. 調試存儲過程
圖 6. 調試存儲過程
Developer Workbench 是開發 Java 應用程序的一個方便的工具。但是，當存在性能問題時，應用程序開發人員就可能不知道哪個 Java 例程或哪部分代碼的性能有缺陷。DB2 trace 功能可用於向下探索和隔離導致問題的應用程序。
CLI 跟蹤概述
IBM Driver for Open Database Connectivity (ODBC) 和 Call Level Interface (CLI) 驅動程序是 DB2 數據庫服務器的一個可調用 SQL 接口。JDBC type 2 driver、DB2 Perl module(DBD:DB2)、PHP Data Objects interface for DB2、IBM_DB driver for Ruby on Rails 和 .Net/ADO/OLEDB 提供程序構建在 IBM Driver for Open Database Connectivity (ODBC) 和 Call Level Interface (CLI) 驅動程序之上。
DB2 CLI trace 是 IBM driver for Open Database Connectivity (ODBC) 和 Call Level Interface (CLI) 驅動程序中內建的跟蹤功能。所有直接或間接訪問 CLI 層的應用程序都可以使用 CLI trace 來跟蹤。DB2 CLI trace 包含不同的時間信息，這些信息可用於診斷應用程序的性能問題。
清單 1 中的 CLI trace 為每個 CLI 函數顯示一個向外箭頭（指向右邊）和一個向內箭頭（指向左邊）。向外箭頭顯示自上次的 CLI 調用以來在應用程序中花費的時間。向內箭頭顯示在 DB2 客戶機之外花費的時間，包括網絡時間（來回）和在 DB2 服務器上花費的時間。例如，SQLExecute() 調用中顯示的 1.828213E+001 秒（大約 18 秒）由 SQL 執行時間加上網絡時間組成。可以提取出 SQLPrepareW() 語句中的 SELECT 語句，然後在數據庫服務器的 DB2 CLP（命令行處理器）上本地運行它。如果在服務器上運行所花的時間要少得多，那麼延遲可能是在網絡層。
如果在服務器上的運行時間大致相同，那麼 DBA 就必須調優服務器和 SQL 語句。
清單 1. SQLExecute() 中的執行時間
SQLPrepareW( hStmt=1:1, pszSqlStr="select * from EMPLOYEE", cbSqlStr=31 )
---> Time elapsed - +1.728000E-003 seconds
( StmtOut="select * from EMPLOYEE" )
...
...
SQLExecute( hStmt=1:1 )
---> Time elapsed - +2.145000E-003 seconds
( Package="SYSSH200 ", Section=4 )
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
( Requested Cursor Attributes=3 )
( Reply Cursor Attributes=524298 )
( Actual Cursor Attributes=524299 )
SQLExecute( )
<--- SQL_SUCCESS Time elapsed - +1.828213E+001 seconds
下面的 CLI 跟蹤輸出顯示在 CLI 調用 SQLGetConnectAttr() 和 SQLColAttributesW() 之間在應用程序中花費的時間為 1.260248E+002 大約（126 秒）。換句話說，應用程序中出現了 1.260248E+002 秒的延遲。如果那樣的延遲超出了預期，那麼應用程序開發人員應該調查應用程序代碼。
清單 2. 應用程序中的執行時間
SQLGetConnectAttr( hDbc=0:1, fOption=SQL_ATTR_AUTOCOMMIT, pvParam=&0c53fdf0,
cbParamMax=-4, pcbParam=<NULL pointer> )
---> Time elapsed - +1.407000E-003 seconds
SQLGetConnectAttr( pvParam=0 )
<--- SQL_SUCCESS Time elapsed - +1.160500E-002 seconds
SQLColAttributesW( hStmt=1:1, iCol=1, fDescType=SQL_DESC_SCHEMA_NAME,
rgbDesc=&0c53fd10, cbDescMax=200, pcbDesc=&0c53fde0, pfDesc=&0c53fdd8 )
---> Time elapsed - +1.260248E+002 seconds
sqlccsend( Handle - 186057520 )
sqlccsend( ulBytes - 228 )
sqlccsend( ) rc - 0, time elASPed - +8.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 4099 ) - rc - 0, time elapsed - +1.311000E-003
SQLColAttributesW( pCharAttribute="MING ", psCharAttributeByteLen=16 )
<--- SQL_SUCCESS Time elapsed - +4.869600E-002 seconds
下面的 CLI 跟蹤顯示一個連接花費了 5.569619E+001 秒（大約 55 秒）。如果只在連接期間觀察到這樣的延遲，那麼可能是認證延遲的症狀。欲了解更多細節，請參閱診斷認證問題小節。
清單 3. SQLDriverConnect() 中的執行時間
SQLDriverConnect( hDbc=0:1, hwnd=0:0, szConnStrIn="DSN=sample;UID=ming;
PWD=********;AUTOCOMMIT=0;CONNECTTYPE=1;", cbConnStrIn=-3,
szConnStrOut=&0bf9de64, cbConnStrOutMax=256, pcbConnStrOut=&0bf9e044,
fDriverCompletion=SQL_DRIVER_NOPROMPT )
---> Time elapsed - +1.806000E-003 seconds
sqlccsend( Handle - 199165312 )
sqlccsend( ulBytes - 276 )
sqlccsend( ) rc - 0, time elASPed - +2.440000E-004
sqlccrecv( )
sqlccrecv( ulBytes - 122 ) - rc - 0, time elapsed - +3.849500E-002
sqlccsend( Handle - 199165312 )
sqlccsend( ulBytes - 272 )
sqlccsend( ) rc - 0, time elASPed - +2.670000E-004
sqlccrecv( )
sqlccrecv( ulBytes - 249 ) - rc - 0, time elapsed - +4.629900E-002
( DBMS NAME="DB2/AIX64", Version="08.02.0004", Fixpack="0x23050106" )
( Application Codepage=1252, Database Codepage=819, Char Send/Recv
Codepage=1252, Graphic Send/Recv Codepage=1200 )
SQLDriverConnect( szConnStrOut="DSN=sample;UID=;PWD=********;
DBALIAS=DPMP;AUTOCOMMIT=0;CONNECTTYPE=1;", pcbConnStrOut=74 )
<--- SQL_SUCCESS Time elapsed - +5.569619E+001 seconds
當利用 CLI 跟蹤調查性能問題時，重要的是使用 CLI 關鍵字 TRACECOMM，另外還可以選擇使用關鍵字 TRACETIMESTAMP，因為這兩個關鍵字將跟蹤額外的時間信息，並將該信息寫入到 CLI 跟蹤文件中，從而更方便發現跟蹤中的延時。
DB2 跟蹤功能概述
DB2 跟蹤可用於跟蹤客戶端上應用程序之下的層。它還可以用於跟蹤服務器端。
可以使用帶時間戳的 DB2 跟蹤來發現網絡緩慢的問題。 下面是可以在客戶端上使用的跟蹤：
輸入命令 db2trc on -t -f trc.dmp 。
通過從 CLP 運行 SQL 語句重新創建性能問題。
輸入命令 db2trc off。
跟蹤被關閉後，在發出 db2trc 命令的路徑中將生成一個二進制 dump 文件。在這裡，這個 dump 文件是 trc.dmp，為了使該文件可讀，必須將其流化（flw）和格式化（fmt）為 ASCII 文件。使用 fmt -c 將生成一個 DRDA 跟蹤。
例如：
db2trc flw trc.dmp trc.flw
db2trc fmt trc.dmp trc.fmt
db2trc fmt -c trc.dmp trc_drda.fmt
應該注意的是，這個過程需要與收集 DB2 跟蹤 dump 文件必須在相同的 DB2 修復包級別上執行。流文件（trc.flw）列出每個進程和線程做出的函數調用。格式文件（trc.fmt）將提供關於每個 DB2 函數的詳細信息，順序與寫到跟蹤文件的順序一致。如果 db2trc 是帶 -t 選項發出的，那麼可以用 -t 選項流化 dump 文件，如下所示。
db2trc flw -t trc.dmp trc.flw
上面的命令創建一個帶時間戳的 DB2 跟蹤流文件。清單 4 是 DB2 跟蹤流文件的一個示例。第二列是時間戳，其格式為 ssss:nnnnnnnnn。其中 ssss 表示秒，nnnnnnnnnn 表示納秒。
清單 4. 帶時間戳的 DB2 跟蹤
5572283 1485:587835949 | | | | | sqlccrecv data [probe 120]
5572284 1485:587837095 | | | | | | sqlcctcprecv entry
5572285 1485:587838001 | | | | | | sqlcctcprecv data [probe 1]
5572286 1485:587839212 | | | | | | | tcprecv entry
6059823 1570:670189615 | | | | | | | tcprecv data [probe 2]
6059824 1570:670198964 | | | | | | | tcprecv exit
6059825 1570:670208194 | | | | | | sqlcctcprecv exit
6059826 1570:670211750 | | | | | sqlccrecv data [probe 5]
6059827 1570:670213511 | | | | | sqlccrecv exit
DB2 依賴於操作系統應用程序編程接口來執行網絡通信。可以將上面的 tcprecv() 函數看作 OS API TCP/IP recv() 調用的一個包裝器。recv()函數從一個連接套接字接收數據。如清單 4 所示，tcprecv() 花了大約 85 秒（1570 - 1485）來接收數據。這 85 秒由服務器響應時間和網絡時間完成。如果在服務器上從 CLP 執行相同的 SQL 語句花的時間要少得多，那麼最值得懷疑的是網絡緩慢，網絡管理員需要進行調查。
清單 5 顯示如何使用 db2diag 命令解釋 DB2 跟蹤或 db2diag.log 中的返回碼。
清單 5. 解釋返回碼
E:db2v8BIN>db2diag -rc fffffb95
Input ECF string 'fffffb95' parsed as 0xFFFFFB95 (-1131）。
NOTE: ../sqz/sqlzwhatisrc.C:
V7 input ZRC 0xFFFFFB95 (-1131) may translate to V8 ZRC value of 0x83000
B95 (-2097149035)
ZRC value to map: 0x83000B95 (-2097149035)
V7 Equivalent ZRC value: 0xFFFFBB95 (-17515)
ZRC class :
Unexpected Operating System error (Class Index: 3)
Component:
Unknown component (Component Index: 0)
Undefined as of DB2 v8.1.14.292; s061108
Attempting to lookup value 0xFFFFFB95 (-1131) as a sqlcode Sqlcode -1131
SQL1131N DARI (Stored Procedure) process has been terminated abnormally.
DB2 Universal JDBC driver 跟蹤概述
當判斷在收到錯誤消息之前已經發生或正在發生的操作、性能問題或掛起時，需要使用 JDBC Universal Driver (JCC) 跟蹤。如果沒有這種類型的信息，就難以確定應用程序如何進入這種狀態。JCC 跟蹤應該在包含 Java 應用程序的系統上運行。
JCC 跟蹤的頭部提供一組有用的環境信息，例如：
操作系統和環境變量。該信息可用於確定我們是否在使用多個版本的 JCC driver 或應用程序庫。
應用程序用於連接的 Userid。
JDK 的版本和供應商。確認 JDK 受 DB2 支持。
JCC Driver 級別和使用的 JDBC 屬性。
遠程 DB2 數據庫的版本。
每種 JCC 驅動程序級別對應於一個 DB2 修復包，如 表 1（DB2 v8.x）和 表 2 （DB2 v9.x）所示。表 3 顯示了從一個 JCC 跟蹤返回的產品標識。
表 1. DB2 v8 附帶的 JCC Driver 版本
JCC 版本 DB2 版本 JCC 1.0 GA（General Availability 或 FixPak 0） JCC 1.1 FP1 JCC 1.2 FP2 JCC 1.3 FP3 JCC 1.5 FP4 JCC 1.9 FP5 JCC 2.2 FP6 JCC 2.3 FP7 JCC 2.5 FP8 JCC 2.6.80 FP9 JCC 2.7.58 FP10 SYSPLEX routing support introduced JCC 2.8.46 FP11 JCC 2.9.31 FP12 JCC 2.10.27 FP13 JCC 2.10.52 FP14
表 2. DB2 9 附帶的 JCC Driver 版本
JCC 版本 DB2 版本 JCC 3.1.57 GA（General Availability 或 FixPak 0） JCC 3.2.49 FP1 JCC 3.3.54 FP2 JCC 3.4.65 FP3
表 3. JCC 跟蹤的產品版本
數據庫產品版本 DB2 平台 SQL08027 DB2 v8.x on Linux/Unix/Windows SQL09011 DB2 v9.x on Linux/Unix/Windows DSN07012 DB2 for z-SerIEs (z/OS) v7.x DSN08015 DB2 for z-SerIEs (z/OS) v8.x V05R04M00 DB2 for i-SerIEs (AS400) V5R4
從 清單 6 中的示例 JCC 跟蹤可以看到，JCC Type 4 應用程序在 Solaris 5.8 上以用戶 admin 運行，它使用 userid DB2INST1 連接到 DB2 v8 for z/OS (DSN08015) 上的數據庫 SAMPLE。
清單 6. 示例 JCC 跟蹤
[ibm][db2][jcc] BEGIN TRACE_DRIVER_CONFIGURATION
[ibm][db2][jcc] Driver: IBM DB2 JDBC Universal Driver Architecture 2.10.62
[ibm][db2][jcc] Compatible JRE versions: { 1.3, 1.4, 1.5 }
[ibm][db2][jcc] Target server licensing restrictions: { z/OS: enabled; SQLDS: enabled;
iSerIEs: enabled; DB2 for Unix/Windows: enabled; Cloudscape: enabled }
[ibm][db2][jcc] Range checking enabled: true
[ibm][db2][jcc] Bug check level: 0xff
[ibm][db2][jcc] Default fetch size: 64
[ibm][db2][jcc] Default isolation: 2
[ibm][db2][jcc] Collect performance statistics: false
[ibm][db2][jcc] No security manager detected.
[ibm][db2][jcc] Detected local clIEnt host: aPPServer.ibm.com/9.29.3.3
[ibm][db2][jcc] Access to package sun.io is permitted by security manager.
[ibm][db2][jcc] JDBC 1 system property jdbc.drivers = null
[ibm][db2][jcc] Java Runtime Environment version 1.4.2_07
[ibm][db2][jcc] Java Runtime Environment vendor = Sun Microsystems Inc.
[ibm][db2][jcc] Java vendor URL = http://Java.sun.com/
[ibm][db2][jcc] Java installation directory = /aPPS/j2re1.4.2_07
[ibm][db2][jcc] Java Virtual Machine specification version = 1.0
[ibm][db2][jcc] Java Virtual Machine specification vendor = Sun Microsystems Inc.
[ibm][db2][jcc] Java Virtual Machine specification name = Java Virtual Machine
Specification
[ibm][db2][jcc] Java Virtual Machine implementation version = 1.4.2_07-b05
[ibm][db2][jcc] Java Virtual Machine implementation vendor = Sun Microsystems Inc.
[ibm][db2][jcc] Java Virtual Machine implementation name = Java HotSpot(TM) Server VM
[ibm][db2][jcc] Java Runtime Environment specification version = 1.4
[ibm][db2][jcc] Java Runtime Environment specification vendor = Sun Microsystems Inc.
[ibm][db2][jcc] Java Runtime Environment specification name = Java Platform API
Specification
[ibm][db2][jcc] Java class format version number = 48.0
[ibm][db2][jcc] Java class path = :/aPPS/jakarta-tomcat-5.5.7/common/lib/db2jcc.jar:
/aPPS/jakarta-tomcat-5.5.7/common/lib/db2jcc_license_cisuz.jar:
/aPPS/jakarta-tomcat-5.5.7/common/lib/db2jcc_license_cisuz.jar:
/aPPS/jakarta-tomcat-5.5.7/common/lib/db2jcc_Javax.jar:
/aPPS/jakarta-tomcat-5.5.7/bin/bootstrap.jar:
/aPPS/jakarta-tomcat-5.5.7/bin/commons-logging-api.jar
[ibm][db2][jcc] Java native library path = /aPPS/j2re1.4.2_07/lib/sparc/server:
/apps/j2re1.4.2_07/lib/sparc:/aPPS/j2re1.4.2_07/../lib/sparc:/usr/lib
[ibm][db2][jcc] Path of extension directory or directorIEs = /aPPS/j2re1.4.2_07/lib/ext
[ibm][db2][jcc] Operating system name = SunOS
[ibm][db2][jcc] Operating system architecture = sparc
[ibm][db2][jcc] Operating system version = 5.8
[ibm][db2][jcc] File separator ("/" on UNIX) = /
[ibm][db2][jcc] Path separator (":" on UNIX) = :
[ibm][db2][jcc] User's account name = admin
[ibm][db2][jcc] User's home directory = /home/admin
[ibm][db2][jcc] User's current working directory = /aPPS/jakarta-tomcat-5.5.7/bin
[ibm][db2][jcc] Loaded global propertIEs file:
/apps/jakarta-tomcat-5.5.7/webaPPS/ivs/WEB-INF/classes/DB2JccConfiguration.propertIEs
[ibm][db2][jcc] Loaded by Context ClassLoader: WebappClassLoader
...
...
[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] BEGIN TRACE_CONNECTS
[ibm][db2][jcc][Connection@16fa474] Successfully connected to server
jdbc:db2://test.ibm.com:50000/SAMPLE
[ibm][db2][jcc][Connection@16fa474] User: DB2INST1
[ibm][db2][jcc][Connection@16fa474] Database product name: DB2
[ibm][db2][jcc][Connection@16fa474] Database product version: DSN08015
[ibm][db2][jcc][Connection@16fa474] Driver name: IBM DB2 JDBC Universal Driver
Architecture
[ibm][db2][jcc][Connection@16fa474] Driver version: 2.10.62
[ibm][db2][jcc][Connection@16fa474] DB2 Application Correlator:
G41E4EB2.GA90.C0E39670F334.0000
[ibm][db2][jcc][Connection@16fa474] END TRACE_CONNECTS
...
Java 性能
性能問題通常可以分為兩類：間歇性的（intermittent）和非間歇性的（non-intermittent）。 間歇性問題難以排除，因為這些問題可能隨著工作負載或應用程序運行的時機而在任意時候發生。對於診斷間歇性性能問題，可以使用的一個非常有用的工具是 db2pd -catch。 該工具可以設置為執行一個腳本，該腳本用於在返回指定錯誤消息時收集診斷信息。這種工具的缺點是，它是在錯誤發生之後才收集信息的。這個工具的一個理想的用途是當數據庫服務器達到一個容量阈值時捕捉快照信息。例如，當超過最大 db2agents 數，DB2 不能接受新連接時，應用程序返回 -1224 (SQL1224)。
可以編寫一個名為 “db2cos” 的 shell 腳本，其中包含您想要在 DB2 遇到 SQL1224 錯誤時運行的任何操作系統或 DB2 命令。注意，該腳本必須命名為 db2cos；否則 DB2 不會執行它。
清單 7. 編寫 db2cos 腳本
#!/bin/sh
# DB2 Callout script to collect information for SQL1224
echo “Collecting information for SQL1224">>db2cos.rpt
echo “db2cos script executed at `date`" >>db2cos.rpt
db2pd -agents >>db2cos.rpt
清單 8 演示在 shell 腳本完成之後，如何安裝調出腳本。如果錯誤消息與鎖有關，則在 db2cos 腳本中還應該收集鎖快照。
清單 8. 啟用 db2cos
$ cp db2cos /home/db2inst1/sqllib
$ db2pd -catch clear all
All error catch flag settings cleared.
$ db2pd -catch -1224
Input ECF string '-1224' parsed as 0xFFFFFB38 (-1224）。
Error Catch #1
Sqlcode: -1224
ReasonCode: 0
ZRC: 0
ECF: 0
Component ID: 0
LockName: Not Set
LockType: Not Set
Current Count: 0
Max Count: 255
Bitmap: 0x461
Action: Error code catch flag enabled
Action: Execute sqllib/db2cos callout script
Action: Produce stack trace in db2diag.log
可重復的或非間歇性的問題診斷起來要容易得多，因為可以使用跟蹤收集更多的診斷信息。 Java 應用程序的性能問題可以分為 4 種類型：
執行慢
掛起
非 DB2 問題
錯誤消息
通常，上述第 4 類（錯誤消息）問題最容易診斷，因為有返回的錯誤消息。在這種情況下，只需根據在客戶端上運行的導致錯誤消息的應用程序的類型收集適當的跟蹤。通常，通過查看跟蹤就可以得到足夠的信息來解決問題。下一節演示如何診斷前三種情況。
Java 例程實現概述
在診斷 Java 例程（可定義為存儲過程或用戶定義函數）的問題之前，有必要回顧一下 Java 例程是如何調用的。默認情況下，DB2 在 DB2 之外開始一個名為 db2fmp 的進程，以運行隔離的 Java 例程。之所以采取這樣的預防性措施，是因為 DB2 要運行應用程序開發人員所編寫的未知的代碼。如果出現一個異常，最壞的情況只是 db2fmp 進程被終止，而不會使整個數據庫停止工作。這種增加的靈活性還可以在劣質的 Java 例程消耗太多的內存或 CPU 時終止它們。如果 Java 例程不加隔離地在 db2agent 中運行，而不是在 db2fmp 進程中運行，那麼一個異常就會使整個數據庫停止工作。
除了將 Java 例程定義為 FENCED 或 UNFENCED 外，還可以將它們定義為 THREADSAFE 或 NOT THREADSAFE。不同之處在於，THREADSAFE Java 例程是作為 db2fmp 進程中的一個線程運行的。而 NOT THREADSAFE Java 例程在一個單獨的 db2fmp 進程中運行。默認情況下，DB2 將 Java 例程創建為 THREADSAFE。由於 db2fmp 進程是使用隔離 userid 運行的，因此它的資源限制由它的用戶限制決定。 清單 9 顯示了如何發現和修改隔離 userid。
清單 9. 修改隔離 userid
/home/db2inst1/sqllib/adm: ls -la .fenced
-rw-r--r-- 1 nobody nobody 0 Jun 20 16:49 .fenced
/home/db2inst1/: db2stop
SQL1064N DB2STOP processing was successful.
/home/db2inst1/: chown db2fenc1 /home/db2inst1/sqllib/adm/.fenced
/home/db2inst1/: db2start
SQL1063N DB2START processing was successful.
/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 注冊表變量 DB2_FMP_COMM_HEAPSZ 決定。 DB2_FMP_COMM_HEAPSZ 的大小將決定可以在一個實例中運行的並發例程的最大數量。 圖 7 顯示了 Java 例程是如何被調用的。
圖 7. 調用 Java 例程
診斷 Java 例程執行慢的問題
如前面 圖 1 所示，既有客戶端組件，也有服務器端組件，兩者各由多個層組成。首先要確定問題是在客戶端還是服務器端。為了排除是 Developer Workbench 導致問題的可能性，可以從客戶端命令行處理器調用該存儲過程（如果適用的話），並檢查響應時間是否可以接受。
如果響應時間還是比較長，或者與從應用程序中調用這個存儲過程的時間差不多，那麼可以斷定，應用程序不是罪魁禍首。在這種情況下，接下來可以從服務器的命令行處理器調用這個存儲過程。如果響應時間較長，那麼數據庫管理員應該調查服務器端。性能問題可能是由於配置不當、調優問題或者執行例程時優化器使用了不好的訪問計劃導致的。
如果不是這樣，那麼我們可以斷定性能下降要麼是出現在 DB2 客戶機代碼中，要麼是出現在網絡上。 此時，可以收集一個帶時間戳選項的 DB2 跟蹤，以確定是哪個函數用了最長的時間才返回。例如，我們是在等 TCP/IP 嗎？有些應用程序使用參數占位符調用例程，因此需要收集 JDBC 或 JCC 跟蹤，以捕捉輸入參數。應用程序端的日志也可能包含這樣的信息。
找出慢的存儲過程之後，應用程序開發人員應該在 Java 例程中添加調試代碼，以判斷性能瓶頸出在什麼地方。添加調試代碼的最容易的方法是將 INSERT 語句添加到 Java 例程中。 清單 10 是創建用於存儲調試信息的 SP_DEBUG 表的腳本。
清單 10. 創建調試表的 DB2 腳本
connect to sample;
create table sp_debug(sp_name varchar(100), time timestamp, trace_point integer,
desc varchar(100));
terminate;
清單 11. 將調試信息寫到表中
import Java.sql.*;
import Java.io.*;
public class TEST_JavaSP3
{
public static void tEST_JavaSP3 (int input) throws SQLException,
Exception
{
int errorCode;
Connection dbCon=null;
Statement debug_st=null;
PreparedStatement pstmt=null;
try
{
// get caller's connection to the database
dbCon = DriverManager.getConnection("jdbc:default:connection");
// Create a statement handle for to execute debug statements
debug_st = dbCon.createStatement();
debug_st.execute("INSERT INTO SP_DEBUG values('test_Javasp3',
current timestamp, 1,'entry')");
String query = "INSERT INTO T1 (C1) VALUES (?)";
debug_st.execute("INSERT INTO SP_DEBUG values('test_Javasp3',
current timestamp, 2,'prepare')");
pstmt = dbCon.prepareStatement(query);
pstmt.setInt(1, input);
pstmt.executeUpdate();
debug_st.execute("INSERT INTO SP_DEBUG values('test_Javasp3',
current timestamp, 3,'executeUpdate')");
/* Cause the stored proc to hang if the input value is 11 */
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')");
// Cleanup
pstmt.close();
debug_st.close();
dbCon.close();
}
catch (SQLException sqle)
{
errorCode = sqle.getErrorCode();
throw new SQLException( errorCode + " FAILED" );
}
finally
{
if(pstmt !=null)
{pstmt.close();}
if(debug_st !=null)
{debug_st.close();}
if( dbCon != null)
{dbCon.close();}
}
} // end finally
}
表 4. SP_DEBUG 表的內容
SP_NAME TIME TRACEPOINT DESC test_Javasp3 2007-07-10-19.25.21.436000 1 entry test_Javasp3 2007-07-10-19.25.21.452000 2 prepare test_Javasp3 2007-07-10-19.25.21.452000 3 executeUpdate test_Javasp3 2007-07-10-19.25.21.452000 4 done if test_Javasp3 2007-07-10-19.25.21.452000 10 exit
使用上述方法的優點是，這種方法非常容易實現。缺點是如果沒有數據庫連接，就不能將調試信息輸出到表中。這大概不是問題，因為像這樣嚴重的錯誤應該已經解決了。 表 4 列出了在執行存儲過程之後調試表的內容。它在執行的代碼旁顯示一個時間戳。
另一種方法是修改 Java 例程，使它將調試信息寫到一個文件中，如 清單 12 所示。在我們的例子中，我們將一個調試參數添加到存儲過程定義中，以啟用/禁用調試。當添加調試信息時，可能會有額外的開銷，所以應用程序開發人員可以選擇從 Java 例程的生產版本中刪除調試代碼。還應注意，與將調試信息插入到一個表中相比，將調試信息寫到文件中需要進行更多的調用，因為需要格式化一個 Java 時間戳。默認情況下，Java 時間戳為自 1970 年 1 月 1 日以來的毫秒數。Calendar() 對象用於將時間戳（單位為毫秒）格式化為人類熟悉的格式。 對 debugOut.flush()的調用立即將字符緩沖區轉儲到文件中。在調試掛起問題時，假設沒有這個調用，那麼如果在字符緩沖區充滿之前發生了掛起，就不能將調試輸出寫到文件。
清單 12. 將調試信息寫到文件
import Java.sql.*;
import Java.io.*;
import Java.util.*;
public class TEST_JavaSP2
{
public static void tEST_JavaSP2 (int input, int debug) throws SQLException,
Exception
{
int errorCode;
PrintWriter debugOut=null;
Calendar cal = null;
try
{
if (debug == 1)
{
cal = Calendar.getInstance();
cal.setTimeInMillis(System.currentTimeMillis() );
// Open debug file
debugOut = new PrintWriter(new FileWriter("sp_debug.txt"));
cal.setTimeInMillis(System.currentTimeMillis() );
debugOut.println(cal.getTime() + " " + cal.get(Calendar.MILLISECOND)+ " "
+ "tEST_JavaSP2 - entry");
// Need to flush buffer to disk otherwise when troubleshooting hang
// issue the output file will be empty
debugOut.flush();
}
// get caller's connection to the database
Connection con = DriverManager.getConnection("jdbc:default:connection");
String query = "INSERT INTO T1 (C1) VALUES (?)";
if (debug == 1)
{
cal.setTimeInMillis(System.currentTimeMillis() );
debugOut.println(cal.getTime() + " " + cal.get(Calendar.MILLISECOND)+ " "
+ "tEST_JavaSP2 - preparing query");
debugOut.flush();
}
PreparedStatement pstmt = con.prepareStatement(query);
pstmt.setInt(1, input);
pstmt.executeUpdate();
if (debug == 1)
{
cal.setTimeInMillis(System.currentTimeMillis() );
debugOut.println(cal.getTime() + " " + cal.get(Calendar.MILLISECOND)+ " "
+ "tEST_JavaSP2 - executed query");
debugOut.flush();
}
if( input == 11)
{
for(int i=0;i<10;i++)
{
if (debug == 1)
{
cal.setTimeInMillis(System.currentTimeMillis() );
debugOut.println(cal.getTime() + " " + cal.get(Calendar.MILLISECOND)
+ " " + "tEST_JavaSP2 - loop" + " i="+i);
debugOut.flush();
}
}
}
if (debug == 1)
{
cal.setTimeInMillis(System.currentTimeMillis() );
debugOut.println(cal.getTime() + " " + cal.get(Calendar.MILLISECOND)
+ " " + "tEST_JavaSP2 - exit");
debugOut.flush();
// Close debug File
debugOut.close();
}
}
catch (SQLException sqle)
{
errorCode = sqle.getErrorCode();
throw new SQLException( errorCode + " FAILED" );
}
finally
{
if(debugOut!=null)
{debugOut.close(); }
}
}
}
在執行存儲過程之後，調試信息被寫到純文本文件 sp_debug.txt 中。可以修改這些例子，以提供附加的調試信息。847 是毫秒數。此外，還有一些更復雜的生成調試信息的方法，例如 這個例子，它演示了如何通過創建一個調試調用庫來跟蹤 SQL 存儲過程。
清單 13. sp_debug.txt 的內容
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 - loop i=2
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - loop i=3
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - loop i=4
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - loop i=5
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - loop i=6
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - loop i=7
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - loop i=8
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - loop i=9
Wed Jul 11 16:18:11 EDT 2007 847 tEST_JavaSP2 - exit
診斷 Java 存儲過程掛起問題
當一個 Java 應用程序或 DB2 Java 例程掛起時，可以生成一個 javacore（也稱 javadump）來確定它是在何處掛起的。下面的例子演示如何為一個 Java 例程收集 Javacore。
為了啟用 Javacore，必須設置 IBM JDK 環境。對於不同的平台和使用的不同 IBM JDK，這個設置過程可能略微有些差別。在我們的例子中，我們從一個 JCC 應用程序連接到 DB2 V8.x server on AIX®。
清單 14. 在 AIX 中啟用 Javacores
$ export JAVA_DUMP_OPTS="ONINTERRUPT(JAVADUMP),ONANYSIGNAL(JavaDUMP)"
$ export IBM_JavaCOREDIR=/db1/j2ma
$ db2set DB2ENVLIST="IBM_JAVACOREDIR Java_DUMP_OPTS"
$ ulimit -a
time(seconds) unlimited
file(blocks) unlimited
data(kbytes) 131072
stack(kbytes) 32768
memory(kbytes) 32768
coredump(blocks) unlimited
nofiles(descriptors) 2000
$ db2stop
SQL1064N DB2STOP processing was successful.
$ db2start
SQL1063N DB2START processing was successful.
注意，設置可能稍微有些不同，因為這個例子中使用的 JDK 級別不同於您使用的 JDK 級別。
JAVA_DUMP_OPTS 指定哪些信號會觸發 Javacore。
IBM_JAVACOREDIR 指定 Javacore 文件的位置。
可以使用 DB2ENVLIST 將環境變量傳遞給 db2fmp 進程，因為 db2start 命令會過濾掉所有不是以 DB2* 或 db2* 開頭的用戶環境變量。
然後，確認隔離 userid 的 coredump=unlimited，並重新啟動實例。
在這個例子中，JCC 應用程序在一個遠程 AIX DB2 服務器上調用存儲過程 TEST_JAVASP，而這個存儲過程掛起，沒有返回。首先要做的事是從客戶端收集一個 JCC 跟蹤，因為我們想知道發送給存儲過程的是什麼值。也許是一個特定的 Java 值導致掛起。
清單 15. 對存儲過程調用的 JCC 跟蹤
[jcc][Time:2007-06-20-17:39:29.388][Thread:main][Connection@54a328]
prepareStatement (CALL JASON.TEST_JavaSP(?)) called
[jcc][Time:2007-06-20-17:39:29.420][Thread:main][Connection@54a328]
prepareStatement () returned PreparedStatement@1fc2fb
...
...
[jcc][Time:2007-06-20-17:39:30.967][Thread:main][PreparedStatement@1fc2fb]
executeUpdate () returned -1
[jcc][SystemMonitor:stop] core: 13.378541ms | network: 9.792076ms | server: 0.0ms
[jcc][Time:2007-06-20-17:39:30.967][Thread:main][PreparedStatement@1fc2fb]
setInt (1, 11) called
[jcc][SystemMonitor:start]
[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 (ASCII) (EBCDIC)
[jcc][t4] 0 1 2 3 4 5 6 7 8 9 A B C D E F 0123456789ABCDEF 0123456789ABCDEF
[jcc][t4] 0000 007ED05100010078 200B00442113A5F9 .~.Q...x ..D!... .=}...........v9
[jcc][t4] 0010 A281949740404040 4040404040404040 ....@@@@@@@@@@@@ samp
[jcc][t4] 0020 D5E4D3D3C9C44040 4040404040404040 ......@@@@@@@@@@ NULLID
[jcc][t4] 0030 4040E2E8E2E2C8F2 F0F0404040404040 @@........@@@@@@ SYSSH200
[jcc][t4] 0040 404040405359534C 564C303100010005 @@@@SYSLVL01.... ...<.<......
[jcc][t4] 0050 2105F100052111F1 0008211400007FFF !....!....!..... ..1....1......".
[jcc][t4] 0060 00062141FFFF0006 2140FFFF00052142 ..!A....!@....!B ......... ......
jcc][t4] 0070 040005210E010008 190080000000 ...!.......... ..............
[jcc][t4]
[jcc][t4] SEND BUFFER: SQLDTA (ASCII) (EBCDIC)
[jcc][t4] 0000 0024D0030001001E 2412001000100676 .$......$......v ..}.............
[jcc][t4] 0010 D00300040671E4D0 0001000A147A0000 .....q.......z.. }.....U}.....:..
[jcc][t4] 0020 0000000B .... ....
[jcc][t4]
[jcc][t4] [time:2007-06-20-17:39:30.967][thread:main][tracepoint:101]Request flushed.
從客戶端上的 JCC 跟蹤可以看到，最近執行的操作是用輸入值 11 調用存儲過程 JASON.TEST_JavaSP(?) 時執行的 executeUpdate()。DRDA 緩沖區顯示，我們在跟蹤結束時發送 EXCSQLSTT（執行 SQL 語句）和 SQLDTA（SQL 數據）。由於沒有將任何其他內容返回到客戶端，因此應該調查服務器端，以確定為什麼沒有返回任何內容。注意，這裡可能需要 DB2 數據庫管理員的幫助，因為應用程序開發人員通常沒有訪問服務器的權限。
在服務器端，有多種方法可以顯示應用程序信息，例如使用 db2pd -applications -db sample、 db2 "list applications show detail" 等等。在我們的例子中，我們選擇收集應用程序快照，以發現發生了什麼事情。在下面的例子中，JCC 應用程序從客戶端 IP 地址 10.1.1.123 和端口 2582 進行連接。如果應用程序與 DB2 數據庫在相同的系統上，那麼 Inbound communication address = *LOCAL.hostname 。為了從快照中識別出應用程序，應用程序開發人員需要知道應用程序的名稱、userid 和它所連接到的數據庫。
清單 16. 使用快照發現與應用程序關聯的 db2agent 的 PID
Application Snapshot
Application handle = 7
Application status = UOW Executing
Status change time = Not Collected
Application code page = 819
Application country/region code = 0
DUOW correlation token = GA123456.GA16.070622200608
Application name = db2jcc_application
Application ID = GA123456.GA16.070622200608
Sequence number = 0003
TP Monitor clIEnt user ID =
TP Monitor clIEnt workstation name = majason1
TP Monitor clIEnt application name =
TP Monitor clIEnt accounting string =
Connection request start timestamp = 06/22/2007 16:06:08.388356
Connect request completion timestamp = 06/22/2007 16:06:08.865863
Application idle time = Not Collected
CONNECT Authorization ID = J2MA
ClIEnt login ID = J2MA
Configuration NNAME of clIEnt = majason1
ClIEnt database manager product ID = JCC03020
Process ID of clIEnt application = 0
Platform of clIEnt application = Unknown via DRDA
Communication protocol of clIEnt = TCP/IP
Inbound communication address = 10.1.1.123 2582
...
Coordinator agent process or thread ID = 340630
...
根據快照信息可以發現，PID 340630 就是負責對存儲過程的調用的 db2agent 進程。但是，由於這是一個 Java 存儲過程，默認情況下它將在一個 db2fmp 進程中作為一個隔離存儲過程運行。在 Windows 之類的支持線程的系統上，這將是一個線程 ID。
可以使用 db2pd -fmp 來發現代表 db2agent 執行該存儲過程的 db2fmp 進程。從下面的清單中可以看到，db2fmp PID 313092 中的線程 2571 (0xA0B) 正在為 db2agent PID 340630 運行 Java 存儲過程。
清單 17. 發現與應用程序關聯的 db2fmp 的 PID
/home/j2ma/sqllib/db2dump: db2pd -fmp
Database Partition 0 -- Active -- Up 0 days 00:00:30 -- Date 06/27/2007 15:22:43
FMP:
Pool Size: 0
Max Pool Size: 225
Keep FMP: YES
Initialized: YES
Trusted Path: /home/j2ma/sqllib/function/unfenced
Fenced User: j2ma
FMP Process:
Address FmpPid Bit Flags ActiveThrd PooledThrd Active
0x078000000016CEA0 313092 64 0x00000003 1 0 No
Active Threads:
Address FmpPid EduPid ThreadId
0x078000000016D020 313092 340630 2571
Pooled Threads:
Address FmpPid ThreadId
No pooled threads.
現在，我們知道哪個 PID 正在運行 db2fmp，如果它消耗太多的資源，我們可以終止它。如果想進一步調查，可以使用 db2pd -stacks 為每個 DB2 進程創建一個 trap 文件。或者，也可以發出 kill -36 313092。對於不同 UNIX 平台，為生成 trap 文件而發送的信號有所不同。
清單 18. 生成的 trap 文件 t313092.000
*******************************************
* A db2fmp process received a sigpre *
* signal *
*******************************************
* Master Thread TID: 00000001 *
* Waiter Thread TID: 00002314 *
* Number of worker threads in process 00000001 *
* db2fmp flags 0000000f *
* thread list *****************************
* Thread TID: 00002571 *
*******************************************
8.1.0.128 s061108 SQL08027
timestamp: 2007-06-27-15.39.55.254086
instance name: j2ma.000
EDU name : db2fmp (Java)
Signal #36
uname: S:AIX R:2 V:5 M:0009028F4C00 N:panipuri
process id: 313092
thread id : 2314 (0x90A)
...
...
<StackTrace>
-------Frame------ ------Function + Offset------
0x000000000000377C ?unknown + 0x0
0x090000000027B54C _event_sleep + 0x9C
0x090000000027BAB0 _event_wait + 0x60
0x0900000000287A5C _cond_wait_local + 0x308
0x0900000000287FD0 _cond_wait + 0x44
0x0900000000288848 pthread_cond_timedwait + 0x25C
0x09000000192C3478 sqloAppWaitOnSync + 0x19C
0x090000001954DACC sqle<ProcessObjects>
timestamp: 2007-06-27-15.39.56.253815
instance name: j2ma.000
EDU name : db2fmp (Java)
Signal #36
uname: S:AIX R:2 V:5 M:0009028F4C00 N:panipuri
process id: 313092
thread id : 258 (0x102)
kthread id : 397831
<StackTrace>
-------Frame------ ------Function + Offset------
0x000000000000377C ?unknown + 0x0
0x0900000000280724 _p_nsleep + 0xC
0x09000000000350B4 nsleep + 0xAC
0x0900000000040964 sleep + 0x58
0x090000001F9E1E50 sysSignalWait + 0x70
0x090000003170283C signalDispatcherThread + 0xE4
0x0900000031703C58 xmExecuteThread + 0x234
0x090000003170852C threadStart + 0x30
0x090000001F9CCEC4 _start + 0x64
0x0900000000271508 _pthread_body + 0xBC
</StackTrace>
這些棧提供的信息有限，因為存儲過程是獨立於 DB2 的、用於運行應用程序開發人員的代碼的過程。可以看到，DB2 調用 JVM 來執行 Java 存儲過程。進一步診斷應用程序的理想方法是，應用程序開發人員添加調試代碼到 Java 存儲過程中。另一種方法是為 db2fmp 生成一個 Javacore 文件，以提供附加的信息。
由於我們已經啟用了 Javacores，並且已經發現了執行存儲過程的 db2fmp 進程的 PID，因此現在可以生成一個 javacore。DB2 將把 javacore 文件轉儲到它的 db2diag.log 中，而不是一個單獨的 javacore 文件。必須使用 grep 命令解析 Javacore。
清單 19. 生成 Javacore 並解析 db2diag.log
$ kill -QUIT <PID of db2fmp>
$ grep MESSAGE /home/j2ma/sqllib/db2dump/db2diag.log >Javadump.txt
生成 javacore 之後，在 javacore 中搜索 native ID:0xA0B。記住，這是從 db2pd -fmp 輸出的線程 id，並從 2571（十進制）轉換為 0xA0B（十六進制）。線程 0xA0B 就是那個掛起的執行 Java 存儲過程的線程。在我們的應用程序中，它在第 31 行。查看 清單 21 中的源代碼，它在一個 while(1) 無限循環中。
清單 20.Javacore 文件
MESSAGE : JVMDG303: JVM Requesting Java core file
MESSAGE : NULL -----------------------------------------------------------------
MESSAGE : 0SECTION TITLE subcomponent dump routine
MESSAGE : NULL ===============================
MESSAGE : 1TISIGINFO signal 3 received
MESSAGE : 1TIDATETIME Date: 2007/06/27 at 15:24:58
MESSAGE : 1TIFILENAME Javacore filename: /db1/j2ma/Javacore313092.1182972298.txt
MESSAGE : 0SECTION XHPI subcomponent dump routine
MESSAGE : NULL ==============================
MESSAGE : 1XHTIME Wed Jun 27 15:24:58 2007
MESSAGE : 1XHSIGRECV SIGQUIT received at 0x7cdb02a639e00002 in <unknown>.
MESSAGE : 1XHFULLVERSION J2RE 1.4.2 IBM AIX 5L for PowerPC (64 bit JVM)
build caix64142-20040917
MESSAGE : NULL
...
...
MESSAGE : 1XMTHDINFO All Thread Details
MESSAGE : NULL ------------------
MESSAGE : NULL
MESSAGE : 2XMFULLTHDDUMP Full thread dump Classic VM (J2RE 1.4.2 IBM AIX 5L for PowerPC
(64 bit JVM) build caix64142-20040917, native threads):
MESSAGE : 3XMTHREADINFO "Thread-0" (TID:0x7000000000B8B78, sys_thread_t:0x1130B7340,
state:R, native ID:0xA0B) prio=5
MESSAGE : 4XESTACKTRACE at TEST_JAVASP.tEST_JAVASP(TEST_JAVASP.Java:31)
MESSAGE : 3XHNATIVESTACK Native Stack
MESSAGE : NULL ------------
...
清單 21.存儲過程的源代碼
1: /* Java stored procedure to insert a value into the database.
2: * It will hang if it receives the value 11.
3: * Inputs: input value (integer)
4: * Ouputs: None
5: */
6:
7:
8: import Java.sql.*;
9:
10: public class TEST_JavaSP
11: {
12: public static void tEST_JavaSP (int input) throws SQLException,
13: Exception
14: {
15: int errorCode;
16:
17: try
18: {
19: // get caller's connection to the database
20: Connection con = DriverManager.getConnection("jdbc:default:connection");
21:
22: String query = "INSERT INTO T1 (C1) VALUES (?)";
23:
24: PreparedStatement pstmt = con.prepareStatement(query);
25: pstmt.setInt(1, input);
26: pstmt.executeUpdate();
27:
28: /* Cause the stored proc to not return if input value is 11 */
29: if( input == 11)
30: {
31: while(true);
32: }
33: }
34: catch (SQLException sqle)
35: {
36: errorCode = sqle.getErrorCode();
37: throw new SQLException( errorCode + " FAILED" );
38: }
39: }
40: }
診斷 Java 應用程序的網絡問題
清單 22 在下面的環境中執行 JDBC 應用程序。由於某種未知的原因，這個 Java 應用程序好像掛起了。我們來看看是什麼問題。
客戶端：在 Windows DB2 v9.1 上運行的遺留的 JDBC Type 2 Application
服務器：AIX DB2 v8.x（存儲過程在這個系統上）
清單 22. 運行 Java 應用程序
D:java>java CallTestJavaSPT2 sample majason 12345678
URL is: jdbc:db2:p6db
Trying to connect using Legacy JDBC T2 driver
Connected to database
Inserting value 9 into database...
Done inserting value 9
Inserting value 10 into database...
Done inserting value 10
Inserting value 11 into database...
(Ctrl-C executed from clIEnt side after a few seconds since the program above seems
to hang and never return.)
首先要做的是收集客戶端或者運行該應用程序的系統上的跟蹤。從 圖 1 可以看到，JDBC Type 2 應用程序在到達 DB2 客戶端代碼之前先經過 DB2 的 CLI 層。因此我們收集一個並發的 CLI、DB2 和 DRDA 跟蹤，並且 CLI 和 DB2 跟蹤啟用時間戳選項。
CLI 跟蹤顯示，我們正使用一個參數占位符調用 CALL TEST_JavaSP(?) 存儲過程。這個存儲過程被使用不同的值調用了三次。可以看到，參數占位符 ? 被綁定一次，然後 SQL 語句執行三次，因為在 SQLBindParameter() 之後有三個對 SQLExecute() 的調用。每當 SQLExecute() 被調用時，可以看到用於參數占位符的值。這個值被標記為 iPar（輸入參數編號）和 rgbValue （輸入參數值）。所以，對於第一次迭代，rgbValue=9，接著是 rgbValue=10，最後是 rgbValue=11，正是在這個地方應用程序掛起。
清單 23. CLI 跟蹤，輸入值 rgbValue=9
...
[1184187845.736027 - 07/11/2007 17:04:05.736027]
SQLPrepareW( hStmt=1:1, pszSqlStr="CALL TEST_JavaSP(?)", cbSqlStr=19 )
[1184187845.748055 - 07/11/2007 17:04:05.748055]
---> Time elapsed - +5.700000E-003 seconds
[1184187845.752649 - 07/11/2007 17:04:05.752649] ( StmtOut="CALL TEST_JavaSP(?)" )
[1184187845.758786 - 07/11/2007 17:04:05.758786]
[1184187845.761948 - 07/11/2007 17:04:05.761948] SQLPrepareW( )
[1184187845.765148 - 07/11/2007 17:04:05.765148]
<--- SQL_SUCCESS Time elapsed - +2.912100E-002 seconds
[1184187845.768377 - 07/11/2007 17:04:05.768377] SQLNumParams( hStmt=1:1, pcPar=&0007f994)
[1184187845.777452 - 07/11/2007 17:04:05.777452]
---> Time elapsed - +3.229000E-003 seconds
[1184187845.780470 - 07/11/2007 17:04:05.780470] SQLNumParams( pcPar=1 )
[1184187845.786270 - 07/11/2007 17:04:05.786270]
<--- SQL_SUCCESS Time elapsed - +1.789300E-002 seconds
[1184187845.802512 - 07/11/2007 17:04:05.802512] SQLBindParameter( hStmt=1:1, iPar=1,
fParamType=SQL_PARAM_INPUT, fCType=SQL_C_LONG, fSQLType=SQL_INTEGER, cbColDef=0,
ibScale=0, rgbValue=&0b7bb808, cbValueMax=4, pcbValue=&0b7bb804 )
[1184187845.835867 - 07/11/2007 17:04:05.835867]
---> Time elapsed - +1.624200E-002 seconds
[1184187845.839286 - 07/11/2007 17:04:05.839286] SQLBindParameter( )
[1184187845.842363 - 07/11/2007 17:04:05.842363]
<--- SQL_SUCCESS Time elapsed - +3.985100E-002 seconds
[1184187845.845624 - 07/11/2007 17:04:05.845624] SQLExecute( hStmt=1:1 )
[1184187845.851609 - 07/11/2007 17:04:05.851609]
---> Time elapsed - +3.261000E-003 seconds
[1184187845.854865 - 07/11/2007 17:04:05.854865]
( Package="SYSSH200 ", Section=4 )
[1184187845.863376 - 07/11/2007 17:04:05.863376]
[1184187845.880312 - 07/11/2007 17:04:05.880312]
( Row=1, iPar=1, fCType=SQL_C_LONG, rgbValue=9, pcbValue=4, piIndicatorPtr=4 )
[1184187845.901568 - 07/11/2007 17:04:05.901568]
sqlccsend( Handle - 192938080 )
sqlccsend( ulBytes - 435 )
sqlccsend( ) rc - 0, time elASPed - +7.000000E-005
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 198 ) - rc - 0, time elapsed - +3.571100E-001
[1184187846.270909 - 07/11/2007 17:04:06.270909] ( return=0 )
[1184187846.277250 - 07/11/2007 17:04:06.277250]
[1184187846.280375 - 07/11/2007 17:04:06.280375] ( COMMIT REQUESTED=1 )
[1184187846.286339 - 07/11/2007 17:04:06.286339]
sqlccsend( Handle - 192938080 )
sqlccsend( ulBytes - 10 )
sqlccsend( ) rc - 0, time elASPed - +6.400000E-005
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 54 ) - rc - 0, time elapsed - +4.342000E-003
[1184187846.306069 - 07/11/2007 17:04:06.306069] ( COMMIT REPLY RECEIVED=1 )
[1184187846.312165 - 07/11/2007 17:04:06.312165]
[1184187846.315283 - 07/11/2007 17:04:06.315283] SQLExecute( )
[1184187846.318434 - 07/11/2007 17:04:06.318434]
<--- SQL_SUCCESS Time elapsed - +4.728100E-001 seconds
清單 24. CLI 跟蹤，輸入值 rgbValue=10
...
[1184187846.369625 - 07/11/2007 17:04:06.369625] SQLExecute( hStmt=1:1 )
[1184187846.375663 - 07/11/2007 17:04:06.375663]
---> Time elapsed - +6.313000E-003 seconds
[1184187846.378759 - 07/11/2007 17:04:06.378759]
( Row=1, iPar=1, fCType=SQL_C_LONG, rgbValue=10, pcbValue=4, piIndicatorPtr=4 )
[1184187846.401220 - 07/11/2007 17:04:06.401220]
sqlccsend( Handle - 192938080 )
sqlccsend( ulBytes - 157 )
sqlccsend( ) rc - 0, time elASPed - +6.700000E-005
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 80 ) - rc - 0, time elapsed - +8.489000E-003
[1184187846.422672 - 07/11/2007 17:04:06.422672] ( return=0 )
[1184187846.428435 - 07/11/2007 17:04:06.428435]
[1184187846.432088 - 07/11/2007 17:04:06.432088] ( COMMIT REQUESTED=1 )
[1184187846.438348 - 07/11/2007 17:04:06.438348]
sqlccsend( Handle - 192938080 )
sqlccsend( ulBytes - 10 )
sqlccsend( ) rc - 0, time elASPed - +6.100000E-005
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 54 ) - rc - 0, time elapsed - +3.608000E-003
[1184187846.454256 - 07/11/2007 17:04:06.454256] ( COMMIT REPLY RECEIVED=1 )
[1184187846.460343 - 07/11/2007 17:04:06.460343]
[1184187846.464846 - 07/11/2007 17:04:06.464846] SQLExecute( )
[1184187846.468118 - 07/11/2007 17:04:06.468118]
<--- SQL_SUCCESS Time elapsed - +9.849300E-002 seconds
...
...
清單 25. CLI 跟蹤，輸入值 rgbValue=11
...
[1184187846.519822 - 07/11/2007 17:04:06.519822] SQLExecute( hStmt=1:1 )
[1184187846.526027 - 07/11/2007 17:04:06.526027]
---> Time elapsed - +6.523000E-003 seconds
[1184187846.529060 - 07/11/2007 17:04:06.529060]
( Row=1, iPar=1, fCType=SQL_C_LONG, rgbValue=11, pcbValue=4, piIndicatorPtr=4 )
[1184187846.549404 - 07/11/2007 17:04:06.549404]
sqlccsend( Handle - 192938080 )
sqlccsend( ulBytes - 157 )
sqlccsend( ) rc - 0, time elASPed - +7.100000E-005
sqlccrecv( timeout - +0.000000E+000 )
在第三次迭代期間，CLI 跟蹤在 SQLExecute() 之後終止。下一步是簡化和去掉應用程序。可以創建一個 DB2 腳本來做同樣的工作。
清單 26. test.db2
connect to sample user db2inst1 using 12345678;
call test_Javasp(9);
call test_Javasp(10);
call test_Javasp(11);
terminate;
在服務器端執行該腳本可以幫助確定問題是在客戶端還是服務器端。如果該腳本在客戶端運行得很好，那麼應該在服務器端運行它。如果它在服務器端運行時掛起，那麼需要調查存儲過程。
