ICT블로그

추가 (2018-09-14)

ORA-00257은 DB을 Archive log Mode로 운영중일 때 발생할 수 있는 에러입니다. Redo Log에 대한 archiving이 정상적으로 완료되지 않았을 경우, Log switch가 실패하며 DB를 정상적으로 사용할수 없습니다. (sysdba 유저 외 일반 유저는 접속불가)

이때 예상되는 문제로는 다음 2가지가 있습니다.

(1) Archiving 공간이 Full이 됨. (File system 혹은 지정한 ASM diskgroup)

(2) FRA기능을 사용할 때 FRA에 할당된 공간(=db_recovery_file_dest_size 파리미터 값)이 100%가 되어, 더 이상 archive log가 저장될 수 없을 때 발생--> ORA-19809, 19804, 19815 에러와 함께 발생하는 특징

실제 DB운영시에는 (2)번의 경우를 주의해야 하는데요, 왜냐하면 (1)번의 경우 일반적으로 File System에 대한 사용률 모니터링, ASM Diskgroup에 대한 사용률 모니터링을 통해 100% 임계치에 도달하기 전에 장애를 예방할 수 있기 때문입니다.

따라서 해당 에러 발생전 사전에 DB의 FRA기능 사용유무를 파악하고 (db_recovery_file_dest_size<>0 이면 FRA는 ON이 된것입니다.) 아카이브 Full로 인한 장애를 예방하는 것이 중요합니다.

실제 운영중인 DB가 아닐경우, 또는 개인이 학습용도로 사용하는 경우 Archive Log는 DB복구에 사용될 뿐이지 필수 파일이 아니므로, 해당 에러가 발생한다면 임의로 archive log 파일을 삭제해도 무방합니다. 단, 운영계 시스템이라면 해당 archive log가 추후 복구 등에 사용될수 있으므로 (시간적 여유가 된다면) 백업 후 archive log를 삭제하거나, 적어도 여유가되는 다른 File system이나 asm diskgroup에 아카이브 로그 파일을 move하기를 권장드립니다.

그리고 FRA기능을 꼭 써야 하는 경우가 아니라면 db_recovery_file_dest_size=0으로 하는것도 관리포인트를 줄이는 효과가 있습니다.

아래는 저의 학습과정을 기록한 것으로 skip 하셔도 무방합니다.

---------------------------------------------------------------------------------------------------------------

※ 주의! : 저의 지식 한계 내에서 문제를 파악하고 분석한 글로서, 부족하거나 잘못된 내용이 포함될 수 있습니다. 참고만 해주시길 바라며, 지적 및 조언은 언제나 환영합니다.

(1) 로그인 시 ORA-00257에러가 떨어짐 (sqlplus "/as sysdba")

sys user를 제외한 전 유저로 로그인시에도 동일한 현상 발생

(2) ORA-00257 에러를 확인한다. (E17766-03)

** archiving 영역의 공간 부족이 의심된다.

(3) alert log, trace log, 관련 제반 parameter 확인

- alert log 확인

************************************************************************

Errors in file f:\app\inseong\diag\rdbms\test1\test1\trace\test1_arc1_4720.trc:

ORA-19809: limit exceeded for recovery files

ORA-19804: cannot reclaim 32109056 bytes disk space from 4102029312 limit

ARC1: Error 19809 Creating archive log file to 'F:\APP\INSEONG\FLASH_RECOVERY_AREA\TEST1\ARCHIVELOG\2016_03_14\O1_MF_1_279_%U_.ARC'

Mon Mar 14 23:29:16 2016

Errors in file f:\app\inseong\diag\rdbms\test1\test1\trace\test1_arc3_4728.trc:

ORA-19815: WARNING: db_recovery_file_dest_size of 4102029312 bytes is 100.00% used, and has 0 remaining bytes available.

************************************************************************

You have following choices to free up space from recovery area:

1. Consider changing RMAN RETENTION POLICY. If you are using Data Guard,

   then consider changing RMAN ARCHIVELOG DELETION POLICY.

2. Back up files to tertiary device such as tape using RMAN

   BACKUP RECOVERY AREA command.

3. Add disk space and increase db_recovery_file_dest_size parameter to

   reflect the new space.

4. Delete unnecessary files using RMAN DELETE command. If an operating

   system command was used to delete files, then use RMAN CROSSCHECK and

   DELETE EXPIRED commands.

************************************************************************

Errors in file f:\app\inseong\diag\rdbms\test1\test1\trace\test1_arc3_4728.trc:

ORA-19809: limit exceeded for recovery files

ORA-19804: cannot reclaim 32109056 bytes disk space from 4102029312 limit

ARC3: Error 19809 Creating archive log file to 'F:\APP\INSEONG\FLASH_RECOVERY_AREA\TEST1\ARCHIVELOG\2016_03_14\O1_MF_1_279_%U_.ARC'

==> 정확히 1분 간격으로 해당 error 메시지가 alert.log에 기록됨.

- trace file (archive process) 확인

*** 2016-03-14 23:32:16.882

ORA-19815: WARNING: db_recovery_file_dest_size of 4102029312 bytes is 100.00% used, and has 0 remaining bytes available.

************************************************************************

You have following choices to free up space from recovery area:

1. Consider changing RMAN RETENTION POLICY. If you are using Data Guard,

   then consider changing RMAN ARCHIVELOG DELETION POLICY.

2. Back up files to tertiary device such as tape using RMAN

   BACKUP RECOVERY AREA command.

3. Add disk space and increase db_recovery_file_dest_size parameter to

   reflect the new space.

4. Delete unnecessary files using RMAN DELETE command. If an operating

   system command was used to delete files, then use RMAN CROSSCHECK and

   DELETE EXPIRED commands.

************************************************************************

ORA-19809: limit exceeded for recovery files

ORA-19804: cannot reclaim 32109056 bytes disk space from 4102029312 limit

*** 2016-03-14 23:32:17.074 4132 krsh.c

ARC3: Error 19809 Creating archive log file to 'F:\APP\INSEONG\FLASH_RECOVERY_AREA\TEST1\ARCHIVELOG\2016_03_14\O1_MF_1_279_%U_.ARC'

*** 2016-03-14 23:32:17.074 2747 krsi.c

krsi_dst_fail: dest:1 err:19809 force:0 blast:1

DDE rules only execution for: ORA 312

----- START Event Driven Actions Dump ----

---- END Event Driven Actions Dump ----

----- START DDE Actions Dump -----

Executing SYNC actions

----- START DDE Action: 'DB_STRUCTURE_INTEGRITY_CHECK' (Async) -----

Successfully dispatched

----- END DDE Action: 'DB_STRUCTURE_INTEGRITY_CHECK' (SUCCESS, 0 csec) -----

Executing ASYNC actions

----- END DDE Actions Dump (total 0 csec) -----

*** 2016-03-14 23:32:17.084 4529 kcrr.c

==> alert log, trace log의 내용은 대동소이하며, 결국 db_recovery_file_dest_size에서 설정된 한계치 만큼 archive log가 공간을 다 사용했기 때문으로 추정된다.

해결방법은 1. 필요없는 archive file 삭제

            2. db_recovery_file_dest_size 크기 확장 

두가지 정도로 정리된다.

※ no archive log mode로 운영 ==> 이것은 해결방안이 아니다.

-- 설정 변경 적용 전 몇가지 DB 설정사항 확인 및 세부 현상 확인

현재 DB는 archive log mode로 운영되고 있으며, 279번째 리두로그가 archiving 되어야 하나, 현재 archive 저장 영역 (db_recovery_file_dest_size)의 사용량이 100%이기 때문에 archive 되지 못하고 있다. (트레이스 파일 분홍색에서 확인 가능)

v$log의 조회내용이며, 현재 1, 2, 3번 리두 로그 그룹이 공통적으로 아카이빙이 되지 않았음(ARC=NO)을 확인 할 수 있다.

실제 db_recovery_file_dest_size 확인 내용 (3912M=4,102,029,312 bytes)

실제로 flash_recovery_area 영역이 한계치에 다다랐음을 알 수 있다.

주의! 이 부분은 디스크 사용량과는 별개이다.

(3) 문제해결

1. 필요없는 archive file 삭제

가장 오래된 archive log file을 삭제하여, 추가용량을 800M 정도 확보하였다.

system user로 login 시 여전히 같은 에러(ORA-00257)이 발생하는데, DB를 재시작 하면 해결될까?

Errors in file f:\app\inseong\diag\rdbms\test1\test1\trace\test1_arc3_4728.trc:

ORA-19809: limit exceeded for recovery files

ORA-19804: cannot reclaim 32109056 bytes disk space from 4102029312 limit

ARC3: Error 19809 Creating archive log file to 'F:\APP\INSEONG\FLASH_RECOVERY_AREA\TEST1\ARCHIVELOG\2016_03_15\O1_MF_1_279_%U_.ARC'

Tue Mar 15 00:11:50 2016

Active call for process 15292 user 'SYSTEM' program 'ORACLE.EXE (J002)'

SHUTDOWN: waiting for active calls to complete.

Tue Mar 15 00:12:17 2016

Errors in file f:\app\inseong\diag\rdbms\test1\test1\trace\test1_arc0_4656.trc:

ORA-19815: WARNING: db_recovery_file_dest_size of 4102029312 bytes is 100.00% used, and has 0 remaining bytes available.

shutdown immediate 를 수행한지 20여분이 지났어도 DB가 정상적으로 shutdown 되지 않는다. Ctrl+ C로 작업 중단 후 확인하자, DB가 비정상 종료(중)인걸 알수 있었다. 결국 윈도우 서비스관리(services.msc)를 통해 서비스 중단 및 재시작하였다.

SQL> startup

DB가 OPEN되지 않는다. 어떤 문제일까..

Errors in file f:\app\inseong\diag\rdbms\test1\test1\trace\test1_arc3_8992.trc:

ORA-19809: limit exceeded for recovery files

ORA-19804: cannot reclaim 33826304 bytes disk space from 4102029312 limit

ARC3: Error 19809 Creating archive log file to 'F:\APP\INSEONG\FLASH_RECOVERY_AREA\TEST1\ARCHIVELOG\2016_03_15\O1_MF_1_280_%U_.ARC'

   BACKUP RECOVERY AREA command.

3. Add disk space and increase db_recovery_file_dest_size parameter to

   reflect the new space.

4. Delete unnecessary files using RMAN DELETE command. If an operating

   system command was used to delete files, then use RMAN CROSSCHECK and

   DELETE EXPIRED commands.

************************************************************************

Errors in file f:\app\inseong\diag\rdbms\test1\test1\trace\test1_ora_16388.trc:

ORA-19809: 복구 파일에 대한 한계를 초과함

ORA-19804: 32109056바이트의 디스크 공간(4102029312 제한)을 재생할 수 없음

ARCH: Error 19809 Creating archive log file to 'F:\APP\INSEONG\FLASH_RECOVERY_AREA\TEST1\ARCHIVELOG\2016_03_15\O1_MF_1_279_%U_.ARC'

Errors in file f:\app\inseong\diag\rdbms\test1\test1\trace\test1_ora_16388.trc:

ORA-16038: 3 로그 279 시퀀스 번호는 기록될 수 없습니다

ORA-19809: 복구 파일에 대한 한계를 초과함

ORA-00312: 온라인 로그 3 스레드 1: 'F:\APP\INSEONG\ORADATA\TEST1\REDO03.LOG'

USER (ospid: 16388): terminating the instance due to error 16038

Instance terminated by USER, pid = 16388

동일한 문제로 보인다. archive log file 중 일부를 삭제했음에도 여전히 저장 공간 오류가 나는것을 이해하기가 어렵다.

해결방법 2. db_recovery_file_dest_size 크기 확장 

다행히 db_recovery_file_dest_size 는 modifiable로, alter system 명령어로 변경가능하다.

database mount 수행 후 파라미터 값 변경 --> database open까지 정상적으로 완료되었다.

※alert log 내용 참조

Instance terminated by USER, pid = 16388 --> shutdown immediate 중 Ctrl+C 로 강제 취소했을때

Tue Mar 15 00:37:50 2016

Starting ORACLE instance (normal)

LICENSE_MAX_SESSION = 0

LICENSE_SESSIONS_WARNING = 0

Picked latch-free SCN scheme 3

Using LOG_ARCHIVE_DEST_1 parameter default value as USE_DB_RECOVERY_FILE_DEST

Autotune of undo retention is turned on. 

IMODE=BR

ILAT =27

LICENSE_MAX_USERS = 0

SYS auditing is enabled

Starting up:

Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production

With the Partitioning, OLAP, Data Mining and Real Application Testing options.

Using parameter settings in server-side spfile F:\APP\INSEONG\PRODUCT\11.2.0\DATABASE\SPFILETEST1.ORA

System parameters with non-default values:

  processes                = 150

  memory_target            = 2G

  memory_max_target        = 3G

  control_files            = "F:\APP\INSEONG\ORADATA\TEST1\CONTROL01.CTL"

  control_files            = "F:\APP\INSEONG\FLASH_RECOVERY_AREA\TEST1\CONTROL02.CTL"

  db_block_size            = 8192

  compatible               = "11.2.0.0.0"

  db_recovery_file_dest    = "F:\app\inseong\flash_recovery_area"

  db_recovery_file_dest_size= 3912M  --> 변경이 필요한 parameter 값

  undo_tablespace          = "UNDOTBS1"

  remote_login_passwordfile= "EXCLUSIVE"

  audit_sys_operations     = TRUE

  db_domain                = ""

  dispatchers              = "(PROTOCOL=TCP) (SERVICE=TEST1XDB)"

  local_listener           = "LISTENER_TEST1"

  audit_file_dest          = "F:\APP\INSEONG\ADMIN\TEST1\ADUMP"

  audit_trail              = "XML"

  audit_trail              = "EXTENDED"

  db_name                  = "TEST1"

  open_cursors             = 300

  diagnostic_dest          = "F:\APP\INSEONG"

Tue Mar 15 00:37:51 2016

PMON started with pid=2, OS id=10512 

Tue Mar 15 00:37:51 2016

VKTM started with pid=3, OS id=15484 at elevated priority

VKTM running at (10)millisec precision with DBRM quantum (100)ms

Tue Mar 15 00:37:51 2016

GEN0 started with pid=4, OS id=14140 

Tue Mar 15 00:37:51 2016

DIAG started with pid=5, OS id=14836 

Tue Mar 15 00:37:52 2016

DBRM started with pid=6, OS id=16916 

Tue Mar 15 00:37:52 2016

PSP0 started with pid=7, OS id=12912 

Tue Mar 15 00:37:52 2016

DIA0 started with pid=8, OS id=12248 

Tue Mar 15 00:37:52 2016

MMAN started with pid=9, OS id=11272 

Tue Mar 15 00:37:53 2016

DBW0 started with pid=10, OS id=16336 

Tue Mar 15 00:37:53 2016

LGWR started with pid=11, OS id=17308 

Tue Mar 15 00:37:53 2016

CKPT started with pid=12, OS id=16664 

Tue Mar 15 00:37:53 2016

SMON started with pid=13, OS id=14868 

Tue Mar 15 00:37:53 2016

RECO started with pid=14, OS id=988 

Tue Mar 15 00:37:53 2016

MMON started with pid=15, OS id=16096 

starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...

starting up 1 shared server(s) ...

ORACLE_BASE from environment = F:\app\inseong

Tue Mar 15 00:37:54 2016

ALTER DATABASE   MOUNT

Tue Mar 15 00:37:54 2016

MMNL started with pid=16, OS id=16424 

Successful mount of redo thread 1, with mount id 1283555746

Database mounted in Exclusive Mode

Lost write protection disabled

Completed: ALTER DATABASE   MOUNT --> MOUNT 완료

Tue Mar 15 00:39:42 2016

ALTER SYSTEM SET db_recovery_file_dest_size='10240M' SCOPE=BOTH; --> 파라미터 값 변경

Tue Mar 15 00:39:42 2016

db_recovery_file_dest_size of 10240 MB is 38.07% used. This is a --> 사용량이 나오며 깨알같은 설명도...

user-specified limit on the amount of space that will be used by this

database for recovery-related files, and does not reflect the amount of

space available in the underlying filesystem or ASM diskgroup. 

Tue Mar 15 00:40:53 2016

alter database open

Tue Mar 15 00:40:53 2016

LGWR: STARTING ARCH PROCESSES

Tue Mar 15 00:40:53 2016

ARC0 started with pid=20, OS id=16708 

ARC0: Archival started

LGWR: STARTING ARCH PROCESSES COMPLETE

ARC0: STARTING ARCH PROCESSES

Tue Mar 15 00:40:54 2016

ARC1 started with pid=21, OS id=14076 

Tue Mar 15 00:40:54 2016

ARC2 started with pid=22, OS id=16032 

ARC1: Archival started

ARC2: Archival started

ARC1: Becoming the 'no FAL' ARCH

ARC1: Becoming the 'no SRL' ARCH

ARC2: Becoming the heartbeat ARCH

Archived Log entry 137 added for thread 1 sequence 279 ID 0x4bb0414b dest 1:

Thread 1 advanced to log sequence 282 (thread open)

Thread 1 opened at log sequence 282

  Current log# 3 seq# 282 mem# 0: F:\APP\INSEONG\ORADATA\TEST1\REDO03.LOG

Tue Mar 15 00:40:54 2016

ARC3 started with pid=23, OS id=2980 

Archived Log entry 138 added for thread 1 sequence 280 ID 0x4bb0414b dest 1:

Archived Log entry 139 added for thread 1 sequence 281 ID 0x4bb0414b dest 1:

Successful open of redo thread 1

ARC3: Archival started

ARC0: STARTING ARCH PROCESSES COMPLETE

MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set

Tue Mar 15 00:40:57 2016

SMON: enabling cache recovery

Successfully onlined Undo Tablespace 2.

Verifying file header compatibility for 11g tablespace encryption..

Verifying 11g file header compatibility for tablespace encryption completed

SMON: enabling tx recovery

Database Characterset is KO16MSWIN949

No Resource Manager plan active

SMON: Parallel transaction recovery tried

replication_dependency_tracking turned off (no async multimaster replication found)

Starting background process QMNC

Tue Mar 15 00:40:57 2016

QMNC started with pid=32, OS id=11476 

Completed: alter database open

Tue Mar 15 00:40:58 2016

Starting background process CJQ0

Tue Mar 15 00:40:58 2016

CJQ0 started with pid=34, OS id=15816 

Setting Resource Manager plan SCHEDULER[0x3003]:DEFAULT_MAINTENANCE_PLAN via scheduler window

Setting Resource Manager plan DEFAULT_MAINTENANCE_PLAN via parameter

Tue Mar 15 00:41:01 2016

Starting background process VKRM

Tue Mar 15 00:41:01 2016

VKRM started with pid=33, OS id=15316 

Tue Mar 15 00:50:58 2016

Starting background process SMCO

Tue Mar 15 00:50:58 2016

SMCO started with pid=24, OS id=10976 

279~281 sequence#에 해당하는 online redo group들이 모두 archiving 완료되었고, current redo group은 group3, sequence#는 282이다.

archiving이 정상적으로 완료되었음을 파일 시스템 영역에서도 확인할수 있다.

또한 아까 문제상황에서는 수행되지 못했던 'alter system switch logfile;' 구문도 정상적으로 수행됨을 확인 할 수 있었다.

덤으로 체크 포인트까지(참고로 체크포인트는 문제상황에서도 작동되었다.) -->

※ 정리

1. db_recovery_file_dest_size 파라미터에서 설정한 값 이상으로 recovery-related files 파일(특히 아카이브)이 쌓였을때 ORA-00257에러가 발생할 수 있으며, 이 때는 sys를 제외한 일반 유저의 접근이 불가능하다.

2. db_recovery_file_dest_size 파라미터 크기를 늘려줌으로써 DB를 다시 정상적으로 운영가능하다.

3. ORA-00257과 같은 상황이 발생하지 않도록, 평소 백업영역 관리에 신경을 써야 한다.

(archiving 삭제 스케쥴러 지정 등)

더 생각해 볼만한 문제

(1) 아카이브 파일을 삭제했으나, 그 내용이 DB로 바로 전달되는 것 같지는 않다... 반영되기 까지 delay가 있는 것인가?

--> 4. Delete unnecessary files using RMAN DELETE command. If an operating

   system command was used to delete files, then use RMAN CROSSCHECK and

   DELETE EXPIRED commands.

==> 문제 확인: RMAN DELETE command를 사용하지 않았기 때문에 문제가 발생했을 것 같다.

(2) archive dest를 지정할 때, 여러 군데를 지정해서 운영가능한 것으로 알고 있다. 이 경우 해당 문제는 발생하지 않는가?