Добро пожаловать в форум, Guest  >>   Войти | Регистрация | Поиск | Правила | В избранное | Подписаться
Все форумы / Oracle Новый топик    Ответить
 Goldengate - неожиданный повтор уже применённых изменений  [new]
GL
Member

Откуда: Харьков
Сообщений: 1513
Конфигурация:

Источник: OEL 5.5 x86_64, Oracle 11.2.0.3 x86_64, RAC, ASM, GoldenGate 11.2.1.0.5, Intergated Extract
Приёмник: OEL 5.5 x86_64, Oracle 11.2.0.3 x86_64, ASM, GoldenGate 11.2.1.0.5

В какой-то момент на репликате начали сыпаться дискарды по вставке строк с дублирующими первичными ключами. Все PK - синтетические, из сиквенсов. Они действительно есть и на источнике и на приёмнике. Всё выглядит так, будто goldengate либо решил во второй раз захватить изменения, либо во второй раз применить. По моим наблюдениям - это второй раз за год.

Кто-нибудь сталкивался?
11 ноя 14, 16:50    [16829643]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
Alexander Ryndin
Member

Откуда:
Сообщений: 4917
Блог
Чудес не бывает. Где то значит криво сконфигурено. Сначала определите, где косяк, а то у вас догадки... Ну и использовать ie на 11.2.0.5 - вы экстремальных, однако
11 ноя 14, 17:50    [16830220]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
GL
Member

Откуда: Харьков
Сообщений: 1513
Alexander Ryndin,

Косяк таки в том, что данные были дважды захвачены, переданы и применены.
В тот момент на каптурящей ноде:
+ Алерт
Tue Nov 11 11:57:15 2014
LOGMINER: End mining logfile for session 7 thread 1 sequence 20922, +FRA/my_db/onlinelog/group_2.258.766873199
LOGMINER: Begin mining logfile for session 7 thread 1 sequence 20923, +FRA/my_db/onlinelog/group_3.259.766873203
Tue Nov 11 11:57:15 2014
LOGMINER: End mining logfile for session 5 thread 1 sequence 20922, +FRA/my_db/onlinelog/group_2.258.766873199
LOGMINER: Begin mining logfile for session 5 thread 1 sequence 20923, +FRA/my_db/onlinelog/group_3.259.766873203
Tue Nov 11 12:02:00 2014
Thread 2 advanced to log sequence 16194 (LGWR switch)
Current log# 9 seq# 16194 mem# 0: +FRA/my_db/onlinelog/group_9.265.766874489
Current log# 9 seq# 16194 mem# 1: +DATA/my_db/onlinelog/group_9.271.766874491
Tue Nov 11 12:02:00 2014
LNS: Standby redo logfile selected for thread 2 sequence 16194 for destination LOG_ARCHIVE_DEST_2
Tue Nov 11 12:02:01 2014
LOGMINER: End mining logfile for session 7 thread 2 sequence 16193, +FRA/my_db/onlinelog/group_8.264.766874485
LOGMINER: Begin mining logfile for session 7 thread 2 sequence 16194, +FRA/my_db/onlinelog/group_9.265.766874489
Tue Nov 11 12:02:02 2014
Archived Log entry 74227 added for thread 2 sequence 16193 ID 0xdef967e8 dest 1:
Tue Nov 11 12:02:45 2014
System State dumped to trace file /u01/app/oracle/diag/rdbms/my_db/my_db2/trace/my_db2_ms05_7958.trc
Tue Nov 11 12:03:00 2014
krvxerpt: Errors detected in process 94, role builder.
krvxmrs: Leaving by exception: 1341
Errors in file /u01/app/oracle/diag/rdbms/my_db/my_db2/trace/my_db2_ms05_7958.trc:
ORA-01341: LogMiner out-of-memory
LOGMINER: session#=5 (OGG$CAP_EOLAP), builder MS05 pid=94 OS id=7958 sid=925 stopped
Errors in file /u01/app/oracle/diag/rdbms/my_db/my_db2/trace/my_db2_ms05_7958.trc:
ORA-01341: LogMiner out-of-memory
Tue Nov 11 12:03:00 2014
LogMiner process death detected
Tue Nov 11 12:03:04 2014
LOGMINER: session#=5 (OGG$CAP_EOLAP), preparer MS07 pid=104 OS id=7962 sid=731 stopped
Tue Nov 11 12:03:04 2014
LOGMINER: session#=5 (OGG$CAP_EOLAP), preparer MS06 pid=96 OS id=7960 sid=8 stopped
Tue Nov 11 12:03:04 2014
LOGMINER: session#=5 (OGG$CAP_EOLAP), reader MS04 pid=84 OS id=7956 sid=25 stopped
System State dumped to trace file /u01/app/oracle/diag/rdbms/my_db/my_db2/trace/my_db2_ora_7954.trc
Non critical error ORA-00602 caught while writing to trace file "/u01/app/oracle/diag/rdbms/my_db/my_db2/trace/my_db2_ora_7954.trc"
Error message: ORA-00602: internal programming exception

Writing to the above trace file is disabled for now on...
Tue Nov 11 12:03:13 2014
OGG Capture client successfully detached from GoldenGate Capture OGG$CAP_EOLAP (OS pid=7954).
Tue Nov 11 12:05:06 2014
Auto-tuning: Shutting down background process GTX1
Tue Nov 11 12:05:50 2014
GoldenGate Capture:OGG$CAP_EOLAP cleared _SKIP_LCR_FOR_ASSERT
GoldenGate Capture: OGG$CAP_EOLAP
setting IGNORE_UNSUPPORTED_TABLE for table (*)
GoldenGate Capture:OGG$CAP_EOLAP setting _FILTER_PARTIAL_ROLLBACK:
Setting XOUT_CLIENT_EXISTS to Y for Capture: OGG$CAP_EOLAP
Tue Nov 11 12:05:50 2014
Starting persistent Logminer Session with sid = 5 for GoldenGate Capture OGG$CAP_EOLAP (OS id=23621).
LOGMINER: Parameters summary for session# = 5
LOGMINER: Number of processes = 4, Transaction Chunk Size = 1
LOGMINER: Memory Size = 999M, Checkpoint interval = 1000M
LOGMINER: SpillScn 0, ResetLogScn 1
LOGMINER: summary for session# = 5
LOGMINER: StartScn: 81846354602 (0x0013.0e6c42aa)
LOGMINER: EndScn: 0
LOGMINER: HighConsumedScn: 81846354602 (0x0013.0e6c42aa)
LOGMINER: session_flag: 0x4f0
LOGMINER: DDL CKPT is on.
LOGMINER: Read buffers: 64
LOGMINER: Memory LWM limit: 10M, 98%
LOGMINER: Memory Release Limit: 15000
LOGMINER: LowCkptScn: 81845963136 (0x0013.0e664980)
LOGMINER: HighCkptScn: 81845963137 (0x0013.0e664981)
LOGMINER: SkipScn: 81845963136 (0x0013.0e664980)
Tue Nov 11 12:05:50 2014
LOGMINER: session#=5 (OGG$CAP_EOLAP), reader MS05 pid=515 OS id=23623 sid=998 started
Tue Nov 11 12:05:50 2014
LOGMINER: session#=5 (OGG$CAP_EOLAP), builder MS07 pid=520 OS id=23627 sid=381 started
Tue Nov 11 12:05:50 2014
LOGMINER: session#=5 (OGG$CAP_EOLAP), preparer MS06 pid=524 OS id=23630 sid=737 started
Tue Nov 11 12:05:50 2014
LOGMINER: session#=5 (OGG$CAP_EOLAP), preparer MS04 pid=525 OS id=23633 sid=818 started
OGG Capture client successfully attached to GoldenGate Capture OGG$CAP_EOLAP to receive uncommitted changes with pid=510 OS id=23621.
LOGMINER: Begin mining logfile for session 5 thread 1 sequence 20919, +FRA/my_db/archivelog/2014_11_11/thread_1_seq_20919.583.863337369
LOGMINER: Begin mining logfile for session 5 thread 2 sequence 16191, +FRA/my_db/archivelog/2014_11_11/thread_2_seq_16191.395.863343021
LOGMINER: End mining logfile for session 5 thread 1 sequence 20919, +FRA/my_db/archivelog/2014_11_11/thread_1_seq_20919.583.863337369
LOGMINER: Begin mining logfile for session 5 thread 1 sequence 20920, +FRA/my_db/onlinelog/group_5.261.766873211
Tue Nov 11 12:06:03 2014
LOGMINER: End mining logfile for session 5 thread 1 sequence 20920, +FRA/my_db/onlinelog/group_5.261.766873211
LOGMINER: Begin mining logfile for session 5 thread 1 sequence 20921, +FRA/my_db/onlinelog/group_1.257.766873197
LOGMINER: End mining logfile for session 5 thread 2 sequence 16191, +FRA/my_db/archivelog/2014_11_11/thread_2_seq_16191.395.863343021
LOGMINER: Begin mining logfile for session 5 thread 2 sequence 16192, +FRA/my_db/onlinelog/group_7.263.766874481
LOGMINER: End mining logfile for session 5 thread 2 sequence 16192, +FRA/my_db/onlinelog/group_7.263.766874481
LOGMINER: Begin mining logfile for session 5 thread 2 sequence 16193, +FRA/my_db/onlinelog/group_8.264.766874485
LOGMINER: End mining logfile for session 5 thread 1 sequence 20921, +FRA/my_db/onlinelog/group_1.257.766873197
LOGMINER: Begin mining logfile for session 5 thread 1 sequence 20922, +FRA/my_db/onlinelog/group_2.258.766873199
Tue Nov 11 12:06:15 2014
LOGMINER: End mining logfile for session 5 thread 1 sequence 20922, +FRA/my_db/onlinelog/group_2.258.766873199
LOGMINER: Begin mining logfile for session 5 thread 1 sequence 20923, +FRA/my_db/onlinelog/group_3.259.766873203
LOGMINER: End mining logfile for session 5 thread 2 sequence 16193, +FRA/my_db/onlinelog/group_8.264.766874485
LOGMINER: Begin mining logfile for session 5 thread 2 sequence 16194, +FRA/my_db/onlinelog/group_9.265.766874489

Вопрос - почему, пусть даже аварийный, рестарт экстракта привёл к таким последствиям?

Экстракт создавался как:
add extract eolap, integrated tranlog, begin now
add exttrail ./dirdat/e1, extract eolap
register extract eolap, database

Конфигурация экстракта:
EXTRACT eolap
USERID ogg, PASSWORD ...
EXTTRAIL ./dirdat/e1
TRANLOGOPTIONS excludeuser ogg
TABLE ...;
...

GoldenGate'ом занимаюсь мало, поэтому буду рад любым рекомендациям или наводящим вопросам.

Да, если это действительно критично, версию GoldenGate'а поменяю. Но, вроде, пока работало.
11 ноя 14, 18:41    [16830563]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
Alexander Ryndin
Member

Откуда:
Сообщений: 4917
Блог
А как определили, что данные в trail-файле задублированы? Logdump?
На системе, кстати, запускаются parallel dml?

P.S. версия, конечно, желательно обновить - сейчас уже 11.2.1.0.27 есть. Нужно понимать, что 11.2.1.0.5 это же буквально пара месяцев после релиза 11.2.1, которая начала поддерживать IE
11 ноя 14, 19:24    [16830813]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
GL
Member

Откуда: Харьков
Сообщений: 1513
Alexander Ryndin,

C logdump'ом пока не довелось познакомиться.
Определили по анализу логов репликата - не было повторений trail-файлов, но было аномально высокое их количество сразу после рестарта экстракта - и логмайнеру на приёмнике.

Версию обновлю. Спасибою
11 ноя 14, 19:40    [16830906]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
Alexander Ryndin
Member

Откуда:
Сообщений: 4917
Блог
GL,

Большое количество trail-файлов ничего не означает. Возможно, это просто была большая параллельная транзакция. Возможно такое, что у вас на источнике выполняются Parallel DML?

P.S. если дадите доступ, то можно поглядеть на trail, тогда точно будет понятно, есть ли дублирование транзакции, или это транзакция с parallel dml развалилась на 2 транзакции.
11 ноя 14, 19:47    [16830939]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
Dimitry Sibiryakov
Member

Откуда:
Сообщений: 51779

Alexander Ryndin
Возможно, это просто была большая параллельная транзакция.

Гораздо вероятнее, что экстракт при крэше забыл о том, что некоторую часть лога уже
сбросил в трейл-файл и после рестарта начал писать тот же лог в новый трейл.

Posted via ActualForum NNTP Server 1.5

11 ноя 14, 20:14    [16831055]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
Alexander Ryndin
Member

Откуда:
Сообщений: 4917
Блог
Dimitry Sibiryakov
Alexander Ryndin
Возможно, это просто была большая параллельная транзакция.

Гораздо вероятнее, что экстракт при крэше забыл о том, что некоторую часть лога уже
сбросил в трейл-файл и после рестарта начал писать тот же лог в новый трейл.
Дим, теоретически все может быть... Но все это бла-бла без анализа.
11 ноя 14, 20:22    [16831091]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
Кристобаль Хозевич
Member

Откуда: тутошний
Сообщений: 250
Alexander Ryndin
Возможно, это просто была большая параллельная транзакция. Возможно такое, что у вас на источнике выполняются Parallel DML?
Нет, источник - OLTP система, там простые, короткие транзакции предсказуемых частоты и объёма. Так что, по-видимому, именно "забыл, что уже сбросил". Да и трейлы уже грохнулись - смотреть некуда :)

Кстати, а чем можно трейлы посмотреть? Я вот так и не решил для себя вопрос про исследование ошибок репликата. А если смочь покопаться в грядущих трейлах после abend'а репликата, можно было бы накопать много интересного...
11 ноя 14, 22:38    [16831631]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
Alexander Ryndin
Member

Откуда:
Сообщений: 4917
Блог
Кристобаль Хозевич
Alexander Ryndin
Возможно, это просто была большая параллельная транзакция. Возможно такое, что у вас на источнике выполняются Parallel DML?
Нет, источник - OLTP система, там простые, короткие транзакции предсказуемых частоты и объёма. Так что, по-видимому, именно "забыл, что уже сбросил". Да и трейлы уже грохнулись - смотреть некуда :)

Кстати, а чем можно трейлы посмотреть? Я вот так и не решил для себя вопрос про исследование ошибок репликата. А если смочь покопаться в грядущих трейлах после abend'а репликата, можно было бы накопать много интересного...
Трейлы посмотреть можно logdump. Я не видел такого, чтобы GoldenGate "забывал". Но тут с одной стороны очень древняя версия, а с другой RAC. Опасная комбинация.
12 ноя 14, 10:10    [16832525]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
Dimitry Sibiryakov
Member

Откуда:
Сообщений: 51779

Alexander Ryndin
Я не видел такого, чтобы GoldenGate "забывал".

У тебя logminer не падал по ООМ.

Posted via ActualForum NNTP Server 1.5

12 ноя 14, 12:17    [16833483]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
GL
Member

Откуда: Харьков
Сообщений: 1513
Dimitry Sibiryakov
Alexander Ryndin
Я не видел такого, чтобы GoldenGate "забывал".
У тебя logminer не падал по ООМ.

Тут Doc ID 1640076.1 написано, что на 11.2.0.3 эта проблема возникает всегда. Но её можно немного отсрочить :)
Так что, пожалуй, я озабочусь апгрейдом базы, а не Голденгейта.
12 ноя 14, 16:06    [16835415]     Ответить | Цитировать Сообщить модератору
 Re: Goldengate - неожиданный повтор уже применённых изменений  [new]
Alexander Ryndin
Member

Откуда:
Сообщений: 4917
Блог
GL
Dimitry Sibiryakov
пропущено...
У тебя logminer не падал по ООМ.

Тут Doc ID 1640076.1 написано, что на 11.2.0.3 эта проблема возникает всегда. Но её можно немного отсрочить :)
Так что, пожалуй, я озабочусь апгрейдом базы, а не Голденгейта.
Это тоже. Будет обновлять базу, то обязательно гляньте вот этот документ Oracle GoldenGate -- Oracle RDBMS Server Recommended Patches (Doc ID 1557031.1)
12 ноя 14, 16:47    [16835797]     Ответить | Цитировать Сообщить модератору
Все форумы / Oracle Ответить