Oracle mechanics

21.06.2012

ORA-01089 при запросах через dblink к Active Data Guard 11.2.0.3

Filed under: Active Data Guard,error,Oracle,remote — Игорь Усольцев @ 00:14
Tags: , ,

В конфигурации Read Only Standby (2-node RAC 11.2.0.3) with Redo Apply (такой кластерный Active Data Guard) после остановки инстанса #1 (на котором выполняется накат логов) командой shutdown abort наблюдаются следующие интересные вещи:

1) Остающий рабочим инстанс #2 закрывает доступ к файлам бд – автоматически переходя в состояние mounted:

Reconfiguration started (old inc 48, new inc 50)
 List of instances:
 2 (myinst: 2)
 ...
Reconfiguration complete
Recovery session aborted due to instance crash
Close the database due to aborted recovery session
SMON: disabling tx recovery
All dispatchers and shared servers shutdown
CLOSE: killing server sessions.
CLOSE: all sessions shutdown successfully.
SMON: disabling tx recovery
SMON: disabling cache recovery

, и не возвращается в состояние READ ONLY в автоматическом режиме после рестарта инстанса #1 — что само по себе не совсем укладывается в концепцию Unbreakable, но, по крайней мере, подробно отражено в alert.log

2) после ручного возвращения инстанса #2 в состояние READ ONLY:

SQL> alter database open read only;

Database altered.

вне зависимости от состояния инстанса #1 и статуса процесса MRP0 (REDO APPLY) на инстансе #1, запросы через db link к инстансу #2 завершаются ошибкой ORA-01089 с длииинным – в нескольких минут — таймаутом:

SQL> select * from dual@stby_i2;

select * from dual@stby_i2

ORA-01089: immediate shutdown in progress - no operations are permitted
ORA-02063: preceding line from STBY_I2
Process ID: 20342
Session ID: 745 Serial number: 7359

Elapsed: 00:06:03.04

Что в статистике active standby инстанса #2 отображается в виде многократного ожидания (до начала выполнения запроса — SQL_ID=NULL):

11.2.0.3.@ SQL> select sql_id, event, count(*), max(p1text) as p1_desc, min(p1), max(p1)
  2    from v$active_session_history
  3   where SESSION_ID = 745
  4     and session_serial# = 7359
  5     and sample_id >= 159748
  6   group by sql_id, event
  7  /

SQL_ID EVENT                                     COUNT(*) P1_DESC MIN(P1) MAX(P1)
------ ----------------------------------------- -------- ------- ------- -------
       Global transaction acquire instance locks       59 retries       0      58

В то же время на инстансе #1 (после перезапуска standby инстанса в read only mode) проблем не наблюдается — запросы через db link выполняются без ошибок, несмотря на то что формально оба инстанса находятся в одинаково корректных состояниях:

SQL> select i.THREAD#,
  2         d.LOG_MODE,
  3         d.CONTROLFILE_TYPE,
  4         d.OPEN_RESETLOGS,
  5         d.OPEN_MODE,
  6         d.DATABASE_ROLE,
  7         d.PLATFORM_NAME,
  8         i.VERSION,
  9         i.STATUS,
 10         i.PARALLEL,
 11         i.LOGINS,
 12         i.DATABASE_STATUS,
 13         i.INSTANCE_ROLE,
 14         i.ACTIVE_STATE
 15    from gv$database d, gv$instance i
 16   where d.INST_ID = i.INST_ID
 17  /

THREAD# LOG_MODE   CONTROLFILE_TYPE OPEN_RESETLOGS OPEN_MODE  DATABASE_ROLE    PLATFORM_NAME    VERSION    STATUS PARALLEL LOGINS  DATABASE_STATUS INSTANCE_ROLE    ACTIVE_STATE
------- ---------- ---------------- -------------- ---------- ---------------- ---------------- ---------- ------ -------- ------- --------------- ---------------- ------------
      1 ARCHIVELOG STANDBY          REQUIRED       READ ONLY  PHYSICAL STANDBY Linux x86 64-bit 11.2.0.3.0 OPEN   YES      ALLOWED ACTIVE          PRIMARY_INSTANCE NORMAL
                                                   WITH APPLY

      2 ARCHIVELOG STANDBY          REQUIRED       READ ONLY  PHYSICAL STANDBY Linux x86 64-bit 11.2.0.3.0 OPEN   YES      ALLOWED ACTIVE          PRIMARY_INSTANCE NORMAL
                                                   WITH APPLY

с единственным отличием — накат логов штатно выполняется на ноде #1:

 SQL> select to_char(inst_id) inst_id, status from gv$managed_standby where process='MRP0';

INST_ID    STATUS
---------- ------------
1          WAIT_FOR_LOG

Сложилось впечатление, что при выполнении команд ALTER DATABASE OPEN READ ONLY | OPEN READ WRITE есть проблема, связанная с некорректным ПЕРЕзапуском функционала SMON transaction recovery (или какой-то составляющей из этой области?), наблюдаемая и на standby database, и на обычной primary database – специалистам большого Oracle известная — Bug 13724193 – ORA-1089 over database link [ID 13724193.8]:

A SQL command using a DB link to a primary database that was open could report that a shutdown was in progress if the primary instance had not been restarted since it transitioned from being an “open read only” standby

Workaround
Restart the primary instance.

Известный мне метод отключения | включения отложенного SMON tx recovery с использованием event 10513 не позволяет сэмулировать проблему

Вышеупомянутый для primary database workaround типа RESTART, естественно, помогает и в описанном выше случае для active standby инстанса #2

Кроме того, в случае остановки инстанса #1 командой shutdown immediate:

Shutting down instance (immediate)
Shutting down instance: further logons disabled
...
MRP0: Background Media Recovery cancelled with status 16037
Errors in file /opt/oracle/admin/diag/rdbms/..._pr00_19604.trc:
ORA-16037: user requested cancel of managed recovery operation
...
MRP0: Background Media Recovery process shutdown (stby_i1)
...
ALTER DATABASE CLOSE NORMAL

— системный процесс MRP0 (Managed Standby Recovery Process, выполняющий накат логов) останавливается корректно по пользовательскому запросу.

Как следствие standby инстанс #2 доступ к бд не закрывает, tx recovery не отключает и остаётся доступным в состоянии READ ONLY:

Reconfiguration started (old inc 42, new inc 44)
List of instances:
 2 (myinst: 2)
 Global Resource Directory frozen
 ...
Reconfiguration complete

P.S. Собственно, мониторинг обновления matview, использующего запросы у удалённой кластерной Active Data Guard бд, хронологически отражающий проблему:

SQL> select rd.STATUS,
2         rd.ERROR#,
3         rd.ACTUAL_START_DATE,
4         rd.RUN_DURATION,
5         rd.ADDITIONAL_INFO
6    from dba_scheduler_job_run_details rd
7   where rd.job_name = 'REMOTE_MATVIEW_01'
8    order by log_date
9  /

STATUS     ERROR# ACTUAL_START_DATE                 RUN_DURATION   ADDITIONAL_INFO
---------- ------ --------------------------------- -------------- --------------------------------------------------------------------------------
SUCCEEDED       0 07-JUN-12 12.50.00.011119 +04:00  +000 00:01:37  -- успешное обновление MVIEW, запрос случайно (LOAD_BALANCE=on) попал на standby #1
...
SUCCEEDED       0 07-JUN-12 15.50.00.008691 +04:00  +000 00:05:37  -- аналогично, но со значительно большим временем выполнения
...
FAILED      12008 07-JUN-12 16.30.00.002733 +04:00  +000 00:06:09  ORA-12008: ошибка в пути обновления материализованного представления
                                                                   ORA-12801: ошибка в сервере P003 параллельного запроса
                                                                   ORA-04052: ошибка во время поиска удаленного объекта SCOTT.REMOTE_TABLE@REMOTE_DB
                                                                   ORA-00604: ошибка на рекурсивном SQL-уровне 2
                                                                   ORA-01089: никакие действия не разрешены, т.к. идет срочный останов
                                                                   ORA-02063: предшествующий line из REMOTE_DB
                                                                   ORA-06512: на  "SYS.DBMS_SNAPSHOT", line 2563
                                                                   ORA-06512: на  "SYS.DBMS_SNAPSHOT", line 2776
                                                                   ORA-06512: на  "SYS.DBMS_SNAPSHOT", line 2745
...
SUCCEEDED       0 07-JUN-12 17.10.00.003701 +04:00  +000 00:03:35

-- *** active standby instance #2 restart ***

SUCCEEDED       0 07-JUN-12 17.22.40.030187 +04:00  +000 00:00:36  -- успешное обновление MVIEW на standby #1 или #2
SUCCEEDED       0 07-JUN-12 17.25.05.293906 +04:00  +000 00:00:31  -- со штатным временем выполнения
...

Добавить комментарий »

Комментариев нет.

RSS feed for comments on this post. TrackBack URI

Добавить комментарий

Заполните поля или щелкните по значку, чтобы оставить свой комментарий:

Логотип WordPress.com

Для комментария используется ваша учётная запись WordPress.com. Выход / Изменить )

Фотография Twitter

Для комментария используется ваша учётная запись Twitter. Выход / Изменить )

Фотография Facebook

Для комментария используется ваша учётная запись Facebook. Выход / Изменить )

Google+ photo

Для комментария используется ваша учётная запись Google+. Выход / Изменить )

Connecting to %s

Блог на WordPress.com.

%d такие блоггеры, как: