问题:
最近遇到一个问题,Db2应用状态是UOW Waiting,但Most recent operation是Fetch,并且Rows fetched在不断增加,于是模拟了这一现象。
完整的应用快照如下:
inst105@NODE01:~> db2 get snapshot for application agentid 27385
Application Snapshot
Application handle = 27385
Application status = UOW Waiting
Status change time = 05/21/2020 13:38:24.897981
Application code page = 1208
Application country/region code = 0
DUOW correlation token = 197.0.0.1.45730.200521052846
Application name = db2jcc_application
Application ID = 197.0.0.1.45730.200521052846
Sequence number = 00002
TP Monitor client user ID =
TP Monitor client workstation name = 197.0.0.1
TP Monitor client application name =
TP Monitor client accounting string =
Connection request start timestamp = 05/21/2020 13:28:44.273888
Connect request completion timestamp = 05/21/2020 13:28:44.274760
Application idle time = 6 seconds
CONNECT Authorization ID = inst105
Client login ID = inst105
Configuration NNAME of client = 197.0.0.1
Client database manager product ID = JCC03690
Process ID of client application = 0
Platform of client application = Unknown via DRDA
Communication protocol of client = TCP/IP
Inbound communication address = 197.0.0.1 45730
Database name = SAMPLE
Database path = /home/inst105/inst105/NODE0000/SQL00001/MEMBER0000/
Client database alias = SAMPLE
Input database alias =
Last reset timestamp =
Snapshot timestamp = 05/21/2020 13:38:30.142379
Authorization level granted =
User authority:
DBADM authority
SECADM authority
DATAACCESS authority
ACCESSCTRL authority
Group authority:
SYSADM authority
SYSMAINT authority
CREATETAB authority
BINDADD authority
CONNECT authority
IMPLICIT_SCHEMA authority
SYSMON authority
Coordinator member number = 0
Current member number = 0
Coordinator agent process or thread ID = 11759
Current Workload ID = 1
Agents stolen = 0
Agents waiting on locks = 0
Maximum associated agents = 1
Priority at which application agents work = 0
Priority type = Dynamic
Lock timeout (seconds) = -1
Locks held by application = 3
Lock waits since connect = 0
Time application waited on locks (ms) = 0
Deadlocks detected = 0
Lock escalations = 0
Exclusive lock escalations = 0
Number of Lock Timeouts since connected = 0
Total time UOW waited on locks (ms) = 0
Total sorts = 0
Total sort time (ms) = 0
Total sort overflows = 0
Buffer pool data logical reads = 6
Buffer pool data physical reads = 0
Buffer pool temporary data logical reads = 0
Buffer pool temporary data physical reads = 0
Buffer pool data writes = 0
Buffer pool index logical reads = 4
Buffer pool index physical reads = 0
Buffer pool temporary index logical reads = 0
Buffer pool temporary index physical reads = 0
Buffer pool index writes = 0
Buffer pool xda logical reads = 0
Buffer pool xda physical reads = 0
Buffer pool temporary xda logical reads = 0
Buffer pool temporary xda physical reads = 0
Buffer pool xda writes = 0
Total buffer pool read time (milliseconds) = 0
Total buffer pool write time (milliseconds)= 0
Time waited for prefetch (ms) = 0
Unread prefetch pages = 0
Direct reads = 0
Direct writes = 0
Direct read requests = 0
Direct write requests = 0
Direct reads elapsed time (ms) = 0
Direct write elapsed time (ms) = 0
Number of SQL requests since last commit = 61
Commit statements = 1
Rollback statements = 0
Dynamic SQL statements attempted = 1
Static SQL statements attempted = 1
Failed statement operations = 1
Select SQL statements executed = 1
Xquery statements executed = 0
Update/Insert/Delete statements executed = 0
DDL statements executed = 0
Inactive stmt history memory usage (bytes) = 0
Internal automatic rebinds = 0
Internal rows deleted = 0
Internal rows inserted = 0
Internal rows updated = 0
Internal commits = 1
Internal rollbacks = 0
Internal rollbacks due to deadlock = 0
Binds/precompiles attempted = 0
Rows deleted = 0
Rows inserted = 0
Rows updated = 0
Rows selected = 590
Rows read = 590
Rows written = 0
UOW log space used (Bytes) = 0
Previous UOW completion timestamp = 05/21/2020 13:28:44.390162
Elapsed time of last completed uow (sec.ms)= 0.022277
UOW start timestamp = 05/21/2020 13:28:44.398776
UOW stop timestamp =
UOW completion status =
Open remote cursors = 1
Open remote cursors with blocking = 1
Rejected Block Remote Cursor requests = 0
Accepted Block Remote Cursor requests = 1
Open local cursors = 0
Open local cursors with blocking = 0
Total User CPU Time used by agent (s) = 0.057733
Total System CPU Time used by agent (s) = 0.000000
Host execution elapsed time = 0.003211
Package cache lookups = 1
Package cache inserts = 0
Application section lookups = 61
Application section inserts = 0
Catalog cache lookups = 30
Catalog cache inserts = 0
Catalog cache overflows = 0
Catalog cache high water mark = 0
Workspace Information
Most recent operation = Fetch
Cursor name = SQL_CURSH200C1
Most recent operation start timestamp = 05/21/2020 13:28:44.399010
Most recent operation stop timestamp = 05/21/2020 13:38:24.897980
Agents associated with the application = 1
Number of hash joins = 0
Number of hash loops = 0
Number of hash join overflows = 0
Number of small hash join overflows = 0
Number of OLAP functions = 0
Number of OLAP function overflows = 0
Statement type = Dynamic SQL Statement
Statement = Fetch
Section number = 1
Application creator = NULLID
Package name = SYSSH200
Consistency Token =
Package Version ID =
Cursor name = SQL_CURSH200C1
Statement member number = 0
Statement start timestamp = 05/21/2020 13:28:44.399010
Statement stop timestamp = 05/21/2020 13:38:24.897980
Elapsed time of last completed stmt(sec.ms)= 0.000104
Total Statement user CPU time = 0.053066
Total Statement system CPU time = 0.000000
SQL compiler cost estimate in timerons = 81
SQL compiler cardinality estimate = 10000
Degree of parallelism requested = 1
Number of agents working on statement = 1
Number of subagents created for statement = 1
Statement sorts = 0
Total sort time = 0
Sort overflows = 0
Rows read = 590
Rows written = 0
Internal rows deleted = 0
Internal rows updated = 0
Internal rows inserted = 0
Rows fetched = 590
Buffer pool data logical reads = 6
Buffer pool data physical reads = 0
Buffer pool temporary data logical reads = 0
Buffer pool temporary data physical reads = 0
Buffer pool index logical reads = 0
Buffer pool index physical reads = 0
Buffer pool temporary index logical reads = 0
Buffer pool temporary index physical reads = 0
Buffer pool xda logical reads = 0
Buffer pool xda physical reads = 0
Buffer pool temporary xda logical reads = 0
Buffer pool temporary xda physical reads = 0
Blocking cursor = YES
Dynamic SQL statement text:
select * from t1_bak
Agent process/thread ID = 11759
Memory usage for application:
Memory Pool Type = Application Heap
Current size (bytes) = 131072
High water mark (bytes) = 131072
Configured size (bytes) = 1048576
Agent process/thread ID = 11759
Agent Lock timeout (seconds) = -1
Memory usage for agent:
Memory Pool Type = Other Memory
Current size (bytes) = 327680
High water mark (bytes) = 524288
Configured size (bytes) = 3741052928
过一小会再次查看快照,发现Rows fetch会发生变化,如下:
inst105@NODE01:~> db2 get snapshot for application agentid 27385
Application Snapshot
Application handle = 27385
Application status = UOW Waiting
Status change time = 05/21/2020 13:39:14.925468
Application code page = 1208
Application country/region code = 0
DUOW correlation token = 197.0.0.1.45730.200521052846
Application name = db2jcc_application
Application ID = 197.0.0.1.45730.200521052846
Sequence number = 00002
TP Monitor client user ID =
TP Monitor client workstation name = 197.0.0.1
TP Monitor client application name =
TP Monitor client accounting string =
Connection request start timestamp = 05/21/2020 13:28:44.273888
Connect request completion timestamp = 05/21/2020 13:28:44.274760
Application idle time = 5 seconds
CONNECT Authorization ID = inst105
Client login ID = inst105
Configuration NNAME of client = 197.0.0.1
Client database manager product ID = JCC03690
Process ID of client application = 0
Platform of client application = Unknown via DRDA
Communication protocol of client = TCP/IP
Inbound communication address = 197.0.0.1 45730
Database name = SAMPLE
Database path = /home/inst105/inst105/NODE0000/SQL00001/MEMBER0000/
Client database alias = SAMPLE
Input database alias =
Last reset timestamp =
Snapshot timestamp = 05/21/2020 13:39:19.321331
Authorization level granted =
User authority:
DBADM authority
SECADM authority
DATAACCESS authority
ACCESSCTRL authority
Group authority:
SYSADM authority
SYSMAINT authority
CREATETAB authority
BINDADD authority
CONNECT authority
IMPLICIT_SCHEMA authority
SYSMON authority
Coordinator member number = 0
Current member number = 0
Coordinator agent process or thread ID = 11759
Current Workload ID = 1
Agents stolen = 0
Agents waiting on locks = 0
Maximum associated agents = 1
Priority at which application agents work = 0
Priority type = Dynamic
Lock timeout (seconds) = -1
Locks held by application = 3
Lock waits since connect = 0
Time application waited on locks (ms) = 0
Deadlocks detected = 0
Lock escalations = 0
Exclusive lock escalations = 0
Number of Lock Timeouts since connected = 0
Total time UOW waited on locks (ms) = 0
Total sorts = 0
Total sort time (ms) = 0
Total sort overflows = 0
Buffer pool data logical reads = 6
Buffer pool data physical reads = 0
Buffer pool temporary data logical reads = 0
Buffer pool temporary data physical reads = 0
Buffer pool data writes = 0
Buffer pool index logical reads = 4
Buffer pool index physical reads = 0
Buffer pool temporary index logical reads = 0
Buffer pool temporary index physical reads = 0
Buffer pool index writes = 0
Buffer pool xda logical reads = 0
Buffer pool xda physical reads = 0
Buffer pool temporary xda logical reads = 0
Buffer pool temporary xda physical reads = 0
Buffer pool xda writes = 0
Total buffer pool read time (milliseconds) = 0
Total buffer pool write time (milliseconds)= 0
Time waited for prefetch (ms) = 0
Unread prefetch pages = 0
Direct reads = 0
Direct writes = 0
Direct read requests = 0
Direct write requests = 0
Direct reads elapsed time (ms) = 0
Direct write elapsed time (ms) = 0
Number of SQL requests since last commit = 66
Commit statements = 1
Rollback statements = 0
Dynamic SQL statements attempted = 1
Static SQL statements attempted = 1
Failed statement operations = 1
Select SQL statements executed = 1
Xquery statements executed = 0
Update/Insert/Delete statements executed = 0
DDL statements executed = 0
Inactive stmt history memory usage (bytes) = 0
Internal automatic rebinds = 0
Internal rows deleted = 0
Internal rows inserted = 0
Internal rows updated = 0
Internal commits = 1
Internal rollbacks = 0
Internal rollbacks due to deadlock = 0
Binds/precompiles attempted = 0
Rows deleted = 0
Rows inserted = 0
Rows updated = 0
Rows selected = 640
Rows read = 640
Rows written = 0
UOW log space used (Bytes) = 0
Previous UOW completion timestamp = 05/21/2020 13:28:44.390162
Elapsed time of last completed uow (sec.ms)= 0.022277
UOW start timestamp = 05/21/2020 13:28:44.398776
UOW stop timestamp =
UOW completion status =
Open remote cursors = 1
Open remote cursors with blocking = 1
Rejected Block Remote Cursor requests = 0
Accepted Block Remote Cursor requests = 1
Open local cursors = 0
Open local cursors with blocking = 0
Total User CPU Time used by agent (s) = 0.062408
Total System CPU Time used by agent (s) = 0.000000
Host execution elapsed time = 0.003211
Package cache lookups = 1
Package cache inserts = 0
Application section lookups = 66
Application section inserts = 0
Catalog cache lookups = 30
Catalog cache inserts = 0
Catalog cache overflows = 0
Catalog cache high water mark = 0
Workspace Information
Most recent operation = Fetch
Cursor name = SQL_CURSH200C1
Most recent operation start timestamp = 05/21/2020 13:28:44.399010
Most recent operation stop timestamp = 05/21/2020 13:39:14.925466
Agents associated with the application = 1
Number of hash joins = 0
Number of hash loops = 0
Number of hash join overflows = 0
Number of small hash join overflows = 0
Number of OLAP functions = 0
Number of OLAP function overflows = 0
Statement type = Dynamic SQL Statement
Statement = Fetch
Section number = 1
Application creator = NULLID
Package name = SYSSH200
Consistency Token =
Package Version ID =
Cursor name = SQL_CURSH200C1
Statement member number = 0
Statement start timestamp = 05/21/2020 13:28:44.399010
Statement stop timestamp = 05/21/2020 13:39:14.925466 <-----
Elapsed time of last completed stmt(sec.ms)= 0.000106
Total Statement user CPU time = 0.057741
Total Statement system CPU time = 0.000000
SQL compiler cost estimate in timerons = 81
SQL compiler cardinality estimate = 10000
Degree of parallelism requested = 1
Number of agents working on statement = 1
Number of subagents created for statement = 1
Statement sorts = 0
Total sort time = 0
Sort overflows = 0
Rows read = 640
Rows written = 0
Internal rows deleted = 0
Internal rows updated = 0
Internal rows inserted = 0
Rows fetched = 640 <-----
Buffer pool data logical reads = 6
Buffer pool data physical reads = 0
Buffer pool temporary data logical reads = 0
Buffer pool temporary data physical reads = 0
Buffer pool index logical reads = 0
Buffer pool index physical reads = 0
Buffer pool temporary index logical reads = 0
Buffer pool temporary index physical reads = 0
Buffer pool xda logical reads = 0
Buffer pool xda physical reads = 0
Buffer pool temporary xda logical reads = 0
Buffer pool temporary xda physical reads = 0
Blocking cursor = YES
Dynamic SQL statement text:
select * from t1_bak
Agent process/thread ID = 11759
Memory usage for application:
Memory Pool Type = Application Heap
Current size (bytes) = 131072
High water mark (bytes) = 131072
Configured size (bytes) = 1048576
Agent process/thread ID = 11759
Agent Lock timeout (seconds) = -1
Memory usage for agent:
Memory Pool Type = Other Memory
Current size (bytes) = 327680
High water mark (bytes) = 524288
Configured size (bytes) = 3741052928
每隔几秒钟看一次Rows Fetched,会发现每次都增加10:
inst105@NODE01:~> db2 get snapshot for application agentid 27385 | grep -i "Rows fetched"
Rows fetched = 1440
inst105@NODE01:~> db2 get snapshot for application agentid 27385 | grep -i "Rows fetched"
Rows fetched = 1440
inst105@NODE01:~> db2 get snapshot for application agentid 27385 | grep -i "Rows fetched"
Rows fetched = 1450
inst105@NODE01:~> db2 get snapshot for application agentid 27385 | grep -i "Rows fetched"
Rows fetched = 1450
inst105@NODE01:~> db2 get snapshot for application agentid 27385 | grep -i "Rows fetched"
Rows fetched = 1450
inst105@NODE01:~> db2 get snapshot for application agentid 27385 | grep -i "Rows fetched"
Rows fetched = 1460
下面是模拟上面问题的java程序的核心代码:
PreparedStatement ps = conn.prepareStatement("select * from t1_bak");
ps.setFetchSize(10);
ResultSet rs = ps.executeQuery();
while (rs.next())
{
int id = rs.getInt("ID");
String name = rs.getString("NAME");
System.out.println("ID: " + id );
System.out.println("NAME: " + name);
System.out.println("-------------------");
Thread.sleep(1000);
}
可以看到,setFetchSize设置了每次取10条记录,所以我们看到快照中Rows Fetched每次变化都是增加10。每次读取完一条数据之后休息1秒,这样我们有时间查看快照,观察变化。