首页 > 代码库 > 使用logminer挖掘日志,分析历史操作 系列一
使用logminer挖掘日志,分析历史操作 系列一
===============STARTED====================================
事件起因:
业务的人mail过来说是有张表记录的10K+的优惠码记录没了,要我们确认下之前是否有这样的相关清除操作。
当然,先去数据库确认下这张表关于这个字段的count,的确没有相关的记录。
于是想着之前是不是有人做了相关的DML操作,
先看下这个视图,
select table_name, owner,num_rows, blocks, last_analyzed,partitioned
from dba_tables
where table_name =‘NIKE_COUPON‘;
TABLE_OWNER TABLE_NAME PARTITION_NAME SUBPARTITION_NAME INSERTS UPDATES DELETES TIMESTAMP TRU DROP_SEGMENTS
------------- ---------------- ------------------------------ ------------------------- ---------- ---------- ---------- --------- --- -------------
AP NIKE_COUPON 4 66 0 02-JAN-17 NO 0
看了下deletes为0呀,想了下也许这个视图的数据来源不准,进一步分析,可以通过ASH来看看是否有着这样的DML操作。
(关于dba_tab_modifications这个视图有时候还是挺有用的,但是有几个限制,所以反馈的信息有时也不是很准~)
ASH信息获取:
SQL> set lines 1000
SQL> set pages 400
SQL> select distinct a.sample_time,
2 a.sql_id,a.blocking_session,a.session_state,a.event,a.wait_class,a.program,a.module,a.machine,c.sql_text
3 from dba_hist_active_sess_history a ,v$sqlarea c
where a.sql_id=c.sql_id
and sample_time between to_date(‘1-JAN-17 00.00.00‘,‘dd-MON-yy hh24:mi:ss‘) and to_date(‘3-JAN-17 23.00.00‘,‘dd-MON-yy hh24:mi:ss‘)
and lower(c.sql_text) like ‘%delete%nike_coupon%‘
order by 1 ; 4 5 6 7
SAMPLE_TIME SQL_ID BLOCKING_SESSION SESSION EVENT WAIT_CLASS PROGRAM MODULE MACHINE
--------------------------------------------------------------------------- ------------- ---------------- ------- ---------------------------------------------------------------- ---------------
SQL_TEXT
----------------------------------------
01-JAN-17 02.02.47.280 AM 8c7cw4xvync0v 7431 WAITING enq: TX - row lock contention Application JDBC Thin Client JDBC Thin Client ip-xxxx.xx.b2c.nike.com
DELETE FROM nike_coupon WHERE coupon_id = :1
01-JAN-17 02.02.47.280 AM 8c7cw4xvync0v 7431 WAITING enq: TX - row lock contention Application JDBC Thin Client JDBC Thin Client ip-xxxx.xx.b2c.nike.com
DELETE FROM nike_coupon WHERE coupon_id = :1
01-JAN-17 02.02.47.280 AM 8c7cw4xvync0v 7431 WAITING enq: TX - row lock contention Application JDBC Thin Client JDBC Thin Client ip-xxxx.xx.b2c.nike.com
DELETE FROM nike_coupon WHERE coupon_id = :1
01-JAN-17 02.02.47.280 AM 8c7cw4xvync0v 7431 WAITING enq: TX - row lock contention Application JDBC Thin Client JDBC Thin Client ip-xxxx.xx.b2c.nike.com
DELETE FROM nike_coupon WHERE coupon_id = :1
01-JAN-17 02.02.47.280 AM 8c7cw4xvync0v 7431 WAITING enq: TX - row lock contention Application JDBC Thin Client JDBC Thin Client ip-xxxx.xx.b2c.nike.com
DELETE FROM nike_coupon WHERE coupon_id = :1
01-JAN-17 02.02.47.280 AM 8c7cw4xvync0v 7431 WAITING enq: TX - row lock contention Application JDBC Thin Client JDBC Thin Client ip-xxxx.xx.b2c.nike.com
DELETE FROM nike_coupon WHERE coupon_id = :1
01-JAN-17 02.04.53.276 AM 8c7cw4xvync0v ON CPU JDBC Thin Client JDBC Thin Client ip-xxxx.xx.b2c.nike.com
DELETE FROM nike_coupon WHERE coupon_id = :1
01-JAN-17 02.07.34.168 AM 8c7cw4xvync0v ON CPU JDBC Thin Client JDBC Thin Client ip-xxxx.xx.b2c.nike.com
DELETE FROM nike_coupon WHERE coupon_id = :1
01-JAN-17 02.13.30.192 AM 8c7cw4xvync0v ON CPU JDBC Thin Client JDBC Thin Client ip-xxxx.xx.b2c.nike.com
DELETE FROM nike_coupon WHERE coupon_id = :1
可见,在01-JAN-17 02.02.47.280 AM 左右的确有应用服务器连过来做了delete这张表记录的操作,然后和应用,业务都确认好了,应用有每个月初的batch把一些过期的优惠券记录删掉,但是业务想在延长一个月,后面当然是和业务确认好数据,然后重新insert进去。
事情就这样告一段落。
但是可以看到delete语句是带有绑定变量的,如果业务没有数据副本保留,要我们DBA来去fetch到那些删掉的记录,我们如何去获取呢,那就得想办法去得到这个绑定变量的值。
SQL> select
2 dbms_sqltune.extract_bind(bind_data,1).value_string bind1,
3 dbms_sqltune.extract_bind(bind_data,2).value_string bind2,
dbms_sqltune.extract_bind(bind_data,3).value_string bind3
from sys.wrh$_sqlstat
where sql_id = ‘8c7cw4xvync0v‘;
4 5 6
BIND1
------------------------------
BIND2
------------------------------------
BIND3
---------------------
HO1234567
HO1234567
SELECT snap_id, NAME,POSITION,DATATYPE_STRING,VALUE_STRING,LAST_CAPTURED cdate
FROM DBA_HIST_SQLBIND WHERE SQL_ID=‘8c7cw4xvync0v‘ ;
SNAP_ID NAME POSITION DATATYPE_STRING
---------- ------------------------------ ---------- ---------------
VALUE_STRING
-----------------------------------------------
CDATE
---------
33175 :1 1 VARCHAR2(128)
HO1234567
01-JAN-17
33175 :1 1 VARCHAR2(128)
HO1234567
01-JAN-17
SQL> select snap_id,BEGIN_INTERVAL_TIME,END_INTERVAL_TIME from dba_hist_snapshot where snap_id=33175;
SNAP_ID BEGIN_INTERVAL_TIME END_INTERVAL_TIME
---------- --------------------------------------------------------------------------- ---------------------------------------------------------------------------
33175 01-JAN-17 02.00.36.240 AM 01-JAN-17 03.00.38.812 AM
33175 01-JAN-17 02.00.36.109 AM 01-JAN-17 03.00.38.693 AM
只能查到这一个绑定变量的值:HO1234567
明显是不够的。
这里略带说一下,关于获取绑定变量的一些方法。
1.10043获取bind value,但是在这里不合适,因为要获取的是历史绑定变量
2. v$sql_bind_capture以及dba_hist_sqlbind
3.dbms_sqltune.extract_bind from dba_hist_sqlstat
Bind Capture History
Oracle captures the bind value and stores it into the repository(AWR), but with following restrictions.
- Captured periodically(_cursor_bind_capture_interval), not at real time.
- Captured under maximum size(_cursor_bind_capture_area_size)
- Only bind variables in WHERE clause are captured
大致这三种方法获取bind value,
但是也有如下的限制,如下一小段英文转自Historical Bind Variable Storage
http://www.dba-oracle.com/t_historical_bind_variable_storage.htm
Question: I need to see historical SQL with the bind variables used. Does AWR or STATSPACK store bind variable information? Does Oracle store SQL bind variable values anywhere?
Answer: Only the PGA stores specific bind variable and cursor values, and these are not kept for historical analysis.
The extra cost AWR allows you to see a "representative" sample bind variable value, but all bind variable values are NOT present. In Oracle 10g and beyond, bind variables are periodically captured in the v$sql_bind_capture anddba_hist_sqlbind views, but these are bind variables or ONLY for a single, specific session, and not all historical session bind variables for a SQL statement are kept.
This is because the amount of disk storage to keep a history of all bind variable values would be huge, especially for database that process thousands of transactions per second.
These limited bind values can be found in some AWR and ASH tables as well as the v$sql_plan view. Also, DML statements will have bind variable information in the archived redo logs available via LogMiner.
The best way to collect bind variable for any SQL statement is by using TKPROF(a 10046 trace).
v$sql_plan Bind Variable Display
The v$sql_plan only shows Systemwide values and it does not contain session-level bind variable values. However, you can use the dbms_xplan.display package to display a sample bind variable:
select
sql_text,
other_xml
from
$sql_plan
where
sql_id=‘XXXX‘
and
id=0;
AWR dba_hist_sqlstat Bind Variable Display
select
sql_text,
other_xml
from
$dba_hist_sqlplan
where
sql_id=‘XXXX‘
and
id=0;
Or you can use the dbms_xplan_display_awr procedure to see a sample bind variable:
select
*
from
table(dbms_xplan.display_awr(‘&SQL_ID‘,NULL,NULL,‘ADVANCED‘))
好的,所以看来只能通过logminer来获取sql redo和sql undo的一些信息了。之前也没怎么用过logminer这个强大的工具,明天先研究下再来更新后续!~~
使用logminer挖掘日志,分析历史操作 系列一