There may be occasions when it’s necessary to investigate recent changes to the database and report what was changed, when and by whom. For years Oracle’s DBMS_LOGMNR package has been available for such tasks but its invocations have not been fully covered. Conventional methods use the ADD_LOGFILE() procedure to prepare Log Miner for use with a basic call to the START_LOGMNR procedure. This starts the utility with the current SCN as the starting point. There is another way to start Log Miner, by selecting a valid starting SCN and providing that to the START_LOGMNR() call. In this article, you will see how this can be done, and, in the process, reveal a possible area of concern with PGA allocations.
Looking at a ‘plain vanilla’ script to start Log Miner the usual procedure calls are made that start Log Miner with the current SCN:
--
-- run_logmnr.sql
--
-- Add logfiles and set DBMS_LOGMNR to
-- continuously mine archivelogs
--
set linesize 200 trimspool on pagesize 0
--
-- Add the existing logfiles
--
-- Omit standby logfiles
--
select 'exec dbms_logmnr.add_logfile('''||member||''')'
from v$logfile
where type <> 'STANDBY'
and member in (select min(member) from v$logfile group by group#)
spool /tmp/add_logfiles.sql
/
spool off
@/tmp/add_logfiles
--
-- Start logmnr in coninuous mine mode
--
exec dbms_logmnr.start_logmnr(options => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG + DBMS_LOGMNR.CONTINUOUS_MINE + DBMS_LOGMNR.COMMITTED_DATA_ONLY)
Note that all available redo logs are added prior to starting Log Miner. Another method exists that supplies a starting SCN to the start_logmnr call, as long as the database is running in ARCHIVELOG mode:
BEGIN
DBMS_LOGMNR.START_LOGMNR(
startScn => <start SCN>,
endScn => <stop SCN>,
OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG +
DBMS_LOGMNR.COMMITTED_DATA_ONLY +
DBMS_LOGMNR.CONTINUOUS_MINE);
END;
/
Interestingly, the end SCN is not necessary to get a Log Miner session started. The database must be in ARCHIVELOG mode so that the CONTINUOUS_MINE option can be specified because Log Miner will automatically add every available archived log file as it runs. Using this method allows a specific SCN be used to start any search; specifying the end SCN brackets search so that only a limited subset of data is returned to the V$LOGMNR_CONTENTS view and provides a stopping point for the search, so that a query of the view can terminate.
It’s a simple task to monitor the progress of Log Miner by checking the database alert log as entries marked with ‘LOGMINER’ are registered. A complete entry will include a BEGIN and an END line, as shown below:
Mon Oct 07 12:48:22 2019
LOGMINER: End mining logfile for session -2147482111 thread 1 sequence 9776, /oracle/archive/awcis/awcis_0000009776_0001_1008544071.arc
Mon Oct 07 12:48:22 2019
LOGMINER: Begin mining logfile for session -2147482111 thread 1 sequence 9777, /oracle/archive/awcis/awcis_0000009777_0001_1008544071.arc
Mon Oct 07 12:48:36 2019
LOGMINER: End mining logfile for session -2147482111 thread 1 sequence 9777, /oracle/archive/awcis/awcis_0000009777_0001_1008544071.arc
Mon Oct 07 12:48:36 2019
LOGMINER: Begin mining logfile for session -2147482111 thread 1 sequence 9778, /oracle/archive/awcis/awcis_0000009778_0001_1008544071.arc
Mon Oct 07 12:48:49 2019
LOGMINER: End mining logfile for session -2147482111 thread 1 sequence 9778, /oracle/archive/awcis/awcis_0000009778_0001_1008544071.arc
Mon Oct 07 12:48:49 2019
LOGMINER: Begin mining logfile for session -2147482111 thread 1 sequence 9779, /oracle/archive/awcis/awcis_0000009779_0001_1008544071.arc
For local Oracle sessions the numbers are positive integers; for remote sessions, initiated by utilities such as Perl, Python, C/C++ or other languages negative integers will be seen (the entries shown above were initiated by a Python script). Log file names will cycle through both the online redo logs and the available archived copies.
Starting Log Miner in this fashion can also throw errors such as ‘missing logfile’ when the selected starting SCN or SCN range is no longer available in the redo stream. Long-running queries can encounter such errors. Additionally, if the SCN is out of range with respect to the available log files Log Miner will not start, throwing:
ERROR at line 1:
ORA-01292: no log file has been specified for the current LogMiner session
ORA-06512: at "SYS.DBMS_LOGMNR", line 58
ORA-06512: at line 2
To help to eliminate such errors selecting the FIRST_CHANGE# from the V$LOG view will provide valid starting points for a Log Miner session; using a similar query against V$ARCHIVED_LOG will return all available starting SCNs for the archived redo copies.
This is not the only complication to using Log Miner in this way. Depending upon how much information is to be returned, the Logmminer process can allocate large amounts of PGA memory which can, if the pga_aggregate_limit is small, throw the following error:
ORA-04036: PGA memory used by the instance exceeds PGA_AGGREGATE_LIMIT
fortunately this is not a fatal error. As PGA resources are no longer needed memory can be released back to the database for use elsewhere. However, it may take a bit longer than desired to get that memory released back to the memory pool. An option is to set the pga_aggregate_limit higher than the sum of the Log Miner sessions which can prevent the error from occurring. How do you know what memory is allocated to those sessions? A view, V$PROCESS_MEMORY_DETAIL, is available in the database. But attempting to query this view without some preparation will return:
no rows selected.
This is a relatively minor issue, but it requires the use of the oradebug utility. The following steps will load data into V$PROCESS_MEMORY_DETAIL:
--
-- Set the current session identifier
--
oradebug setmypid
--
-- Using the PID of the desired process
-- dump the memory data
--
-- This populates V$PROCESS_MEMORY_DETAIL
--
oradebug pga_detail_get
--
-- Query the view to get the desired data
--
select * From v$process_memory_detail;
--
-- To re-populate the view with newer data
-- simply execute the oradebug pga_detail_get
-- statement
--
oradebug pga_detail_get
A script to perform these actions is shown below:
--
-- Set up the environment for oradebug calls
--
oradebug setmypid
set echo off trimspool on
set verify off
undefine p_1
undefine p_2
undefine s1
undefine s2
variable p1 number
variable p2 number
column sys_date new_value sysdt noprint
select to_char(sysdate, 'RRRRMMDDHH24MISS') sys_date from dual;
--
-- Get process id of the <USER> session
--
column pid new_value p_1
select pid from v$process where addr in (select paddr from v$session where username = '<USER>' and sid = (select max(sid) From v$session where username = '<USER>'));
begin
:p1 := &p_1;
end;
/
--
-- Dump process detail to v$process_memory_detail
--
oradebug dump pga_detail_get &p_1
spool &p_1._pga_stats_&sysdt..log
--
-- Get session information for <USER>
--
COLUMN alme HEADING "Allocated MB" FORMAT 99999D9
COLUMN usme HEADING "Used MB" FORMAT 99999D9
COLUMN frme HEADING "Freeable MB" FORMAT 99999D9
COLUMN mame HEADING "Max MB" FORMAT 99999D9
COLUMN username FORMAT a25
COLUMN program FORMAT a22
COLUMN sid FORMAT a5
COLUMN spid FORMAT a8
column pid_remote format a12
SET LINESIZE 300
SELECT s.username, SUBSTR(s.sid,1,5) sid, p.spid, logon_time,
SUBSTR(s.program,1,22) program , s.process pid_remote,
s.status,
ROUND(pga_used_mem/1024/1024) usme,
ROUND(pga_alloc_mem/1024/1024) alme,
ROUND(pga_freeable_mem/1024/1024) frme,
ROUND(pga_max_mem/1024/1024) mame
FROM v$session s,v$process p
WHERE p.addr=s.paddr
AND s.username = '<USER>'
ORDER BY pga_max_mem,logon_time;
--
-- Sleep 30 seconds
--
-- Get session information again
--
exec dbms_lock.sleep(30)
column sid new_value s1 noprint
SELECT s.username, SUBSTR(s.sid,1,5) sid, p.spid, logon_time,
SUBSTR(s.program,1,22) program , s.process pid_remote,
s.status,
ROUND(pga_used_mem/1024/1024) usme,
ROUND(pga_alloc_mem/1024/1024) alme,
ROUND(pga_freeable_mem/1024/1024) frme,
ROUND(pga_max_mem/1024/1024) mame
FROM v$session s,v$process p
WHERE p.addr=s.paddr
AND s.username = '<USER>'
ORDER BY pga_max_mem,logon_time;
exec dbms_lock.sleep(10)
select max(sid) sid from v$session where username = '<USER>';
--
-- Get process memory info
--
COLUMN category HEADING "Category"
COLUMN allocated HEADING "Allocated bytes"
COLUMN used HEADING "Used bytes"
COLUMN max_allocated HEADING "Max allocated bytes"
SELECT pid, category, allocated, used, max_allocated
FROM v$process_memory
WHERE pid in (SELECT pid
FROM v$process
WHERE addr in (select paddr
FROM v$session
WHERE sid = &&s1));
exec dbms_lock.sleep(10)
SELECT pid, category, allocated, used, max_allocated
FROM v$process_memory
WHERE pid in (SELECT pid
FROM v$process
WHERE addr in (select paddr
FROM v$session
WHERE sid = &&s1));
exec dbms_lock.sleep(10)
select pid from v$process where addr in (select paddr from v$session where username = '<USER>' and sid = (select max(sid) from v$session where username = '<USER>'));
--
-- Save first pass of pga stats
--
CREATE TABLE tab1 AS
SELECT pid, category, name, heap_name, bytes, allocation_count,
heap_descriptor, parent_heap_descriptor
FROM v$process_memory_detail
WHERE pid = &p_1
AND category = 'Other';
--
-- Get second pass of pga stats
--
oradebug dump pga_detail_get &p_1
exec dbms_lock.sleep(120)
--
-- Save second pass of pga stats
--
CREATE TABLE tab2 AS
SELECT pid, category, name, heap_name, bytes, allocation_count,
heap_descriptor, parent_heap_descriptor
FROM v$process_memory_detail
WHERE pid = &p_1
AND category = 'Other';
--
-- Start final reports
--
-- PGA heap info
--
COLUMN category HEADING "Category"
COLUMN name HEADING "Name"
COLUMN heap_name HEADING "Heap name"
COLUMN q1 HEADING "Memory 1st" Format 999,999,999,999
COLUMN q2 HEADING "Memory 2nd" Format 999,999,999,999
COLUMN diff HEADING "Difference" Format S999,999,999,999
SET LINES 150
SELECT tab2.pid, tab2.category, tab2.name, tab2.heap_name, tab1.bytes q1, tab2.bytes q2, tab2.bytes-tab1.bytes diff
FROM tab1, tab2
WHERE tab1.category = tab2.category
AND tab1.name = tab2.name
AND tab1.heap_name = tab2.heap_name
and tab1.pid = tab2.pid
AND tab1.bytes <> tab2.bytes
ORDER BY 1, 7 DESC;
--
-- Logminer PGA info
--
COLUMN heap_name HEADING "heap name"
COLUMN name HEADING "Type"
COLUMN allocation_count HEADING "Count"
COLUMN bytes HEADING "Sum"
COLUMN avg HEADING "Average" FORMAT 99999D99
SELECT pid, heap_name, name, allocation_count, bytes, bytes/allocation_count avg
FROM tab2
WHERE heap_name like 'Logminer%';
spool off
drop table tab1 purge;
drop table tab2 purge;
Save this code as a script and edit the text to replace the <USER> strings with the user account running Log Miner. The script specifically targets the Logminer memory so it can be monitored for increases. It can also be modified to look for any other problem memory areas. Comment the ‘drop table’ commands to preserve tab1 and tab2 for further research, if desired as other memory areas may be of interest. Also check Oracle support for known PGA-related issues. Such reports will likely have queries to use to investigate specific problem areas using V$PROCESS_MEMORY_DETAIL. For expedience those additional queries can be added to the code shown above to report on all suspect areas of process memory. This data will be instrumental in proving the necessity of applying specific one-off patches to the database.
Log Miner can be a very useful tool in investigating current and relatively recent past actions to the database. It may be necessary to monitor PGA allocations while Log Miner sessions are active so preventive action such as increasing the pga_aggregate_limit can be executed, and sessions won’t be abruptly terminated. “Forewarned is forearmed”, as the saying goes, and even though DBAs don’t have four arms knowing what could lie ahead is always knowledge worth having.
