使用TraceMon分析TimesTen查詢最大連續記憶體塊瞬間Hang問題

在TimesTen的維護中，監控TimesTen剩餘的最大連續記憶體塊是非常有必要的，但是Oracle在TimesTen中只提供了有一個儲存過程來 檢視TimesTen記憶體資料庫的剩餘最大連續空閒記憶體段，而且該儲存過程還會引起記憶體資料庫瞬間Hang住，我們都知道TimesTen一般承載的業務 都是實時性要求非常高的，這種瞬間Hang住有可能會造成業務影響，所以我們在維護過程中要儘可能的避免頻繁的檢視TimesTen的剩餘最大連續空閒內 存段，而且採用監控記憶體使用情況，在記憶體變化較大時再去檢視剩餘最大連續空閒記憶體段。

在廣東移動的運維期間就出現過由於定期的監控剩餘最大連續空閒記憶體段，造成對業務的影響。
下面透過TimesTen提供的TraceMon工具分析檢視剩餘最大連續空閒記憶體段引起瞬間Hang的原因：
1、檢視剩餘最大連續空閒記憶體段的方式
call ttblockinfo;
2、使用TraceMon工具Debug跟蹤call ttblockinfo的執行過程
---開啟latch的level 4
$ tttracemon tytt
Trace monitor; empty line to exit
Trace> flush
Trace> dump
0 records dumped
Trace> level sql 4
Trace> level latch 6
Trace> level xact 4
Trace> outfile 1.log
---在新視窗中執行查詢剩餘最大連續空閒記憶體段
Command> call ttblockinfo;
< 111, 1, 130092264, 130092264 >
1 row found.
---進入TraceMon，關閉Trace
Trace> flush
Trace> outfile 0;
Trace> level sql 0
Trace> level latch 0
Trace> level xact 0
Trace> show
AGING        ... 0
API          ... 0
ASYNCMV      ... 0
AUTOREFRESH  ... 0
CG           ... 0
CGRID        ... 0
CGRIDC       ... 0
CKPT         ... 0
DBG0         ... 0
DBG1         ... 0
DEADLOCK     ... 1
EE           ... 0
ERR          ... 1
FLOW         ... 0
HEAP         ... 0
IX           ... 0
IXGC         ... 0
LATCH        ... 0
LOB          ... 0
LOCK         ... 0
LOG          ... 0
LOGF         ... 0
MEM          ... 0
OPT          ... 0
ORACON       ... 0
PLOAD        ... 0
PREP         ... 0
PT           ... 0
REPL         ... 0
SM           ... 0
SQL          ... 0
TEST         ... 0
TRACE        ... 0
XA           ... 0
XACT         ... 0
INTERRUPT    ... 0
Trace>
3、下面來看一下Debug的輸出
13:36:43.804    1379 LATCH    4L    2C   3544P sbHeapLatchGet 0x2aaab7f12378 ok
13:36:43.804    1380 LATCH    4L    2C   3544P sbLockBucketLatchGet 0x085f43d8 ok
13:36:43.804    1381 LATCH    4L    2C   3544P sbHeapLatchGet 0x2aaab7f12378 ok
13:36:43.804    1382 XACT     3L    2C   3544P sbXactCommit(E): xactId: 2.3 cacheUpdate: 0 xact.c:6137
13:36:43.804    1383 XACT     3L    2C   3544P sbXactBegin(E): xactId: 2.4
13:36:43.804    1384 LATCH    4L    2C   3544P sbLockBucketLatchGet 0x08603648 ok
13:36:43.804    1385 LATCH    4L    2C   3544P sbInternalLockLatchGet 0x2aaab8527ef8 ok
13:36:43.804    1386 SQL      4L    2C   3544P execEnvGet: Got preallocated env 140887960
13:36:43.804    1387 SQL      3L    2C   3544P Opening: call ttblockinfo
13:36:43.804    1388 LATCH    4L    2C   3544P sbDbLatchGet 0x2aaaaacd0f78 ok                     <====DB latch get
13:36:43.821    1389 LATCH    4L    2C   3544P sbPermAllocLatchGet 0x2aaaaacd12b8 ok
13:36:43.821    1390 SQL      4L    2C   3544P Fetching: call ttblockinfo
13:36:43.832    1391 SQL      4L    2C   3544P Fetching: call ttblockinfo
13:36:43.832    1392 SQL      4L    2C   3544P Closing: call ttblockinfo
13:36:43.832    1393 LATCH    5L    2C   3544P sbDbLatchRel 0x2aaaaacd0f78 ok                     <====DB latch get
13:36:43.832    1394 SQL      4L    2C   3544P sbEeEnvRet: Returned env 140887960
13:36:43.832    1395 LATCH    4L    2C   3544P sbLockBucketLatchGet 0x08603648 ok
13:36:43.832    1396 XACT     3L    2C   3544P sbXactCommit(E): xactId: 2.4 cacheUpdate: 0 xact.c:6137
13:36:43.832    1397 XACT     3L    2C   3544P sbXactBegin(E): xactId: 2.5
13:36:43.832    1398 XACT     3L    2C   3544P sbXactCommit(E): xactId: 2.5 cacheUpdate: 0 xact.c:6137
13:36:43.901    1399 LATCH    4L  135C   3401P sbLogStrandInserterLatchGet 0x2aaab823c7b0 ok
13:36:43.901    1400 LATCH    4L  135C   3401P sbLogBufFlushinfoLatchGet 0x2aaaaacd3338 ok
13:36:44.003    1401 LATCH    4L  135C   3401P sbLogStrandInserterLatchGet 0x2aaab823c7b0 ok
13:36:44.003    1402 LATCH    4L  135C   3401P sbLogBufFlushinfoLatchGet 0x2aaaaacd3338 ok
13:36:44.110    1403 LATCH    4L  135C   3401P sbLogStrandInserterLatchGet 0x2aaab823c7b0 ok

可以看到執行call ttblockinfo時，需要持有DbLatch，這樣所有需要申請記憶體訪問的請求都將會等待。
注：TraceMon非常耗資源，特別是CPU，所以在生產系統中要謹慎，儘量避免整庫Debug，可以採用單個連線進行Debug的方式。
=======================End========================================