=======================
General
=======================
The archive folder was 100% full.
As an SOS operation, all archive files were deleted.
Now, several Extract process are in Abended state.
When checking with info extract EXT_I_01 DETAIL, the error is:
2018-05-21 06:33:43 ERROR OGG-00868 Error code 1291, error message: ORA-01291: missing logfile
(Missing Log File /oracle_db/db2/db_igt/arch/arch0001_136774_827755274.arc. Read Position SCN -976006635).
2018-05-21 06:33:43 ERROR OGG-01668 PROCESS ABENDING.
How to resolve this situation?
=======================
Evidences
=======================
via ggsci
info all
EXTRACT ABENDED EXT_I_01 00:06:36 118:28:15
EXTRACT ABENDED EXT_I_02 00:06:31 118:28:14
EXTRACT ABENDED EXT_I_04 00:06:28 118:28:20
EXTRACT ABENDED EXT_I_05 00:00:06 263:13:17
EXTRACT ABENDED EXT_I_06 00:06:29 118:28:20
EXTRACT ABENDED EXT_I_07 00:06:28 118:28:18
EXTRACT ABENDED EXT_I_09 00:06:30 118:28:22
EXTRACT ABENDED EXT_I_10 00:06:27 118:28:20
EXTRACT ABENDED EXT_I_11 00:06:26 118:28:21
EXTRACT ABENDED EXT_I_13 00:06:36 118:28:15
EXTRACT ABENDED EXT_I_14 00:06:33 118:28:19
EXTRACT ABENDED EXT_I_15 00:06:31 118:28:19
EXTRACT ABENDED EXT_I_17 00:06:30 118:28:20
EXTRACT ABENDED EXT_P_01 00:06:32 118:28:20
EXTRACT ABENDED EXT_P_02 00:06:32 118:28:15
EXTRACT ABENDED EXT_P_04 00:06:30 118:28:21
EXTRACT ABENDED EXT_P_05 00:00:05 263:13:12
EXTRACT ABENDED EXT_P_06 00:06:25 118:28:26
EXTRACT ABENDED EXT_P_07 00:06:28 118:28:18
EXTRACT ABENDED EXT_P_09 00:06:30 118:28:20
EXTRACT ABENDED EXT_P_10 00:06:27 118:28:21
EXTRACT ABENDED EXT_P_11 00:06:30 118:28:22
EXTRACT ABENDED EXT_P_13 00:06:35 118:28:16
EXTRACT ABENDED EXT_P_14 00:06:28 118:28:19
EXTRACT ABENDED EXT_P_15 00:06:28 118:28:18
EXTRACT ABENDED EXT_P_17 00:06:33 118:28:20
EXTRACT ABENDED EXT_S_13 00:06:29 118:28:19
EXTRACT ABENDED EXT_S_14 00:06:32 118:28:21
EXTRACT ABENDED EXT_S_15 00:06:28 118:28:19
EXTRACT ABENDED EXT_S_17 00:06:34 118:28:18
GGSCI (my_server) 19> VIEW PARAM EXT_I_01
Will display extact parameter files
GGSCI (my_server) 19> info extract EXT_I_01 DETAIL
EXTRACT EXT_I_01 Last Started 2018-01-29 06:48 Status ABENDED
Checkpoint Lag 00:06:36 (updated 118:35:46 ago)
Log Read Checkpoint Oracle Integrated Redo Logs
2018-05-16 07:52:30
SCN 3.3318960661 (16203862549)
Target Extract Trails:
Trail Name Seqno RBA Max MB Trail Type
/software/ogg/1212/dirdat/01/out/ei 12 458809 100 EXTTRAIL
Integrated Extract outbound server first scn: Unavailable.Need DBLOGIN.
Extract Source Begin End
Not Available 2018-01-17 10:36 2018-05-16 07:52
Not Available 2018-01-17 10:36 2018-01-29 06:47
Not Available 2018-01-17 10:36 2018-01-28 06:47
Not Available 2018-01-17 10:36 2018-01-27 06:47
Not Available 2018-01-17 10:36 2018-01-26 06:47
Not Available 2018-01-17 10:36 2018-01-25 06:47
Not Available 2018-01-17 10:36 2018-01-24 06:47
Not Available 2018-01-17 10:36 2018-01-23 06:47
Not Available 2018-01-17 10:36 2018-01-22 06:47
Not Available 2018-01-17 10:36 2018-01-21 06:47
Not Available 2018-01-17 10:36 2018-01-20 06:47
Not Available 2018-01-17 10:36 2018-01-19 06:47
Not Available 2018-01-17 10:36 2018-01-18 06:47
Not Available * Initialized * 2018-01-17 10:36
Current directory /software/ogg/1212
Report file /software/ogg/1212/dirrpt/EXT_I_01.rpt
Parameter file /software/ogg/1212/dirprm/ext_i_01.prm
Checkpoint file /software/ogg/1212/dirchk/EXT_I_01.cpe
Process file /software/ogg/1212/dirpcs/EXT_I_01.pce
Error log /software/ogg/1212/ggserr.log
less /software/ogg/1212/dirrpt/EXT_I_01.rpt
Source Context :
SourceModule : [er.redo.oraxo]
SourceID : [/scratch/aime1/adestore/views/aime1_adc4150472/oggcore/OpenSys/src/app/er/redo/oracle/redooraix.c]
SourceFunction : [REDOORAIX_abend_if_missing_logfile]
SourceLine : [8206]
ThreadBacktrace : [15] elements
: [/software/ogg/1212/libgglog.so(CMessageContext::AddThreadContext()+0x1e) [0x7fd7c02e5dee]]
: [/software/ogg/1212/libgglog.so(CMessageFactory::CreateMessage(CSourceContext*, unsigned int, ...)+0x31c) [0x7fd7c02e2c2c]]
: [/software/ogg/1212/libgglog.so(_MSG_ERR_DB_GENERIC_FAILURE(CSourceContext*, char const*, CMessageFactory::MessageDisposition)+0x31) [0x7fd7c02c81d1]]
: [/software/ogg/1212/extract(REDOORAIX_abend_if_missing_logfile(char*)+0x1b9) [0x7b9a57]]
: [/software/ogg/1212/extract(REDOORAIX_attach(ggs::gglib::ggunicode::UString&, int, char (&) [2048])+0x274) [0x7ae574]]
: [/software/ogg/1212/extract(REDOORAIX_validate_config()+0x4e9) [0x7b21f9]]
: [/software/ogg/1212/extract(REDO_validate_config(int, unsigned int*, int*)+0xfab) [0x71f07b]]
: [/software/ogg/1212/extract(redo_log_setup()+0x36) [0x5ad3c6]]
: [/software/ogg/1212/extract(extract_main(int, char**)+0x29e) [0x5b096e]]
: [/software/ogg/1212/extract(ggs::gglib::MultiThreading::MainThread::ExecMain()+0x4f) [0x68743f]]
: [/software/ogg/1212/extract(ggs::gglib::MultiThreading::Thread::RunThread(ggs::gglib::MultiThreading::Thread::ThreadArgs*)+0x104) [0x687694]]
: [/software/ogg/1212/extract(ggs::gglib::MultiThreading::MainThread::Run(int, char**)+0x8b) [0x68785b]]
: [/software/ogg/1212/extract(main+0x3f) [0x5b047f]]
: [/lib64/libc.so.6(__libc_start_main+0xfd) [0x3998c1ed1d]]
: [/software/ogg/1212/extract() [0x51dc59]]
2018-05-21 06:33:43 ERROR OGG-00868 Error code 1291, error message: ORA-01291: missing logfile
(Missing Log File /oracle_db/db2/db_igt/arch/arch0001_136774_827755274.arc. Read Position SCN -976006635).
2018-05-21 06:33:43 ERROR OGG-01668 PROCESS ABENDING.
======================================================
Solution
======================================================
The solution would be to unregister and register the extract process, causing it to reset to currect SCN value.
GGSCI (my_server) 2> DBLOGIN USERID OGG PASSWORD <password>
Successfully logged into database.
GGSCI (my_server) 15> STOP EXTRACT EXT_I_02
EXTRACT EXT_I_02 is already stopped.
If extract cannot be stopped do:
ALTER EXTRACT EXT_P_02, BEGIN NOW
GGSCI (my_server) 16> UNREGISTER EXTRACT EXT_I_02 DATABASE
Successfully unregistered EXTRACT EXT_I_02 from database.
This might take several minutes
GGSCI (my_server) 17> REGISTER EXTRACT EXT_I_02 DATABASE
Extract EXT_I_02 successfully registered with database at SCN 16308342873.
This might take several minutes
GGSCI (my_server) 18> START EXTRACT EXT_I_02
Sending START request to MANAGER ...
EXTRACT EXT_I_02 starting
GGSCI (my_server) 13> INFO EXTRACT EXT_I_02
EXTRACT EXT_I_01 Last Started 2018-05-21 08:20 Status RUNNING
Checkpoint Lag 00:00:00 (updated 00:00:00 ago)
Process ID 36729
Log Read Checkpoint Oracle Integrated Redo Logs
First Record
SCN 3.3405189667 (16290091555)
===============================
Additional Information
===============================
Checking the SCN with INFO EXTRACT XXX SHOWCH command one can see that the SCN in extract is pointing to a deleted archive file
Get data from Database
oracle@my_server:/oracle_db/db2/db_igt/arch>% ls -ltr | head -10
total 59342928
-rw-r----- 1 oracle dba 372660224 May 20 15:44 arch0001_137783_827755274.arc
-rw-r----- 1 oracle dba 371138560 May 20 15:44 arch0001_137784_827755274.arc
-rw-r----- 1 oracle dba 393000960 May 20 15:44 arch0001_137785_827755274.arc
-rw-r----- 1 oracle dba 372824064 May 20 15:45 arch0001_137786_827755274.arc
-rw-r----- 1 oracle dba 384171008 May 20 15:46 arch0001_137787_827755274.arc
-rw-r----- 1 oracle dba 491667968 May 20 15:49 arch0001_137788_827755274.arc
-rw-r----- 1 oracle dba 489092608 May 20 15:51 arch0001_137789_827755274.arc
-rw-r----- 1 oracle dba 377072128 May 20 15:53 arch0001_137790_827755274.arc
-rw-r----- 1 oracle dba 379522048 May 20 15:55 arch0001_137791_827755274.arc
SELECT recid,
name,
first_change#,
next_change#,
TO_CHAR(first_time, 'YYYYMMDD hh24:mi:ss') AS first_time
FROM V$ARCHIVED_LOG
WHERE name LIKE '%arch0001_137783_827755274%';
recid name
------- --------------------------------------------------------
137782 /oracle_db/db2/db_igt/arch/arch0001_137783_827755274.arc
first_change# next_change# first_time
------------- ------------ -----------------
16290091555 16290177738 20180520 13:23:04
SELECT dbid, current_scn FROM V$DATABASE;
dbid current_scn
----------- -----------
1066039690 16307173674
Get data from Extract
GGSCI (my_server) 27> INFO EXTRACT EXT_I_05 SHOWCH
EXTRACT EXT_I_05 Last Started 2018-05-16 07:53 Status ABENDED
Checkpoint Lag 00:00:06 (updated 265:36:17 ago)
Log Read Checkpoint Oracle Integrated Redo Logs
2018-05-10 07:13:58
SCN 3.3213072676 (16097974564)
Current Checkpoint Detail:
Read Checkpoint #1
Oracle Integrated Redo Log
Startup Checkpoint (starting position in the data source):
Timestamp: 2015-08-09 08:42:51.000000
SCN: Not available
Recovery Checkpoint (position of oldest unprocessed transaction in the data source):
Timestamp: 2018-05-10 07:13:58.000000
SCN: 3.3213072615 (16097974503)
Current Checkpoint (position of last record read in the data source):
Timestamp: 2018-05-10 07:13:58.000000
SCN: 3.3213072676 (16097974564)
BR Previous Recovery Checkpoint:
Timestamp: 2018-01-29 06:48:22.685278
SCN: Not available
BR Begin Recovery Checkpoint:
Timestamp: 2018-05-10 05:21:30.000000
SCN: 3.3212132747 (16097034635)
BR End Recovery Checkpoint:
Timestamp: 2018-05-10 05:21:30.000000
SCN: 3.3212132747 (16097034635)
Write Checkpoint #1
GGS Log Trail
Current Checkpoint (current write position):
Sequence #: 363
RBA: 1495
Timestamp: 2018-05-10 07:14:04.547894
Extract Trail: /software/ogg/1212/dirdat/05/out/ei
Trail Type: EXTTRAIL
Header:
Version = 2
Record Source = A
Type = 13
# Input Checkpoints = 1
# Output Checkpoints = 1
File Information:
Block Size = 2048
Max Blocks = 100
Record Length = 2048
Current Offset = 0
Configuration:
Data Source = 3
Transaction Integrity = 1
Task Type = 0
Status:
Start Time = 2018-05-16 07:53:24
Last Update Time = 2018-05-10 07:14:04
Stop Status = A
Last Result = 0
So in archive logs, the first available SCN is 16290091555 starting at 20180520 13:23:04
But the extract is expecting to process SCN 16097974503 from 2018-05-10 07:13:58.
The latest available archive file start with first_change# 16290091555 but extract expect to process SCN starting from 16097974503.
Since the archive files were deleted, the only option is to reset the extract, by register and register it again to the database.
Once that was done, the SCN in Golden Gate extract was in sync with SCN in database.