1200GB의 Oracle 데이터 파일 크기를 복원 중입니다. 데이터 파일은 4000GB(4TB) 크기의 백업 조각에서 읽혀집니다.
참고: 내가 모니터링한 대로 4TB는 내 데이터 파일의 모든 블록을 읽기 위해 완전히 처리되었습니다.
복원하는 동안 몇 가지 문제가 발생했습니다.
상황 1. 2시간 후 복원이 실패하는 기간이 있었습니다. (당시 Netbackup 데이터베이스 콘솔의 작업 열이 비어 있었습니다.)
상황 2. 2시간 이전에 드라이브가 마운트되었으며 2시간 이전에 복원 프로세스가 실패하지 않았습니다. 그런데 55GB 처리 후 갑자기 복원이 실패했습니다.
오래된 로그가 없습니다. 이제 다음과 같은 문제가 발생합니다.
- 3TB 처리 후 복원에 실패했습니다(23시간 경과)... 일부 로그 항목을 게시하겠습니다. 도움을 주십시오.
---------------세부정보 탭이 표시됩니다.
2012년 8월 23일 오후 12:56:40 - 복원된 이미지 r2n1_1345046880 - (파일 읽기 실패(13)); 복원 시간 23:36:17 8/23/2012 12:56:44 PM - 복원 종료; 경과 시간: 23:36:26 복원이 요청한 파일을 복구하지 못했습니다(5)
------------------------------bpbrm 로그가 표시됩니다.
12:56:35.561 [7344.4804] <2> bpbrm brm_child_done: child 4852 exited with status 13: file read failed
12:56:35.561 [7344.4804] <2> bpbrm send_status_to_parent: bpbrm child is done, but the media manager child is not.
12:56:35.561 [7344.4804] <2> bpbrm tell_mm: sending media manager msg: STOP RESTORE r2n1_1345046880
12:56:40.709 [7344.4804] <2> bpbrm read_media_msg: read from media manager: EXIT r2n1_1345046880 150
12:56:40.709 [7344.4804] <2> bpbrm process_media_msg: media manager for backup id r2n1_1345046880 exited with status 150: termination requested by administrator
12:56:40.709 [7344.4804] <2> bpbrm send_status_to_parent: EXIT r2n1_1345046880 13 sent to parent process.
12:56:40.709 [7344.4804] <2> bpbrm read_media_msg: read from media manager: MEDIA NOT READY
12:56:40.771 [7344.4804] <2> bpbrm read_parent_msg: read from parent TERMINATE
12:56:40.771 [7344.4804] <2> bpbrm tell_mm: sending media manager msg: TERMINATE
--------------bprd
12:56:40.725 [3292.7188] <2> read_bpbrm_msg: (pid 7344) EXIT r2n1_1345046880 13
12:56:40.725 [3292.7188] <2> handle_image_status: r2n1_1345046880 restfiles pid 6696 bpbrm pid 7344 status = 13
12:56:40.725 [3292.7188] <2> remove_completed_restore: unlink record with restfiles pid 6696
12:56:40.725 [3292.7188] <2> remove_completed_restore: no more active restores
12:56:40.725 [3292.7188] <2> done_with_bpbrm: bpbrm pid 7344 has no more images to process
12:56:40.725 [3292.7188] <2> send_bpbrm_msg: (pid 7344) TERMINATE
12:56:40.725 [3292.7188] <2> start_indep_grp: active_mpx_groups = 0
12:56:40.725 [3292.7188] <2> start_indep_grp: p_active_restore_for_first_grp = NULL
12:56:40.725 [3292.7188] <2> start_indep_grp: p_first_mpx_group_for_restore = NULL
12:56:40.725 [3292.7188] <2> next_image_using_first_blks: returning NULL
12:56:40.725 [3292.7188] <2> run_restores: brm pid 0 has no active restores and none to start
12:56:40.725 [3292.7188] <2> start_indep_grp: active_mpx_groups = 0
12:56:40.725 [3292.7188] <2> start_indep_grp: p_active_restore_for_first_grp = NULL
12:56:40.725 [3292.7188] <2> start_indep_grp: p_first_mpx_group_for_restore = NULL
12:56:40.725 [6696.7284] <2> restorefiles: Done with port 0 backup_id r2n1_1345046880. Status = 13
12:56:40.725 [6696.7284] <2> add_msgs_to_progress_file: close and re-open the progress log file
12:56:40.725 [6696.7284] <2> log_disconnect: more than 30 mins since the last progress msg, closing sockets
12:56:40.725 [6696.7284] <2> put_short: (10) network write() error: An operation was attempted on something that is not a socket. ; socket = -1
12:56:40.725 [6696.7284] <2> bpcr_disconnect_rqst: bpcr protocol error - couldn't send request type
12:56:40.725 [6696.7284] <2> log_disconnect_all: Couldn't disconnect from bpcd
12:56:40.725 [6696.7284] <2> log_disconnect_all: Couldn't close CLIENT_CMD_SOCK: An operation was attempted on something that is not a socket.
12:56:40.725 [6696.7284] <2> log_disconnect_all: Couldn't close CLIENT_STAT_SOCK: An operation was attempted on something that is not a socket.
12:56:40.756 [6696.7284] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
12:56:40.756 [6696.7284] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bpcd
12:56:40.803 [6696.7284] <2> logconnections: BPCD CONNECT FROM 192.168.59.63.52068 TO 192.168.34.150.13724
12:56:40.803 [6696.7284] <2> vnet_connect_to_vnetd_extra: ../../libvlibs/vnet_vnetd.c.188: msg: VNETD CONNECT FROM 192.168.59.63.52069 TO 192.168.34.150.13724 fd = 808
12:56:40.834 [6696.7284] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.541: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
12:56:40.896 [6696.7284] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.558: ipc_string: /tmp/vnet-32625345712215021290000000000-ERMDYb
12:56:41.754 [6696.7284] <2> get_short: (2) premature end of file (byte 1)
12:56:41.754 [6696.7284] <2> readclientstatus: bpcr short int read failed
12:56:41.754 [6696.7284] <2> readclientstatus: Access is denied.
12:56:41.754 [6696.7284] <2> log_disconnect: Couldn't close progress file /usr/openv/netbackup/logs/user_ops/dbext/logs/17121.0.1345627225 on orcl.justice.gov.ge
12:56:41.754 [6696.7284] <2> log_disconnect: Client close errno = 1
12:56:41.754 [6696.7284] <2> put_short: (10) network write() error: An existing connection was forcibly closed by the remote host. ; socket = 780
12:56:41.754 [6696.7284] <2> bpcr_disconnect_rqst: bpcr protocol error - couldn't send request type
12:56:41.754 [6696.7284] <2> log_disconnect_all: Couldn't disconnect from bpcd
12:56:41.754 [6696.7284] <2> log_disconnect_all: Couldn't close CLIENT_CMD_SOCK: An operation was attempted on something that is not a socket.
12:56:41.754 [6696.7284] <2> log_disconnect_all: Couldn't close CLIENT_STAT_SOCK: An operation was attempted on something that is not a socket.
12:56:41.754 [6696.7284] <2> restorefiles: Received finished from MPX main bprd. Stat = 0
12:56:41.754 [6696.7284] <2> mail_msg_and_set_exit_status: entered; status = 0
12:56:41.754 [6696.7284] <2> mail_msg_and_set_exit_status: Attempting to send mail to oracle on orcl.justice.gov.ge
12:56:41.770 [6696.7284] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
12:56:41.770 [6696.7284] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bpcd
12:56:41.817 [6696.7284] <2> logconnections: BPCD CONNECT FROM 192.168.59.63.52070 TO 192.168.34.150.13724
12:56:41.817 [6696.7284] <2> vnet_connect_to_vnetd_extra: ../../libvlibs/vnet_vnetd.c.188: msg: VNETD CONNECT FROM 192.168.59.63.52071 TO 192.168.34.150.13724 fd = 780
12:56:41.863 [6696.7284] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.541: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
12:56:41.879 [6696.7284] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.558: ipc_string: /tmp/vnet-32628345712216006586000000000-fgV51f
12:56:42.285 [6696.7284] <2> mail_msg_and_set_exit_status: CLIENT_CMD_SOCK from bpcr = 808
12:56:42.285 [6696.7284] <2> mail_msg_and_set_exit_status: CLIENT_STAT_SOCK from bpcr = 780
12:56:42.690 [6696.7284] <2> bpcr_get_version_rqst: bpcd version: 07000000
12:56:42.909 [6696.7284] <2> bpcr_get_version_rqst: bpcd version: 07000000
12:56:43.330 [6696.7284] <2> bpcr_get_version_rqst: bpcd version: 07000000
12:56:43.767 [6696.7284] <2> mail_msg_and_set_exit_status: RESTORE EXIT STATUS = 5
12:56:43.782 [6696.7284] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2054: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
12:56:43.782 [6696.7284] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.2068: service: bpcd
12:56:43.829 [6696.7284] <2> logconnections: BPCD CONNECT FROM 192.168.59.63.52092 TO 192.168.34.150.13724
12:56:43.829 [6696.7284] <2> vnet_connect_to_vnetd_extra: ../../libvlibs/vnet_vnetd.c.188: msg: VNETD CONNECT FROM 192.168.59.63.52093 TO 192.168.34.150.13724 fd = 808
12:56:43.860 [6696.7284] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.541: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a
12:56:43.907 [6696.7284] <2> vnet_vnetd_connect_forward_socket_begin: ../../libvlibs/vnet_vnetd.c.558: ipc_string: /tmp/vnet-32635345712218044217000000000-EOpovo
12:56:44.750 [6696.7284] <2> job_monitoring_exex: ACK disconnect
12:56:44.750 [6696.7284] <2> job_disconnect: Disconnected
12:56:44.750 [6696.7284] <2> get_short: (2) premature end of file (byte 1)
12:56:44.750 [6696.7284] <2> readclientstatus: bpcr short int read failed
12:56:44.750 [6696.7284] <2> readclientstatus: Access is denied.
12:56:44.750 [6696.7284] <2> log_disconnect: Couldn't close progress file /usr/openv/netbackup/logs/user_ops/dbext/logs/17121.0.1345627225 on orcl.justice.gov.ge
12:56:44.750 [6696.7284] <2> log_disconnect: Client close errno = 1
12:56:44.750 [6696.7284] <2> bpcr_disconnect_rqst: bpcr received the following message:
12:56:44.750 [6696.7284] <2> terminate_restore: EXIT STATUS 5
12:56:44.750 [6696.7284] <2> bprd: C:\Program Files\Veritas\NetBackup\bin\userreq_notify.cmd restore orcl.justice.gov.ge oracle
---------RMAN
failure of IRESTORE command on ch1_tape channel at 08/23/2012 12:57:17
RMAN-10038: database session for channel ch1_tape terminated unexpectedly
복원은 수동으로 중지되지 않았습니다.
답변1
RMAN-10038은 일반적으로 복원 처리를 담당하는 Oracle 프로세스(Netbackup의 라이브러리와 연결됨)가 코어 덤프로 인해 중단되었음을 의미합니다. Alert*.log를 확인하고 Oracle 진단 디렉토리에서 *.trc 파일을 찾으십시오.
이것은 알려진 문제일 가능성이 높습니다.http://www.symantec.com/business/support/index?page=content&id=TECH77071
NetBackup 6.5.5용 Oracle 11.2를 활성화하는 EEB(Emergency Engineering Binary)는 다음 링크에서 제공됩니다. http://support.veritas.com/docs/346033
NetBackup 6.5.4의 경우: http://support.veritas.com/docs/346592
이러한 수정 사항 없이 Oracle 버전 11.2를 백업하려고 하면 아래와 같은 오류가 발생합니다.
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03009: failure of backup command on ch00 channel at 07/27/2010 09:23:23
RMAN-10038: database session for channel ch00 terminated unexpectedly
그 외에는 먼저 Oracle 지원팀에 문의한 다음 Netbackup 지원팀에 문의하겠습니다.