為了客觀、準確、有效地評估 TDengine 3.0 的性能指標,我們決定使用 TSBS(Time Series Benchmark Suite)作為基準性能測試平臺,針對 DevOps 場景的數據集對 TDengine 3.0 展開整體(包括寫入、查詢、存儲、資源消耗等)性能評估。 ...
[20230228]產生大量日誌分析(生產系統日誌分析).txt
--//生產系統優化已經基本完成,我發現這套系統日誌產生非常大對比我以前管理優化類似的項目.
--//一直沒時間,今天有空簡單探究看看.
1.環境:
[email protected]:1521/orcl> @ pr
==============================
PORT_STRING : x86_64/Linux 2.4.xx
VERSION : 19.0.0.0.0
BANNER : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
BANNER_FULL : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0
BANNER_LEGACY : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
CON_ID : 0
PL/SQL procedure successfully completed.
2.問題提出:
[email protected]:1521/orcl> @ ashtop event 1=1 &day
Total Distinct Distinct
Seconds AAS %This EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps
--------- ------- ------- ---------------------------- ------------------- ------------------- ---------- --------
16362 .2 51% | 2023-02-26 10:48:20 2023-02-27 10:47:57 8620 14724
3584 .0 11% | log file sync 2023-02-26 10:48:12 2023-02-27 10:48:07 1 2799
3214 .0 10% | log file parallel write 2023-02-26 10:48:12 2023-02-27 10:48:07 1 2738
2874 .0 9% | RMAN backup & recovery I/O 2023-02-26 23:53:59 2023-02-27 02:31:08 1 2862
2718 .0 8% | db file sequential read 2023-02-26 10:48:41 2023-02-27 10:47:54 1769 2614
893 .0 3% | db file parallel read 2023-02-26 10:49:56 2023-02-27 10:48:08 514 877
--//log file sync 排在第一,log file parallel write第2,說明寫入redo很多.
--//RMAN 備份主要原因是增量備份沒有打開塊跟蹤,以及archive log重覆備份的問題.
[email protected]:1521/orcl> @ d_arc
DATE WEEK SIZE_MB NUMBER_OF_SWITCHES_PER_DAY
------------- ------------- ---------- --------------------------
2023-02-27 09 MONDAY 2984 6 --//當天
2023-02-26 09 SUNDAY 4381 8
2023-02-25 08 SATURDAY 5488 10
2023-02-24 08 FRIDAY 6773 11
2023-02-23 08 THURSDAY 7236 12
2023-02-22 08 WEDNESDAY 7832 12
2023-02-21 08 TUESDAY 7978 12
2023-02-20 08 MONDAY 6940 11
2023-02-19 08 SUNDAY 4293 8
2023-02-18 07 SATURDAY 5216 9
...
--//可以看出每天正常業務基本在6G上下.實際上以前類似系統僅僅1.XG上下(順便說一下當時系統日誌實際上還是偏大的).對比幾乎增加
--//4-5倍.實際上我提出來團隊的人根本不當一回事.
--//我仔細看了redo dump,日誌的產生主要集中在表LIS.LIS_RESULT.仔細查看我才發現開發編程上的問題.開發太不瞭解oracle資料庫了.
--//一些細節慢慢展開....
3.分析:
[email protected]:1521/orcl> @ cs lis
alter session set current_schema=lis
Session altered.
$ cat aa1.txt
set numw 12
column id new_value v_id
column item_id new_value v_item_id
column scn1 new_value v_scn1
column scn2 new_value v_scn2
set term off
--select current_scn-1e4 scn1 from v$database;
select id,max(item_id) item_id from LIS_RESULT where id = (select max(id) from LIS_RESULT ) group by id;
host sleep &&1
--select current_scn scn2 from v$database;
set term on
SELECT versions_starttime
,versions_endtime
,versions_xid
,versions_operation
,versions_startscn
,versions_endscn
,lis_result.id
,lis_result.item_id
--FROM LIS_RESULT VERSIONS BETWEEN scn &v_scn1 and &v_scn2
FROM LIS_RESULT VERSIONS BETWEEN TIMESTAMP sysdate-1/1440 and sysdate
WHERE id = &&v_id and item_id = &&v_item_id
-- order by VERSIONS_STARTSCN
;
--//註:選擇sleep N一定時間,可能是IMU導致的情況,如果輸入0可能出現看不到update的執行.
--//正常情況選擇3秒比較穩妥.
--//另外說明欄位id,item_id組成主鍵.
[email protected]:1521/orcl> @ aa1.txt 3
VERSIONS_STARTTIME VERSIONS_ENDTIME VERSIONS_XID V VERSIONS_STARTSCN VERSIONS_ENDSCN ID ITEM_ID
-------------------- -------------------- ---------------- - ----------------- --------------- ------------ ------------
2023-03-01 09:07:46. 0C001E00889B1E00 U 44616129592 26961471 7075
2023-03-01 09:07:46. 2023-03-01 09:07:46. 08001F0043E61600 I 44616129291 44616129592 26961471 7075
[email protected]:1521/orcl> @ aa1.txt 3
VERSIONS_STARTTIME VERSIONS_ENDTIME VERSIONS_XID V VERSIONS_STARTSCN VERSIONS_ENDSCN ID ITEM_ID
-------------------- -------------------- ---------------- - ----------------- --------------- ------------ ------------
2023-03-01 09:07:52. 0C000A00909B1E00 U 44616131159 26961475 3791
2023-03-01 09:07:49. 2023-03-01 09:07:52. 0C000F00EF9A1E00 I 44616130857 44616131159 26961475 3791
[email protected]:1521/orcl> @ aa1.txt 3
VERSIONS_STARTTIME VERSIONS_ENDTIME VERSIONS_XID V VERSIONS_STARTSCN VERSIONS_ENDSCN ID ITEM_ID
-------------------- -------------------- ---------------- - ----------------- --------------- ------------ ------------
2023-03-01 09:08:49. 02000100EDE51300 U 44616150499 26961554 7436
2023-03-01 09:08:46. 2023-03-01 09:08:49. 05000B0042F01500 I 44616150170 44616150499 26961554 7436
--//相差3秒.
[email protected]:1521/orcl> @ aa1.txt 3
VERSIONS_STARTTIME VERSIONS_ENDTIME VERSIONS_XID V VERSIONS_STARTSCN VERSIONS_ENDSCN ID ITEM_ID
-------------------- -------------------- ---------------- - ----------------- --------------- ------------ ------------
2023-03-01 09:09:52. 0C001900379C1E00 U 44616170991 26961673 3431
2023-03-01 09:09:52. 2023-03-01 09:09:52. 0100110024371600 I 44616170950 44616170991 26961673 3431
--//看versions_operation列,先insert然後update,看VERSIONS_STARTTIME列幾乎在同一個時間點完成或者相差3秒馬上修改.
--//不知道3秒是否是IMU的影響.我執行許多次要麼相差3秒,要麼基本相差0.
--//修改如下,註解item_id = &&v_item_id.
$ cat aa1.txt
set numw 12
column id new_value v_id
column item_id new_value v_item_id
column scn1 new_value v_scn1
column scn2 new_value v_scn2
set term off
select current_scn-1e4 scn1 from v$database;
select id,max(item_id) item_id from LIS_RESULT where id = (select max(id) from LIS_RESULT ) group by id;
host sleep &&1
select current_scn scn2 from v$database;
set term on
SELECT versions_starttime
,versions_endtime
,versions_xid
,versions_operation
,versions_startscn
,versions_endscn
,lis_result.id
,lis_result.item_id
FROM LIS_RESULT VERSIONS BETWEEN scn &v_scn1 and &v_scn2
-- FROM LIS_RESULT VERSIONS BETWEEN TIMESTAMP sysdate-1/1440 and sysdate
WHERE id = &&v_id
--and item_id = &&v_item_id
order by versions_startscn
;
[email protected]:1521/orcl> @ aa1.txt 3
VERSIONS_STARTTIME VERSIONS_ENDTIME VERSIONS_XID V VERSIONS_STARTSCN VERSIONS_ENDSCN ID ITEM_ID
-------------------- -------------------- ---------------- - ----------------- --------------- ------------ ------------
2023-03-01 09:12:59. 2023-03-01 09:12:59. 0A001E00B1D61800 I 44616226517 44616226539 26961902 3429
2023-03-01 09:12:59. 2023-03-01 09:12:59. 0A001E00B1D61800 I 44616226517 44616226536 26961902 3428
2023-03-01 09:12:59. 2023-03-01 09:12:59. 0A001E00B1D61800 I 44616226517 44616226527 26961902 3423
2023-03-01 09:12:59. 2023-03-01 09:12:59. 0A001E00B1D61800 I 44616226517 44616226530 26961902 3425
2023-03-01 09:12:59. 2023-03-01 09:12:59. 0A001E00B1D61800 I 44616226517 44616226542 26961902 3430
2023-03-01 09:12:59. 2023-03-01 09:12:59. 0A001E00B1D61800 I 44616226517 44616226533 26961902 3427
2023-03-01 09:12:59. 2023-03-01 09:12:59. 0A001E00B1D61800 I 44616226517 44616226548 26961902 3431
2023-03-01 09:12:59. 060014008F631600 U 44616226527 26961902 3423
2023-03-01 09:12:59. 08000E0059E61600 U 44616226530 26961902 3425
2023-03-01 09:12:59. 0C0008005E9C1E00 U 44616226533 26961902 3427
2023-03-01 09:12:59. 0A001B005CD61800 U 44616226536 26961902 3428
2023-03-01 09:12:59. 0C001400349D1E00 U 44616226539 26961902 3429
2023-03-01 09:12:59. 0C000000009D1E00 U 44616226542 26961902 3430
2023-03-01 09:12:59. 0C000900479D1E00 U 44616226548 26961902 3431
14 rows selected.
--//基本類似!!可以看出開發犯了一個錯誤,應該不要分2步完成業務的邏輯操作(先insert後update),這樣幾乎產生3倍的日誌量.
--//insert的前image很少,僅僅包括rowdi,因為回滾是delete操作,僅僅需要知道rowid就ok了.
--//而update的前image,就是修改前的內容,後iamge是修改後的內容,這樣產生的redo量很大.
--//如果先組織好數據,1次性插入完成操作,可以大大的減少redo的產生.
--//可以看出一個特點inert是批量插入,而update是一條一條update的,不知道我的這個判斷是否正確?
--//查詢共用池,發現update執行如下語句.
[email protected]:1521/orcl> @ sql_id dpmmf1c22cfx8
--SQL_ID = dpmmf1c22cfx8
UPDATE lis_result
SET item_sort = :item_sort
,item_name = :item_name
,item_name_cn = :item_name_cn
,item_code = :item_code
,neg_text = :neg_text
,item_ref_min = :item_ref_min
,item_ref_max = :item_ref_max
,item_flag = :item_flag
,item_flag_str = :item_flag_str
,crt_flag = :crt_flag
,RESULT_TIME = :RESULT_TIME
,his_flag = :his_flag
,his_result = :his_result
,his_result_time = :his_result_time
,tip_ratio = :tip_ratio
,item_method = :item_method
,test_inst_id = :test_inst_id
,Inst_Alam = :Inst_Alam
,print_grp = :print_grp
,item_result = :item_result
,result_symbol = :result_symbol
,item_result_text = :item_result_text
,item_remark = :item_remark
,item_od = :item_od
,item_sco = :item_sco
,cutt_of = :cutt_of
,ITEM_UNIT = :ITEM_UNIT
,ITEM_REF = :ITEM_REF
,item_result2 = :item_result2
,item_result3 = :item_result3
,item_result4 = :item_result4
,HIS_RESULT2 = :HIS_RESULT2
,HIS_RESULT_TIME2 = :HIS_RESULT_TIME2
,HIS_RESULT1 = :HIS_RESULT1
,HIS_RESULT_TIME1 = :HIS_RESULT_TIME1
,order_id = :order_id
,order_item_id = :order_item_id
,order_item_name = :order_item_name
,REPORT_NOT_PRINT = :REPORT_NOT_PRINT
,ITEM_FEE = :ITEM_FEE
,TEST_INST_NAME = :TEST_INST_NAME
,INPUT_TYPE = :INPUT_TYPE
,CHECK_FLAG = :CHECK_FLAG
,MSG_RESULT_MIN_MAX = :MSG_RESULT_MIN_MAX
,MSG_RESULT_FLAG = :MSG_RESULT_FLAG
,ORI_ITEM_RESULT = :ORI_ITEM_RESULT
,ORDER_NO = :ORDER_NO
,CRIT_REF = :CRIT_REF
WHERE id = :id AND item_id = :item_id;
--//註做了格式化處理!!
[email protected]:1521/orcl> @ d_bufferx dpmmf1c22cfx8 60 1
SQL_ID INST_ID MODULE EXECUTIONS CPU_TIME ELAPSED_TIME BUFFER_GETS ROWS_PROCESSED CPU_PER_EXEC ELAPSED_TIME_EXEC BUFFER_GETS_EXEC ROWS_PROCESSED_EXEC
------------- --------------- ------------ ---------- --------------- --------------- --------------- --------------- --------------- ----------------- ---------------- -------------------
dpmmf1c22cfx8 1 w3wp.exe 1200 109992 215504 7324 1200 91.66 179.59 6.10 1.00
--//1分鐘裡面執行1200次.
--//我不知道這樣改進能減少多少redo的產生,不過效果應該不錯.
3.看看日誌轉儲的情況:
[email protected]:1521/orcl> @ o2 lis.lis_result
owner object_name object_type status OID D_OID CREATED LAST_DDL_TIME
----- ----------- ----------- --------- ----- ------ ------------------- -------------------
LIS LIS_RESULT TABLE VALID 73760 73760 2020-11-27 16:43:13 2023-02-20 20:48:04
$ cat dumpredo.sql
column member new_value v_member
column member noprint
set numw 12
--//pause alter system switch logfile ;
--//pause alter system archive log current;
--//12c不允許在pluggable database執行以上命令,可以在別的回話執行然後繼續。
--//SELECT member FROM v$log a, v$logfile b WHERE a.group#(+) = b.group# and a.STATUS='CURRENT' and rownum=1;
column scn1 new_value v_scn1
column scn2 new_value v_scn2
select current_scn scn1 from v$database;
--//以下DML操作內容:
--//update t1 set small_vc = upper(small_vc);
--//commit ;
host sleep &&1
select current_scn scn2 from v$database;
--//prompt alter system dump logfile '&&v_member' scn min &&v_curr1 scn max &&v_curr2;
--//alter system dump logfile '&&v_member' scn min &&v_curr1 scn max &&v_curr2;
alter system dump redo scn min &&v_scn1 scn max &&v_scn2 Objno 73760;
[email protected]:1521/orcl> @ dumpredo 20
SCN1
------------
44616387435
SCN2
------------
44616392839
System altered.
$ egrep "LEN.*VLD|OBJ:" /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_254310.trc > /tmp/aa1.txt
REDO RECORD - Thread:1 RBA: 0x00335f.0016ec2c.0010 LEN: 0x0330 VLD: 0x05 CON_UID: 0
CHANGE #1 CON_ID:0 TYP:0 CLS:25 AFN:4 DBA:0x010000c0 OBJ:4294967295 SCN:0x0000000a63580e9d SEQ:1 OP:5.2 ENC:0 RBL:0 FLG:0x0000
CHANGE #2 CON_ID:0 TYP:0 CLS:26 AFN:4 DBA:0x010668b2 OBJ:4294967295 SCN:0x0000000a63580e9c SEQ:3 OP:5.1 ENC:0 RBL:0 FLG:0x0000
CHANGE #3 CON_ID:0 TYP:2 CLS:1 AFN:8 DBA:0x020fafed OBJ:73760 SCN:0x0000000a63580f6f SEQ:1 OP:11.2 ENC:0 RBL:0 FLG:0x0000
REDO RECORD - Thread:1 RBA: 0x00335f.0016ec2f.0010 LEN: 0x055c VLD: 0x05 CON_UID: 0
CHANGE #1 CON_ID:0 TYP:0 CLS:39 AFN:4 DBA:0x01000118 OBJ:4294967295 SCN:0x0000000a63580f6c SEQ:1 OP:5.2 ENC:0 RBL:0 FLG:0x0000
CHANGE #2 CON_ID:0 TYP:0 CLS:40 AFN:4 DBA:0x010635d4 OBJ:4294967295 SCN:0x0000000a63580f6b SEQ:3 OP:5.1 ENC:0 RBL:0 FLG:0x0000
CHANGE #3 CON_ID:0 TYP:2 CLS:1 AFN:8 DBA:0x020fc26b OBJ:73760 SCN:0x0000000a6356dc28 SEQ:1 OP:11.5 ENC:0 RBL:0 FLG:0x0000
--//OP: 11.2 insert , 11.5 update.
--//insert產生日誌長度在0x0330.
--//update產生日誌長度在0x055c.
--//有點複雜,放棄!!
$ egrep "^CHANGE" /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_254310.trc | sed "s/^.*OP://" | awk '{print $1}'| sort | uniq -c | sort -nr
827 5.1
684 11.5
594 5.2
582 5.20
118 11.2
29 13.22
17 11.4
15 4.1
8 11.6
2 13.24
5.1修改undo header中的事務信息
5.2事務開始
5.4 commit
11.2插入一條數據
11.3刪除一條數據
11.4鎖定數據(select for update)
11.5更新記錄
11.6行鏈接
$ perl /u01/app/oracle/diag/rdbms/orcl/orcl/trace/redo_summary.pl /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_254310.trc
OBJECT_ID REDO_SIZE
73760 985712
NON-OBJECT REDO 4504
--//20秒,odbject_id=73760,產生了985712,接近1M.
--//修改:
alter system dump redo scn min &&v_scn1 scn max &&v_scn2 Objno 73760;
--//為
alter system dump redo scn min &&v_scn1 scn max &&v_scn2 ;
[email protected]:1521/orcl> @ dumpredo 20
SCN1
------------
44616972825
SCN2
------------
44616979192
System altered.
$ perl /u01/app/oracle/diag/rdbms/orcl/orcl/trace/redo_summary.pl /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_7455.trc | head
OBJECT_ID REDO_SIZE
73760 1766264
NON-OBJECT REDO 626700
194159 524444
73757 416740
195403 396376
73621 306072
214792 227400
74655 198564
215210 166736
.......
--//可以大部分對象是object_id=73760.
--//如果僅僅1個insert.至少減少一半的日誌大小。.
--//如果你看update的相關日誌:
REDO RECORD - Thread:1 RBA: 0x00335f.0016e66b.0010 LEN: 0x05c4 VLD: 0x05 CON_UID: 0
SCN: 0x0000000a63580c1c SUBSCN: 1 03/01/2023 09:22:18
CHANGE #1 CON_ID:0 TYP:0 CLS:21 AFN:4 DBA:0x010000a0 OBJ:4294967295 SCN:0x0000000a63580c05 SEQ:1 OP:5.2 ENC:0 RBL:0 FLG:0x0000
ktudh redo: slt: 0x0005 sqn: 0x0014dffb flg: 0x0012 siz: 660 fbi: 0
uba: 0x010080ac.034d.23 pxid: 0x0000.000.00000000
CHANGE #2 CON_ID:0 TYP:0 CLS:22 AFN:4 DBA:0x010080ac OBJ:4294967295 SCN:0x0000000a63580c04 SEQ:4 OP:5.1 ENC:0 RBL:0 FLG:0x0000
ktudb redo: siz: 660 spc: 2410 flg: 0x0012 seq: 0x034d rec: 0x23
xid: 0x0003.005.0014dffb
ktubl redo: slt: 5 wrp: 1 flg: 0x0c08 prev dba: 0x00000000 rci: 0 opc: 11.1 [objn: 73760 objd: 73760 tsn: 8]
[Undo type ] Regular undo [User undo done ] No [Last buffer split] No
[Temp object] No [Tablespace Undo ] No [User only ] No
Begin trans
prev ctl uba: 0x010080ac.034d.1f prev ctl max cmt scn: 0x0000000a63580200
prev tx cmt scn: 0x0000000a63580233
txn start scn: 0xffffffffffffffff logon user: 106
prev brb: 0x010080aa prev bcl: 0x00000000
BuExt idx: 0 flg2: 0
KDO undo record:
KTB Redo
op: 0x04 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: L itl: xid: 0x000c.010.001e9637 uba: 0x01072687.17be.04
flg: C--- lkc: 0 scn: 0x0000000a634f990a
KDO Op code: URP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x020fbcf1 hdba: 0x00801262
itli: 5 ispac: 0 maxfr: 4858
tabn: 0 slot: 21(0x15) flag: 0x2c lock: 0 ckix: 254
ncol: 56 nnew: 47 size: 13
col 3: [ 2] c1 46
...
col 55: [24]
00 31 00 5e 00 31 00 5e 00 32 00 35 00 31 00 39 00 37 00 34 00 35 00 31
--//後image
CHANGE #3 CON_ID:0 TYP:2 CLS:1 AFN:8 DBA:0x020fbcf1 OBJ:73760 SCN:0x0000000a63580c1a SEQ:1 OP:11.5 ENC:0 RBL:0 FLG:0x0000
KTB Redo
op: 0x01 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: F xid: 0x0003.005.0014dffb uba: 0x010080ac.034d.23
KDO Op code: URP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x020fbcf1 hdba: 0x00801262
itli: 5 ispac: 0 maxfr: 4858
tabn: 0 slot: 21(0x15) flag: 0x2c lock: 5 ckix: 254
ncol: 55 nnew: 46 size: -13
col 3: [ 2] c1 46
..
col 54: [ 8] 00 30 00 2e 00 31 00 30
--//前image
--//註意IMU是反過來的保存的!!
CHANGE #4 MEDIA RECOVERY MARKER CON_ID:0 SCN:0x0000000000000000 SEQ:0 OP:5.20 ENC:0 FLG:0x0000
session number = 31
serial number = 22815
transaction name =
version 318767104
audit sessionid 6720706
Client Id =
login username = LIS
(LWN RBA: 0x00335f.0016e66f.0010 LEN: 0x00000004 NST: 0x0001 SCN: 0x0000000a63580c1f)
--//看看object_id=194159.
[email protected]:1521/orcl> @ oid 194159
owner object_name object_type SUBOBJECT_NAME CREATED LAST_DDL_TIME status DATA_OBJECT_ID
----- --------------- ----------- -------------- ------------------- ------------------- --------- --------------
LIS LIS_RESULT_TEMP TABLE 2022-07-01 12:06:16 2022-10-20 11:16:17 VALID 194159
--//根據情況修改aa1.txt => aa2.txt,id是LIS_RESULT_TEMP的主鍵.
$ cat aa2.txt
set numw 12
column id new_value v_id
column item_id new_value v_item_id
column scn1 new_value v_scn1
column scn2 new_value v_scn2
set term off
select current_scn-1e4 scn1 from v$database;
select max(id) id from LIS_RESULT_temp;
host sleep &&1
select current_scn scn2 from v$database;
set term on
SELECT versions_starttime
,versions_endtime
,versions_xid
,versions_operation
,versions_startscn
,versions_endscn
,lis_result_temp.id
FROM LIS_RESULT_TEMP VERSIONS BETWEEN scn &v_scn1 and &v_scn2
-- FROM LIS_RESULT VERSIONS BETWEEN TIMESTAMP sysdate-1/1440 and sysdate
WHERE id = &&v_id
--and item_id = &&v_item_id
order by versions_startscn
;
[email protected]:1521/orcl> @ aa2.txt 3
VERSIONS_STARTTIME VERSIONS_ENDTIME VERSIONS_XID V VERSIONS_STARTSCN VERSIONS_ENDSCN ID
-------------------- -------------------- ---------------- - ----------------- --------------- ------------
2023-03-01 10:26:48. 2023-03-01 10:26:48. 0C00150016B41E00 I 44617508176 44617508212 219375442
2023-03-01 10:26:48. 04001A00E48F1400 U 44617508212 219375442
[email protected]:1521/orcl> @ aa2.txt 3
VERSIONS_STARTTIME VERSIONS_ENDTIME VERSIONS_XID V VERSIONS_STARTSCN VERSIONS_ENDSCN ID
-------------------- -------------------- ---------------- - ----------------- --------------- ------------
2023-03-01 10:26:54. 2023-03-01 10:26:54. 03000900C8E11400 I 44617509759 44617509775 219375476
2023-03-01 10:26:54. 0C0020000FB41E00 U 44617509775 219375476
--//^_^,一樣的情況!!大致明白為什麼會產生這樣大的日誌量,開發把資料庫當作垃圾桶!!
--//再看另外一個對象73757.
[email protected]:1521/orcl> @oid 73757
owner object_name object_type SUBOBJECT_NAME CREATED LAST_DDL_TIME status DATA_OBJECT_ID
----- ---------------- ----------- -------------- ------------------- ------------------- --------- --------------
LIS LIS_ORDER_DETAIL TABLE 2020-11-27 16:43:13 2023-02-20 20:47:34 VALID 76018
[email protected]:1521/orcl> @ aa3.txt 3
VERSIONS_STARTTIME VERSIONS_ENDTIME VERSIONS_XID V VERSIONS_STARTSCN VERSIONS_ENDSCN ID
-------------------- -------------------- ---------------- - ----------------- --------------- ------------
2023-03-01 10:30:54. 2023-03-01 10:30:54. 0C000500E2B51E00 I 44617592015 44617592021 134648696
2023-03-01 10:30:54. 2023-03-01 10:30:54. 07000800C6F51400 U 44617592021 44617592059 134648696
2023-03-01 10:30:54. 0C0011005EB51E00 U 44617592059 134648696
[email protected]:1521/orcl> @ aa3.txt 3
VERSIONS_STARTTIME VERSIONS_ENDTIME VERSIONS_XID V VERSIONS_STARTSCN VERSIONS_ENDSCN ID
-------------------- -------------------- ---------------- - ----------------- --------------- ------------
2023-03-01 10:32:33. 2023-03-01 10:32:33. 0C000700A8B61E00 I 44617636753 44617636768 134650263
2023-03-01 10:32:33. 2023-03-01 10:32:33. 03000D0013E21400 U 44617636768 44617636886 134650263
2023-03-01 10:32:33. 0C00020093B61E00 U 44617636886 134650263
--//2次update!!到此,終於明白為什麼這套系統日誌比原來舊系統多很多的原因.
--//應該一次insert就完成的業務,開發寫成insert+update來完成。
--//簡單估算(0x0330+0x055c)/0x400 = 2.13671875,這樣寫日誌至少增加1倍日誌量。
4.附錄:
--//腳本的來源當時沒記錄,也不知道是否可靠與正確.
$ cat /u01/app/oracle/diag/rdbms/orcl/orcl/trace/redo_summary.pl
# TDH 2008-09-26
# Analyses a formatted redo dump and
# summarises redo bytes by object.
#
my $current_object;
my $current_bytes;
my %object_bytes = ();
sub DescendingNum {
$object_bytes{$b} <=> $object_bytes{$a};
}
while (<>) {
if (/LEN: 0x([a-f0-9A-F]+) VLD/) {
if (defined($current_object)) {
$object_bytes{$current_object} += $current_bytes;
}
elsif (defined($current_bytes)) {
$object_bytes{"NON-OBJECT REDO"} += $current_bytes;
}
$current_bytes = hex($1);
$current_object = undef;
}
elsif (/objn: (\d+) objd/) {
$current_object = $1;
}
}
printf "%20s %40s\n","OBJECT_ID","REDO_SIZE";
foreach my $key (sort DescendingNum(keys(%object_bytes))) {
printf "%20s %40s\n",$key,$object_bytes{$key};
}