miércoles, 29 de julio de 2015

Dbvisit Replicate with error ORA-01502: index 'DBVREP.DBRSPK_MINE_SESSION_AUDIT_HIST' or partition of such index is in unusable state (DBD ERROR: OCIStmtExecute)

He estado trabajando en la configuración de una plataforma de replicación con Oracle Database Standard Edition en RAC y el producto Dbvisit Replicate 2.7.12.

La configuración tiene sus cosas, ya que el sitio primario replica a un sitio en la nube, por tanto, hay algunos inconvenientes que se han tenido que ajustar, principalmente asociado al ancho de banda del canal de comunicación.

Por otro lado, ha pesar que tome como referencia el nivel transaccional de las bases de datos de producción, para establecer el monto de datos que podrían ser enviados al sitio alterno, me he llevado al sorpresa, que el monto y tamaño de los archivos PLOG que genera la herramienta, con la información que debe ser replicada al sitio alterno, es por mucho, superior a la información de redolog que genera la base de datos. Estamos hablando en términos de las bases de datos de este cliente en específico y que no necesariamente pueda ser el mismo caso en otra infraestructura, una relación de 1 a 3 apróximadamente.

Bueno esto que les cuento es solamente introductorio. Lo que realmente nos trae aquí el día de hoy, es que he notado un poco frágil el nivel de confianza de dicho producto. Su instalación y configuración es excelente y fácil de realizar en el momento que conoces la infraestructura y el asistente. Pero se quiebra fácilmente ante tantos niveles de conflictos que deben ser solucionados, mientras se estabiliza la plataforma.

Uno de esos errores extraños y que quise documentar es el de esta noche. Algunos de los procesos de replicación en el sitio principalmente se encontraban corriendo, pero uno de ellos indicaba que estaba en modo progreso.
Al bajar los servicios y volvernos a iniciar, obtuve el error ORA-01502 indicándome que uno de los indices de unas de las tablas que maneja el esquema de replicación, no era utilizable. En pocas palabras estaba "CORRUPTO".

La solución no fue complicada. Me conecté con el usuario dueño del esquema, procedí a recrear el índice, subí los procesos y asunto resuelto.
Aquí el asunto, es que me dí cuenta, cerca del medio día de hoy y ya habían pasado un poco más de once horas desde el problema.
Moraleja: No se puede dejar tanto tiempo sin monitorear el estado de salud de la solución.

[user@server-test01 ~]$ sudo su - oracle
[sudo] password for user:
oracle@server-test01[ORCL1] ~$ cd replicate
oracle@server-test01[ORCL1] replicate$ cd DB-REPLICATE
oracle@server-test01[ORCL1] DB-REPLICATE$ ./start-console.sh
Initializing......done
DDC loaded from database (441 variables).
Dbvisit Replicate version 2.7.12.4968
Copyright (C) Dbvisit Software Limited.  All rights reserved.

| Dbvisit Replicate 2.7.12.4968(MAX edition) - Fully Licensed
Could not connect to MINE process. Operation now in progress.
APPLY IS running. Currently at plog 5293 and SCN 3867534287 (07/29/2015 00:59:53).
MINE1 IS running. Currently at plog 472 and SCN 56279086 (07/29/2015 11:22:19).
APPLY1 IS running. Currently at plog 472 and SCN 56279052 (07/29/2015 11:22:12).

Progress of replication DB-REPLICATE:MINE->APPLY: total/this execution (stale)
--------------------------------------------------------------------------------------------------------------------------------------------
ABANKS.SSS_ERRORES_REPLICACION_CAFSA:---%  Mine:0/0      Unrecov:0/0         Applied:5031438/1704780 Conflicts:0/0   Last:29/07/2015 00:44:30/OK
--------------------------------------------------------------------------------------------------------------------------------------------
1 tables listed (out of 59 total).
Progress of replication DB-REPLICATE:MINE1->APPLY1: total/this execution (stale)
--------------------------------------------------------------------------------------------------------------------------------------------
ABANKS.ME_DEFINICION_ENCUESTAS:---%  Mine:0/0            Unrecov:0/0         Applied:2/0         Conflicts:2/0       Last:--/--
ABANKS.SYS_EXPORT_FULL_01:    ---%  Mine:0/0             Unrecov:0/0         Applied:1/0         Conflicts:1/0       Last:--/--
--------------------------------------------------------------------------------------------------------------------------------------------
2 tables listed (out of 866 total).
dbvrep> shutdown all
Dbvisit Replicate APPLY process shutting down.
Dbvisit Replicate MINE1 process shutting down.
Dbvisit Replicate APPLY1 process shutting down.
Shutdown of MINE failed: -2: Operation now in progress
                                                                                                                                             dbvrep> exit
oracle@server-test01[ORCL1] DB-REPLICATE$ ps -ef|grep dbvrep
oracle   45252 43326  0 11:37 pts/1    00:00:00 grep dbvrep
oracle   64573     1  5 Jul27 ?        02:11:39 dbvrep APPLY1 A --daemon --ddcfile /home/oracle/replicate/ANODO/ANODO-APPLY1.ddc start APPLY1
oracle   64609     1 13 Jul27 ?        05:02:18 dbvrep MINE ANO --daemon --ddcfile /home/oracle/replicate/ANODO/ANODO-MINE.ddc start MINE
oracle@server-test01[ORCL1] DB-REPLICATE$ ./arrancar
Initializing......done
DDC loaded from database (441 variables).
Dbvisit Replicate version 2.7.12.4968
Copyright (C) Dbvisit Software Limited.  All rights reserved.
DDC file /home/oracle/replicate/DB-REPLICATE/DB-REPLICATE-APPLY1.ddc loaded.
Starting process APPLY1...started
Initializing......done
DDC loaded from database (441 variables).
Dbvisit Replicate version 2.7.12.4968
Copyright (C) Dbvisit Software Limited.  All rights reserved.
DDC file /home/oracle/replicate/DB-REPLICATE/DB-REPLICATE-MINE.ddc loaded.
Starting process MINE...started
oracle@server-test01[ORCL1] DB-REPLICATE$ FATAL-3549: Execute failed on SQL 'delete from dbrsmine_session_audit_hist where (create_date, sid) in (
select max(create_date), sid
from dbrsmine_session_audit_hist
where plog_sequence
and ddc_id = ? and mine_process_name = ?
group by sid)
and ddc_id = ? and mine_process_name = ?' with error ORA-01502: index 'DBVREP.DBRSPK_MINE_SESSION_AUDIT_HIST' or partition of such index is in unusable state (DBD ERROR: OCIStmtExecute)
Trying to create support package now.
Packaging into ZIP file: /home/oracle/replicate/DB-REPLICATE/log/dbvisit_support_dbvrep_DB-REPLICATE_MINE.mmf6.zip for process MINE, addinfo []
Trying retrieving +RECO/DB-REPLICATE/redo03b.log from ASM using asmcmd. If this fails, restart with NOASMDIRECT added to the SUPPORT command. This requires Oracle 11g or newer.
Trying retrieving +RECO/DB-REPLICATE/redo02b.log from ASM using asmcmd. If this fails, restart with NOASMDIRECT added to the SUPPORT command. This requires Oracle 11g or newer.
Packaging data from database. If this fails, restart SUPPORT PACKAGE with NODB option.
Zip file created: /home/oracle/replicate/DB-REPLICATE/log/dbvisit_support_dbvrep_DB-REPLICATE_MINE.mmf6.zip (status: 1)

oracle@server-test01[ORCL1] DB-REPLICATE$ . oraenv
ORACLE_SID = [ORCL1] ? DB-REPLICATE1
The Oracle base remains unchanged with value /u01/app/oracle
oracle@server-test01[DB-REPLICATE1] DB-REPLICATE$ sqlplus dbvrep/manager

SQL*Plus: Release 11.2.0.4.0 Production on Wed Jul 29 11:39:13 2015

Copyright (c) 1982, 2013, Oracle.  All rights reserved.


Connected to:
Oracle Database 11g Release 11.2.0.4.0 - 64bit Production
With the Real Application Clusters and Automatic Storage Management options

SQL> alter index DBRSPK_MINE_SESSION_AUDIT_HIST rebuild;

Index altered.

SQL> exit
Disconnected from Oracle Database 11g Release 11.2.0.4.0 - 64bit Production
With the Real Application Clusters and Automatic Storage Management options
oracle@server-test01[DB-REPLICATE1] DB-REPLICATE$ ps -ef|grep dbvrep
oracle   45582     1 32 11:37 ?        00:00:34 dbvrep APPLY1 A --daemon --ddcfile /home/oracle/replicate/DB-REPLICATE/DB-REPLICATE-APPLY1.ddc start APPLY1
oracle   46833 43326  0 11:39 pts/1    00:00:00 grep dbvrep
oracle   64573     1  5 Jul27 ?        02:11:46 dbvrep APPLY1 A --daemon --ddcfile /home/oracle/replicate/ANODO/ANODO-APPLY1.ddc start APPLY1
oracle   64609     1 13 Jul27 ?        05:02:33 dbvrep MINE ANO --daemon --ddcfile /home/oracle/replicate/ANODO/ANODO-MINE.ddc start MINE
oracle@server-test01[DB-REPLICATE1] DB-REPLICATE$ kill -9 45582
oracle@server-test01[DB-REPLICATE1] DB-REPLICATE$ ./arrancar
Initializing......done
DDC loaded from database (441 variables).
Dbvisit Replicate version 2.7.12.4968
Copyright (C) Dbvisit Software Limited.  All rights reserved.
DDC file /home/oracle/replicate/DB-REPLICATE/DB-REPLICATE-APPLY1.ddc loaded.
Starting process APPLY1...started
Initializing......done
DDC loaded from database (441 variables).
Dbvisit Replicate version 2.7.12.4968
Copyright (C) Dbvisit Software Limited.  All rights reserved.
DDC file /home/oracle/replicate/DB-REPLICATE/DB-REPLICATE-MINE.ddc loaded.
Starting process MINE...started
oracle@server-test01[DB-REPLICATE1] DB-REPLICATE$

- Dbvisit Replicate 2.7.12.4968(MAX edition) - Fully Licensed
MINE IS running. Currently at plog 5317 (redo sequence 17924 [1] 16605 [2]) and SCN 3869789161 (07/29/2015 06:45:04).
APPLY IS running. Currently at plog 5307 and SCN 3867677431 (07/29/2015 03:45:38).
MINE1 IS running. Currently at plog 473 and SCN 56311319 (07/29/2015 11:32:54).
APPLY1 IS running. Currently at plog 473 and SCN 56311018 (07/29/2015 11:32:51).

Progress of replication AAGEN:MINE->APPLY: total/this execution

Después de algunos minutos de haber reiniciado el proceso, ya la replicación estaba sincronizada.

- Dbvisit Replicate 2.7.12.4968(MAX edition) - Fully Licensed
MINE IS running. Currently at plog 5348 (redo sequence 17939 [1] 16621 [2]) and SCN 3870601339 (07/29/2015 12:03:45).
APPLY IS running. Currently at plog 5348 and SCN 3870601277 (07/29/2015 12:03:44).
MINE1 IS running. Currently at plog 473 and SCN 56384659 (07/29/2015 11:48:30).
APPLY1 IS running. Currently at plog 473 and SCN 56384344 (07/29/2015 11:48:19).
Progress of replication AAGEN:MINE->APPLY: total/this execution

No hay comentarios:

Publicar un comentario en la entrada

Te agradezco tus comentarios. Te esperamos de vuelta.