오라클에서 ORA-00257 에러 발생 시
추가 (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를 지정할 때, 여러 군데를 지정해서 운영가능한 것으로 알고 있다. 이 경우 해당 문제는 발생하지 않는가?