ERVER_INFO: 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 905 NDMP_CONFIG_GET_SERVER_INFO: successful. Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] AuthType[2] 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 1322 NDMP_CONFIG_GET_EXT_LIST: 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 1372 NDMP_CONFIG_GET_EXT_LIST: successful 108 14fc 09/16 13:56:56 2391 Data server connect complete. 108 14fc 09/16 13:56:56 2391 LOGIN TO MOVER 108 14fc 09/16 13:56:56 2391 ndmp.cpp 3054 CONNECT: opening socket connection to host [spiderman.hrt.hr] port [65351] family [IPv4] 108 14fc 09/16 13:56:56 2391 ndmp.cpp 3088 CONNECT successful: Now waiting for NOTIFY_CONNECTED message. 108 14fc 09/16 13:56:56 2391 ndmp.cpp 2749 NDMP_NOTIFY_CONNECTED: received ndmp_notify_connected. Version:[4], Reason:[0] Text:[Connected] 108 14fc 09/16 13:56:56 2391 ndmp.cpp 3137 NDMP_CONNECT_OPEN: protocol_version[4] 108 14fc 09/16 13:56:56 2391 ndmp.cpp 3152 NDMP_CONNECT_OPEN: successful 108 14fc 09/16 13:56:56 2391 ndmp.cpp 2804 NDMP_NOTIFY_CONNECTED: successful. Version is [4] 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 873 NDMP_CONFIG_GET_SERVER_INFO: 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 905 NDMP_CONFIG_GET_SERVER_INFO: successful. Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] AuthType[2] 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 787 NDMP_CONNECT_CLIENT_AUTH: login[ndmp] mode[2=NDMP_AUTH_MD5] 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 807 NDMP_CONNECT_CLIENT_AUTH: successful 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 827 NDMP_CONFIG_GET_HOST_INFO: 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 849 NDMP_CONFIG_GET_HOST_INFO: successful. Host[spiderman.hrt.hr] OsType[Windows Server x64] Version[6.2Build 9200: ] HostId[A01503A] 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 873 NDMP_CONFIG_GET_SERVER_INFO: 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 905 NDMP_CONFIG_GET_SERVER_INFO: successful. Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] AuthType[2] 108 14fc 09/16 13:56:56 2391 New NRS:[true] Version:[10.0.0(BUILD116)] 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 1322 NDMP_CONFIG_GET_EXT_LIST: 108 14fc 09/16 13:56:56 2391 ndmp_v4.cpp 1372 NDMP_CONFIG_GET_EXT_LIST: successful 108 14fc 09/16 13:56:56 2391 Data mover connect complete. 108 14fc 09/16 13:56:56 2391 Set NDMP Variables() - Back-up NDMP variable backup type set to [dump]. 108 14fc 09/16 13:56:56 2391 Set NDMP Variables() - Back-up record size set to [65536]. 108 14fc 09/16 13:56:56 2391 NDMP Variable Setup() - backup type is dump 108 14fc 09/16 13:56:56 2391 Set NDMP Variables() - NDMP server type is 5 108 14fc 09/16 13:56:57 2391 Opening tape for archive [4236]... 108 14fc 09/16 13:56:57 2391 Construct Open Device Name() - got subclientID 6 and clientID 3 108 14fc 09/16 13:56:57 2391 Construct Open Device Name() - constructed virtual tape name is R:0:2391:4236:106:0:1:0:2:3:6:6:13:4436701240229:0:0 108 14fc 09/16 13:56:57 2391 ndmp_v4.cpp 1686 NDMP_TAPE_OPEN [spiderman.hrt.hr]: Device[R:0:2391:4236:106:0:1:0:2:3:6:6:13:4436701240229:0:0] Mode[0] 108 14fc 09/16 13:57:03 2391 Log Message() - received NDMP_LOG_MESSAGE [spiderman.hrt.hr][CVNRS: Tape opened. AfileId=4236 CopyId=0 Stream=1] 108 14fc 09/16 13:57:03 2391 ndmp.cpp 2225 Message not replied to yet. 108 14fc 09/16 13:57:05 2391 ndmp_v4.cpp 1706 NDMP_TAPE_OPEN: successful 108 14fc 09/16 13:57:05 2391 Restore Request() - MAX Restore List Length set to [1048576]. 108 14fc 09/16 13:57:05 2391 ndmp_v4.cpp 2829 NDMP_MOVER_SET_WINDOW [spiderman.hrt.hr]: Offset[0] Length[1557968040960] 108 14fc 09/16 13:57:05 2391 ndmp_v4.cpp 2846 NDMP_MOVER_SET_WINDOW: successful 108 14fc 09/16 13:57:05 2391 ndmp_v4.cpp 2712 NDMP_MOVER_LISTEN [spiderman.hrt.hr]: mode[1] addr_type[1] 108 14fc 09/16 13:57:11 2391 ndmp_v4.cpp 2735 NDMP_MOVER_LISTEN: successful 108 14fc 09/16 13:57:11 2391 ndmp_v4.cpp 2742 --- address[0xa018063] port[65378] 108 14fc 09/16 13:57:11 2391 ndmp_v4.cpp 2742 --- address[0xa01503a] port[65378] 108 14fc 09/16 13:57:11 2391 ndmp_v4.cpp 2143 NDMP_DATA_CONNECT(tcp): 108 14fc 09/16 13:57:11 2391 ndmp_v4.cpp 2147 --- address[0xa018063] port[65378] 108 14fc 09/16 13:57:11 2391 ndmp_v4.cpp 2147 --- address[0xa01503a] port[65378] 108 14fc 09/16 13:57:32 2391 ndmp_v4.cpp 2192 NDMP_DATA_CONNECT: successful 108 14fc 09/16 13:57:32 2391 re-initialized tape server for next block of files. 108 14fc 09/16 13:57:33 2391 Successfully translated archFileId 4236 (commCellId 2) to client Id 3 108 14fc 09/16 13:57:34 2391 Back-up Vendor() - Source Client ID = 3, back-up vendor = 1 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2385 NDMP_DATA_START_RECOVER_CV: RestoreType[dump] BackupVendor[NetApp] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [ACL_START]=[1557968033792] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [BASE_DATE]=[14327177354] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [CV_FIRST_OFFSET]=[365568] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [DEBUG]=[N] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [DIRECT]=[Y] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [DUMP_DATE]=[18622231081] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [ENHANCED_DAR_ENABLED]=[T] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [FILESYSTEM]=[/svm01/vol_orabckp] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [HIST]=[N] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [NDMP_VERSION]=[4] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [NO_ACLS]=[N] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [PATHNAME_SEPARATOR]=[/] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [RECURSIVE]=[N] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [TYPE]=[dump] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [UPDATE]=[Y] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2395 ENV [VERBOSE]=[N] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2416 FILE Offset[1422527511552] Inode[20265] Mtime[1442342090] Size[5273444] [expdp/pris/expdp_export_cumulative.log] to [/C:\tmp/expdp_export_cumulative.log] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2448 NDMP_DATA_START_RECOVER_CV: successful 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2975 NDMP_MOVER_READ [spiderman.hrt.hr]: Offset[0] Length[4194304] 108 14fc 09/16 13:57:34 2391 ndmp_v4.cpp 2992 NDMP_MOVER_READ: successful 108 14fc 09/16 13:59:34 2391 ndmp_v4.cpp 2079 NDMP_DATA_GET_STATE: Timeout:[7200] 108 14fc 09/16 13:59:34 2391 ndmp_v4.cpp 2105 NDMP_DATA_GET_STATE: successful. Operation[2] State[0x1] HaltReason[0] BytesProcessed[0] EstBytesRemain[0] ReadOffset[0] ReadLength[4194304] 108 14fc 09/16 14:00:44 2391 ndmp_v4.cpp 2975 NDMP_MOVER_READ [spiderman.hrt.hr]: Offset[1422527511552] Length[4194304] 108 14fc 09/16 14:00:44 2391 ndmp_v4.cpp 2992 NDMP_MOVER_READ: successful 108 14fc 09/16 14:01:44 2391 ndmp_v4.cpp 2079 NDMP_DATA_GET_STATE: Timeout:[7200] 108 14fc 09/16 14:01:44 2391 ndmp_v4.cpp 2105 NDMP_DATA_GET_STATE: successful. Operation[2] State[0x1] HaltReason[0] BytesProcessed[0] EstBytesRemain[0] ReadOffset[1422527511552] ReadLength[4194304] 108 14fc 09/16 14:01:57 2391 ndmp_v4.cpp 2975 NDMP_MOVER_READ [spiderman.hrt.hr]: Offset[1422531705856] Length[4194304] 108 14fc 09/16 14:01:57 2391 ndmp_v4.cpp 2992 NDMP_MOVER_READ: successful 108 14fc 09/16 14:01:57 2391 Log Message() - received NDMP_LOG_MESSAGE [vmvcenter][Total number of files sent for recovery :: 1,Total number of files recovered successfully :: 1,Total number of files which skipped to be recovered :: 0,Total number of files which failed to be recovered ::0] 108 14fc 09/16 14:01:57 2391 Data Halted Notification() - received DATA_HALT with reason [NDMP_DATA_HALT_SUCCESSFUL] 108 14fc 09/16 14:01:57 2391 ndmp_v4.cpp 2079 NDMP_DATA_GET_STATE: Timeout:[7200] 108 14fc 09/16 14:01:57 2391 ndmp_v4.cpp 2105 NDMP_DATA_GET_STATE: successful. Operation[2] State[0x2] HaltReason[0] BytesProcessed[5273444] EstBytesRemain[0] ReadOffset[1422531705856] ReadLength[4194304] 108 14fc 09/16 14:03:27 2391 ndmp_v4.cpp 2900 NDMP_MOVER_ABORT [spiderman.hrt.hr]: 108 14fc 09/16 14:03:27 2391 Mover Halted Notification() - received NDMP_MOVER_HALTED reason [NDMP_MOVER_HALT_ABORTED] 108 14fc 09/16 14:03:27 2391 ndmp.cpp 2225 Message not replied to yet. 108 14fc 09/16 14:03:28 2391 ndmp_v4.cpp 2914 NDMP_MOVER_ABORT: successful 108 14fc 09/16 14:03:28 2391 ndmp_v4.cpp 2934 NDMP_MOVER_STOP [spiderman.hrt.hr]: 108 14fc 09/16 14:03:28 2391 ndmp_v4.cpp 2948 NDMP_MOVER_STOP: successful 108 14fc 09/16 14:03:28 2391 ndmp_v4.cpp 2551 NDMP_DATA_STOP: 108 14fc 09/16 14:03:28 2391 ndmp_v4.cpp 2565 NDMP_DATA_STOP: successful 108 14fc 09/16 14:03:28 2391 ndmp_v4.cpp 1735 NDMP_TAPE_CLOSE [spiderman.hrt.hr]: [R:0:2391:4236:106:0:1:0:2:3:6:6:13:4436701240229:0:0]. Timeout:[1200] 108 14fc 09/16 14:03:28 2391 ndmp_v4.cpp 1752 NDMP_TAPE_CLOSE: successful 108 14fc 09/16 14:03:28 2391 ndmp.cpp 1038 NDMP_CONNECT_CLOSE [spiderman.hrt.hr] 108 14fc 09/16 14:03:28 2391 ndmp.cpp 1038 NDMP_CONNECT_CLOSE [vmvcenter] 108 1fe4 09/16 14:03:54 2391 NasRestore::progressReport() - Exiting progress reporting thread... 108 14fc 09/16 14:03:54 2391 FClRestore::ProcessRestoreMessage() - Processing FSR_MSG_WAIT_ARCHIVE_CLOSED 108 14fc 09/16 14:03:55 2391 FClRestore::ProcessRestoreMessage() - Processing FSR_MSG_RESTORE_END 108 14fc 09/16 14:03:55 2391 FclRestore::OnMsgRestoreEnd() - Restore on client [spiderman.hrt.hr] subclient [Orabckp] completed... 108 14fc 09/16 14:03:55 2391 FclRestore::OnMsgRestoreEnd() - File Statistics: Total [1], Succeeded [1], Skipped [0] Failed [0] Need Reboot [0] 108 14fc 09/16 14:03:55 2391 FclRestore::OnMsgRestoreEnd() - Byte Statistics: Total [0], Succeeded [5273444], Skipped [0] Failed [0] 108 14fc 09/16 14:03:55 2391 FclRestore::OnMsgRestoreEnd() - The failed byte count does not include files that failed due to seek error 108 14fc 09/16 14:03:55 2391 FclRestore::OnMsgRestoreEnd() - sending FSR_MSG_RESTORE_END to FSRestoreHead 108 14fc 09/16 14:03:55 2391 FclRestore::sendMsgToRestoreHead() - Could not send FSR_MSG_RESTORE_END to Restore Head - not connected! 108 14fc 09/16 14:03:55 2391 FClRestore::processRestoreMsgs() - Exiting the thread... 108 2714 09/16 14:03:55 2391 FclRestore::receiveRestoreMsgs() - Waking up after FSR_MSG_RESTORE_END has been processed 108 2714 09/16 14:03:55 2391 FclRestore::SuspendRestoreMessageProcessor()() - Resuming Restore Message Processor 108 2714 09/16 14:03:55 2391 FclRestore::receiveRestoreMsgs() - Waiting for children threads to complete... 108 2714 09/16 14:03:55 2391 FclRestore::receiveRestoreMsgs() - Exiting the thread... 108 2714 09/16 14:03:55 2391 ::main() - Finished receiving messages. Shutting down. 108 2714 09/16 14:03:55 2391 NasRestore::finalize() - Files restored : [1], Files that failed or had errors during restore : [0] 108 2714 09/16 14:03:55 2391 NasMedia::cleanup() - setting the current tape position to 0 - will reset the tape position. 108 2714 09/16 14:03:55 2391 stat- ID [Job Progress Update], Samples [8], Time [0.000587] Sec(s), Average [0.000073] Sec/Sample 108 2714 09/16 14:03:55 2391 FclRestore::finalize() - Restore successful - sending FSR_MSG_RESTORE_END 108 2714 09/16 14:03:55 2391 Using default close pipeline args for a backup, backupState is not being set 108 2714 09/16 14:03:55 2391 CVJobCtrlLog::unregisterProcess(): successfully removed file [C:\Program Files\NetApp\SnapProtect\Base\JobControl\0.108] 108 2714 09/16 14:03:56 2391 ::main() - Exiting... 108 2714 09/16 14:03:56 2391 JOBRESULTSTABLE(C:\Program Files\NetApp\SnapProtect\iDataAgent\JobResults\CV_JobResults\2\0\2391\Job removing copy 'C:\Program Files\NetApp\SnapProtect\iDataAgent\JobResults\CV_JobResults\2\0\2391' 108 2714 09/16 14:03:56 2391 ** CVSession::sendBytes(...) iSocketMember=992 send failed, err=0x8007276D:{QiSocket.cpp[CQiSocket::Send(397)]/W32.10093.(Either the application has not called WSAStartup, or WSAStartup failed.)}. 108 2714 09/16 14:03:56 2391 ** CVSession::disconnect (void) @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : spiderman File : StartRestore.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 11876 1540 09/16 13:56:28 2391 STARTRESTORE Resetting to time [0] to current time [1442404586] 11876 1540 09/16 13:56:28 2391 STARTRESTORE To time is changed from [1442404586] to archive file creation time [1442370632] returned by getArchFileByTime for backupset [5] reference time [1442404586] 11876 1540 09/16 13:56:28 2391 Init() - Initializing job control [token=No Token,cn=spiderman] in single threaded mode, serverName [Instance001], ControlFlag [1], Job Id [2391] 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE options - 0x8c0 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE Restore Options - ER_UNCONDITIONAL | ER_PRESERVE_LEVEL | ER_NONFULLREGISTRY 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE synthetic full - no 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE commcell - 2 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE source client - 3 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE dest client - 1005 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE apptype - 13 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE instance - 1 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE backupset = 5 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE subclient - 6 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE from time - 0 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE to time - 1442370632 2015/09/16 04:30:32 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE source path - [/svm01/vol_orabckp/expdp/pris/expdp_export_cumulative.log] 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE dest path - [C:\tmp] 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE copy - 0 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE em function - 0 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE em firstnode - 0 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE em skipnodes - 0 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE em page size - -1 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE skip errors and continue - [false] 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE checking whether super restore should be applied 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE filter browse XML string [] 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE converting restore job into a single subclient restore for subclient [6] 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE starting regular restore 11876 2cc0 09/16 13:56:29 2391 FSSubclientConf::load(857) - +++ 11876 2cc0 09/16 13:56:29 2391 FSSubclientConf::load(857) - --- 0:00.086676 11876 2cc0 09/16 13:56:29 2391 STARTRESTORE start operation on subclient id [6] name [Orabckp] backupset id [5] 11876 2cc0 09/16 13:56:30 2391 STARTRESTORE SECURITY: canRestore() returned true for subclientId (6). User (2), commCell (2), srcClientId (3), destClientId (1005), appTypeId (13), instance (1), backupSet (5), inPlace = (false) impersonateUser = (false) machineUId=(). 11876 2cc0 09/16 13:56:30 2391 STARTRESTORE filter browse XML string [] 11876 2cc0 09/16 13:56:30 2391 STARTRESTORE Non-snap restore for non-DB restore 11876 2cc0 09/16 13:56:30 2391 STARTRESTORE connecting to MediaAgent 'spiderman.hrt.hr*spiderman*8400*8402' 11876 2cc0 09/16 13:56:31 2391 STARTRESTORE Sending source path '/svm01/vol_orabckp/expdp/pris/expdp_export_cumulative.log' with strip level 4 11876 2cc0 09/16 13:56:31 2391 STARTRESTORE Sending destination path 'C:\tmp' 11876 2770 09/16 14:03:55 2391 STARTRESTORE File Statistics: Succeeded [1], Skipped [0] Failed [0] 11876 2770 09/16 14:03:56 2391 STARTRESTORE Received FSR_MSG_RESTORE_END 11876 29cc 09/16 14:04:07 2391 STARTRESTORE Received disconnect request 11876 29cc 09/16 14:04:07 2391 STARTRESTORE Disconnected MA session completed restore 11876 2cc0 09/16 14:04:08 2391 STARTRESTORE Success | Partial Success | Failure: Total files [1], Succeeded [1], Transferred [0], Skipped [0], Failed [0], MaAttach [true] 11876 2cc0 09/16 14:04:08 2391 Sending SUCCESS complete message to JM, 2391 @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : vmvcenter File : CVNRDS.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 10784 4a7c 09/16 13:56:53 2391 main() - ============================================ 10784 4a7c 09/16 13:56:53 2391 main() - ----------------- STARTED ----------------- 10784 4a7c 09/16 13:56:53 2391 main() - ============================================ 10784 4a7c 09/16 13:56:53 2391 main() - CVNRDS.exe -l ndmp -p 39b87acfec63e189d0906fb4cabcb115b06a64ae3ac14aa86 -j 2391 -cn vmvcenter -cn vmvcenter cvshost:spiderman.hrt.hr*spiderman cvsport:65341:0 cvsmyplatform:4 cvsremoteplatform:2 -vm Instance001 10784 4a7c 09/16 13:56:53 2391 Init() - Initializing job control [token=,cn=vmvcenter], serverName [spiderman.hrt.hr], ControlFlag [4], Job Id [2391] 10784 4a7c 09/16 13:56:53 2391 Cvcl::init() - CVCL: Running in FIPS Mode 10784 4a7c 09/16 13:56:54 2391 CVJobCtrlLog::registerProcess(): successfully created file [C:\Program Files\NetApp\SnapProtect\Base\JobControl\10.784] 10784 4a7c 09/16 13:56:54 2391 CompleteStartup() - Process was created using IPv4. 10784 4a7c 09/16 13:56:54 2391 CompleteStartup() - Going to listen on host:[vmvcenter]. Listening on all IPv4 interfaces. 10784 4a7c 09/16 13:56:54 2391 CompleteStartup() - Going to listen on socket [548] port [51872]. 10784 4a7c 09/16 13:56:54 2391 CompleteStartup() - Send to NAS iDA NDMP port [51872] binded to socket 10784 4a7c 09/16 13:56:57 2391 ndmp.cpp 3513 NOTIFY_CONNECTED: protocol_version[4] 10784 4a7c 09/16 13:56:57 2391 ndmp.cpp 3521 NOTIFY_CONNECTED: successful 10784 4a7c 09/16 13:56:57 2391 ndmp.cpp 3480 NDMP_CONNECT_OPEN reply 10784 4a7c 09/16 13:56:57 2391 ndmp.cpp 3491 NDMP_CONNECT_OPEN reply: successful 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4300 NDMP_CONFIG_GET_SERVER_INFO reply: Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] Auth:[2] 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4329 NDMP_CONFIG_GET_SERVER_INFO reply: successful 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4073 NDMP_CONFIG_GET_AUTH_ATTR reply: Error[0] AuthType[2] 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4095 NDMP_CONFIG_GET_AUTH_ATTR reply: successful 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4157 NDMP_CONNECT_CLIENT_AUTH reply: Error[0] 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4177 NDMP_CONNECT_CLIENT_AUTH reply: successful 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4054 AUTHENTICATION successful 10784 4a7c 09/16 13:56:57 2391 NRDS debug level as given by registry key NDMP_API/\nNRDSLOGLEVEL is set to 1 10784 4a7c 09/16 13:56:57 2391 runMainLoop() - Registering call backs for NRDS 10784 4a7c 09/16 13:56:57 2391 Waiting for next NDMP message. TimeOut [9000] 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4352 NDMP_CONFIG_GET_HOST_INFO reply: Host[vmvcenter] OsType[Windows Server x64] Version[6.1Build 7601: Service Pack 1] ID:[A014F14] 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4378 NDMP_CONFIG_GET_HOST_INFO reply: successful 10784 4a7c 09/16 13:56:57 2391 Waiting for next NDMP message. TimeOut [9000] 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4300 NDMP_CONFIG_GET_SERVER_INFO reply: Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] Auth:[2] 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4329 NDMP_CONFIG_GET_SERVER_INFO reply: successful 10784 4a7c 09/16 13:56:57 2391 Waiting for next NDMP message. TimeOut [9000] 10784 4a7c 09/16 13:56:57 2391 ************ GET_EXTENSION_LIST ************ 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4231 NDMP_CONFIG_GET_EXT_LIST reply 10784 4a7c 09/16 13:56:57 2391 ndmp_v4.cpp 4276 NDMP_CONFIG_GET_EXT_LIST reply: successful 10784 4a7c 09/16 13:56:57 2391 ************ GET_EXTENSION_LIST[0] ************ 10784 4a7c 09/16 13:56:57 2391 Waiting for next NDMP message. TimeOut [9000] 10784 4a7c 09/16 13:57:12 2391 NdmpDataConnectHandler() - Creating socket to connect to tape server 10784 4a7c 09/16 13:57:12 2391 NdmpDataConnectHandler() - Attempting to connect to IP passed into NDMP_DATA_CONNECT. Using IPv4. 10784 4a7c 09/16 13:57:33 2391 NdmpDataConnectHandler() - NRDS_Error: NdmpDataConnectHandler: Failed to connect to remote tape server::error : 10784 4a7c 09/16 13:57:33 2391 NdmpDataConnectHandler() - NRDS_Error: NdmpDataConnectHandler: 0x8007274C:{QiSocket.cpp[CQiSocket::Connect(224)]/W32.10060.(A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.)} 10784 4a7c 09/16 13:57:33 2391 NdmpDataConnectHandler() - Successfully connected to ip address 10784 4a7c 09/16 13:57:33 2391 ndmp_v4.cpp 5859 NDMP_DATA_CONNECT reply: Error[0] 10784 4a7c 09/16 13:57:33 2391 ndmp_v4.cpp 5879 NDMP_DATA_CONNECT reply: successful 10784 4a7c 09/16 13:57:33 2391 Waiting for next NDMP message. TimeOut [9000] 10784 4a7c 09/16 13:57:35 2391 processStartRecoverRequest() - DAR restore requested 10784 4a7c 09/16 13:57:35 2391 ndmp_v4.cpp 5729 NDMP_DATA_START_RECOVER_CV reply: Error[0] 10784 4a7c 09/16 13:57:35 2391 ndmp_v4.cpp 5749 NDMP_DATA_START_RECOVER_CV reply: successful 10784 4a7c 09/16 13:57:35 2391 Waiting for next NDMP message. TimeOut [9000] 10784 3390 09/16 13:57:35 2391 processDumpData() - Printing the START_RECOVER request variables 10784 3390 09/16 13:57:35 2391 printStartRecoverRequest() - NDMP_DATA_START_RECOVER_CV 10784 3390 09/16 13:57:35 2391 #environmental vars: [16] 10784 3390 09/16 13:57:35 2391 environmental vars: 10784 3390 09/16 13:57:35 2391 var 1 : name = ACL_START , value = 1557968033792 10784 3390 09/16 13:57:35 2391 var 2 : name = BASE_DATE , value = 14327177354 10784 3390 09/16 13:57:35 2391 var 3 : name = CV_FIRST_OFFSET , value = 365568 10784 3390 09/16 13:57:35 2391 var 4 : name = DEBUG , value = N 10784 3390 09/16 13:57:35 2391 var 5 : name = DIRECT , value = Y 10784 3390 09/16 13:57:35 2391 var 6 : name = DUMP_DATE , value = 18622231081 10784 3390 09/16 13:57:35 2391 var 7 : name = ENHANCED_DAR_ENABLED , value = T 10784 3390 09/16 13:57:35 2391 var 8 : name = FILESYSTEM , value = /svm01/vol_orabckp 10784 3390 09/16 13:57:35 2391 var 9 : name = HIST , value = N 10784 3390 09/16 13:57:35 2391 var 10 : name = NDMP_VERSION , value = 4 10784 3390 09/16 13:57:35 2391 var 11 : name = NO_ACLS , value = N 10784 3390 09/16 13:57:35 2391 var 12 : name = PATHNAME_SEPARATOR , value = / 10784 3390 09/16 13:57:35 2391 var 13 : name = RECURSIVE , value = N 10784 3390 09/16 13:57:35 2391 var 14 : name = TYPE , value = dump 10784 3390 09/16 13:57:35 2391 var 15 : name = UPDATE , value = Y 10784 3390 09/16 13:57:35 2391 var 16 : name = VERBOSE , value = N 10784 3390 09/16 13:57:35 2391 #recover names: [1] 10784 3390 09/16 13:57:35 2391 recover names: NOT LOGGED. See NasRestore.log or CvNasSnapRestore.log 10784 3390 09/16 13:57:35 2391 options = RESTORE_OPTION_NOT_IN_PLACE | RESTORE_OPTION_UNCOND_OVERWRITE 10784 3390 09/16 13:57:35 2391 | RESTORE_OPTION_RECURSIVE | RESTORE_OPTION_NDMP_RESTORE 10784 3390 09/16 13:57:35 2391 preprocessRestorePaths() - Sorted source pathnames in ascending order 10784 3390 09/16 13:57:35 2391 ClientHives::ClientHives() - Skipping user hive [\Registry\User\S-1-5-21-809044434-1823356140-929701000-45724] from system state backup, it should be backed up with regular file system backups 10784 3390 09/16 13:57:35 2391 ClientHives::ClientHives() - Skipping user hive [\Registry\User\S-1-5-21-809044434-1823356140-929701000-45724_Classes] from system state backup, it should be backed up with regular file system backups 10784 3390 09/16 13:57:35 2391 Initializing the share monitor as this is not an Index cache restore 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - ## hal.dll found at C:\Windows\system32\hal.dll 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - ## ntoskrnl.exe found at C:\Windows\system32\ntoskrnl.exe 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - ## ntkrnlpa.exe found at C:\Windows\system32\ntkrnlpa.exe 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - ## kernel32.dll found at C:\Windows\system32\kernel32.dll 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - ## ntdll.dll found at C:\Windows\system32\ntdll.dll 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - ## win32k.sys found at C:\Windows\system32\win32k.sys 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - ## winsrv.dll found at C:\Windows\system32\winsrv.dll 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - ## bootvid.dll found at C:\Windows\system32\bootvid.dll 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - ## kdcom.dll found at C:\Windows\system32\kdcom.dll 10784 3390 09/16 13:57:35 2391 FsRestoreNTObjectsFactory::FsRestoreNTObjectsFactory() - Simpana currently installed at C:\Program Files\NetApp\SnapProtect 10784 3390 09/16 13:57:35 2391 preprocessRestorePaths() - Created the FsRestoreNTObjectsFactory factory successfully 10784 3390 09/16 13:57:35 2391 preprocessRestorePaths::Number of valid source paths: 1 10784 3390 09/16 13:57:35 2391 Creating the DumpParser & tape buffer for file server::NetApp 10784 3390 09/16 13:57:35 2391 fill_tape_buffer() - sending notify_data_read for offset [0], length [4194304] , chunk_offset [18446744073709551615], chunk_length [18446744073709551615] 10784 3390 09/16 13:57:35 2391 ndmp_v4.cpp 4697 NDMP_NOTIFY_DATA_READ: Offset:[0] Length:[4194304] 10784 3390 09/16 13:57:35 2391 ndmp_v4.cpp 4711 NDMP_NOTIFY_DATA_READ: successful 10784 4a7c 09/16 13:59:35 2391 ndmp_v4.cpp 5612 NDMP_DATA_GET_STATE reply: BytesProcessed:[0] ReadOffset:[0] ReadLen:[4194304] 10784 4a7c 09/16 13:59:35 2391 ndmp_v4.cpp 5644 NDMP_DATA_GET_STATE reply: successful 10784 4a7c 09/16 13:59:35 2391 Waiting for next NDMP message. TimeOut [9000] 10784 3390 09/16 14:00:44 2391 checkDumpHeader() - Dump is a NOT compressed dump 10784 3390 09/16 14:00:44 2391 Dump date: Wed Sep 16 02:04:57 2015 10784 3390 09/16 14:00:44 2391 checkDumpHeader() - Assume WIN32 block size equal to cluster size of 4096 bytes 10784 3390 09/16 14:00:44 2391 checkDumpHeader() - file system block size: 4096 bytes 10784 3390 09/16 14:00:44 2391 checkDumpHeader() - The longest permissible path length defined by Windows documentation: 1024 chars 10784 3390 09/16 14:00:44 2391 parseDumpStream() - Begin parsing file data ... 10784 3390 09/16 14:00:44 2391 parseDumpStream() - Restoring file [/expdp_export_cumulative.log] 10784 3390 09/16 14:00:44 2391 fill_tape_buffer() - sending notify_data_read for offset [1422527511552], length [4194304] , chunk_offset [18446744073709551615], chunk_length [18446744073709551615] 10784 3390 09/16 14:00:44 2391 ndmp_v4.cpp 4697 NDMP_NOTIFY_DATA_READ: Offset:[1422527511552] Length:[4194304] 10784 3390 09/16 14:00:44 2391 ndmp_v4.cpp 4711 NDMP_NOTIFY_DATA_READ: successful 10784 4a7c 09/16 14:01:44 2391 ndmp_v4.cpp 5612 NDMP_DATA_GET_STATE reply: BytesProcessed:[0] ReadOffset:[1422527511552] ReadLen:[4194304] 10784 4a7c 09/16 14:01:44 2391 ndmp_v4.cpp 5644 NDMP_DATA_GET_STATE reply: successful 10784 4a7c 09/16 14:01:44 2391 Waiting for next NDMP message. TimeOut [9000] 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B35474000] [1422528036864] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B354F4400] [1422528562176] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B35574800] [1422529087488] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B355F4C00] [1422529612800] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B35675000] [1422530138112] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B356F5400] [1422530663424] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B35775800] [1422531188736] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 fill_tape_buffer() - sending notify_data_read for offset [1422531705856], length [4194304] , chunk_offset [18446744073709551615], chunk_length [18446744073709551615] 10784 3390 09/16 14:01:57 2391 ndmp_v4.cpp 4697 NDMP_NOTIFY_DATA_READ: Offset:[1422531705856] Length:[4194304] 10784 3390 09/16 14:01:57 2391 ndmp_v4.cpp 4711 NDMP_NOTIFY_DATA_READ: successful 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B357F5C00] [1422531714048] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B35876000] [1422532239360] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 getfile() - Getting next file hdr at tape offset 0x[14B358F6400] [1422532764672] 10784 3390 09/16 14:01:57 2391 getfile() - Successfully read the next header for the same file. 10784 3390 09/16 14:01:57 2391 endOfFileRestore() - Finished restoring file [/expdp_export_cumulative.log] 10784 3390 09/16 14:01:57 2391 Sending the status of the restore to NasRestore 10784 3390 09/16 14:01:57 2391 processDumpData() - Finished parsing the dump stream, time taken [0]Hr:[4]Min:[22]Secs,total # bytes processed [5273444] 10784 3390 09/16 14:01:57 2391 Finished restoring data. NDMP error::0::NDMP_NO_ERR 10784 3390 09/16 14:01:57 2391 Halting the data task with reason 1 10784 3390 09/16 14:01:57 2391 haltDataTask() - Closing the data socket 10784 3390 09/16 14:01:57 2391 ndmp_v4.cpp 4669 NDMP_NOTIFY_DATA_HALTED: Reason:[1=NDMP_DATA_HALT_SUCCESSFUL] 10784 3390 09/16 14:01:57 2391 ndmp_v4.cpp 4682 NDMP_NOTIFY_DATA_HALTED: successful 10784 4a7c 09/16 14:01:57 2391 ndmp_v4.cpp 5612 NDMP_DATA_GET_STATE reply: BytesProcessed:[5273444] ReadOffset:[1422531705856] ReadLen:[4194304] 10784 4a7c 09/16 14:01:57 2391 ndmp_v4.cpp 5644 NDMP_DATA_GET_STATE reply: successful 10784 4a7c 09/16 14:01:57 2391 Waiting for next NDMP message. TimeOut [9000] 10784 4a7c 09/16 14:03:28 2391 ndmp_v4.cpp 5694 NDMP_DATA_STOP reply: Error[0] 10784 4a7c 09/16 14:03:28 2391 ndmp_v4.cpp 5714 NDMP_DATA_STOP reply: successful 10784 4a7c 09/16 14:03:28 2391 Waiting for next NDMP message. TimeOut [9000] 10784 4a7c 09/16 14:03:28 2391 ndmp.cpp 1038 NDMP_CONNECT_CLOSE [] 10784 4a7c 09/16 14:03:28 2391 Waiting for next NDMP message. TimeOut [9000] 10784 4a7c 09/16 14:03:28 2391 ndmp.cpp 1379 NDMP_CONNECTION_CLOSED 10784 4a7c 09/16 14:03:28 2391 runMainLoop() - MsgReceive returned [-1]. NDMP Message [654311549]==[NDMP_CONNECTION_CLOSED] 10784 4a7c 09/16 14:03:28 2391 runMainLoop() - Exiting.. 10784 4a7c 09/16 14:03:28 2391 ~CVNdmpTapeBuffer() - freed tape buffer 10784 4a7c 09/16 14:03:28 2391 ~CVNdmpTapeBuffer() - destructor called 10784 4a7c 09/16 14:03:28 2391 CVJobCtrlLog::unregisterProcess(): successfully removed file [C:\Program Files\NetApp\SnapProtect\Base\JobControl\10.784] 10784 4a7c 09/16 14:03:28 2391 main() - ============================================ 10784 4a7c 09/16 14:03:28 2391 main() - ----------------- STOPPED ----------------- 10784 4a7c 09/16 14:03:28 2391 main() - ============================================ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : spiderman File : IndexCacheServer.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 6484 1ae8 09/16 13:27:34 2388 TranLog_StartDownloadWorker will attempt to get ICD from main Index Cache @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : spiderman File : JobManager.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 7080 2bb0 09/16 13:27:15 2388 Servant [---- IMMEDIATE RESTORE REQUEST ----] Task id [2388] Clnt[hrtcluster.hrt.hr] AppType[NAS][13] 7080 d64 09/16 13:27:16 2388 Scheduler Restore request successfuly sent 7080 d64 09/16 13:27:16 2388 Scheduler Phase [2-Restore] (0,0) started on [spiderman.hrt.hr] in [0] second(s) - startRestore.exe 2388 2388 7080 2708 09/16 13:27:16 2388 Servant Reg [Control] received. Client [spiderman] plattype = 1 7080 2708 09/16 13:27:49 2388 Servant Reg [IndexRestore] received. Client [pris2] plattype = 2 7080 2668 09/16 13:27:49 2388 Servant Reg [NotControl] received. Client [pris2] plattype = 4 7080 2668 09/16 13:27:56 2388 Servant Reg [NotControl] received. Client [pris2] plattype = 4 7080 2668 09/16 13:27:59 2388 Servant Reg [NotControl] received. Client [spiderman] plattype = 2 7080 2668 09/16 13:31:10 2388 Scheduler Set pending cause [Restore job couldn't restore at least one item successfully. Please check log files for more details.]::Client [spiderman] Application [StartRestore] Message Id [402653277] RCID [0] ReservationId [0]. Level [0] flags [0] id [0] overwrite [0] append [0] CustId[0]. 7080 2708 09/16 13:31:10 2388 Scheduler Job [Failed] message received from [spiderman.hrt.hr] Module [StartRestore] Token [] restartPhase [0] 7080 2708 09/16 13:31:10 #### CvResourceManager::releaseJobStreamsNoRetry() - :RM_TRACE[2388]:CvResourceManager.cpp:10424: No reservation exists for Job 2388 7080 2708 09/16 13:31:10 2388 JobSvr Obj Phase [2-Restore] has failed. Restore will continue with phase [Cleanup] before failing. 7080 d64 09/16 13:31:12 2388 Scheduler Restore request successfuly sent 7080 d64 09/16 13:31:12 2388 Scheduler Phase [3-Cleanup] (1,0) started on [spiderman.hrt.hr] in [0] second(s) - startRestore.exe 2388 2388 -o 1:1:0 -cleanup 7080 2708 09/16 13:31:12 2388 Servant Reg [Control] received. Client [spiderman] plattype = 1 7080 2668 09/16 13:31:27 2388 Scheduler Phase [Completed w/ one or more errors] message received from [spiderman.hrt.hr] Module [StartRestore] Token [] restartPhase [0] 7080 2668 09/16 13:31:27 #### CvResourceManager::releaseJobStreamsNoRetry() - :RM_TRACE[2388]:CvResourceManager.cpp:10424: No reservation exists for Job 2388 7080 2668 09/16 13:31:27 2388 JobSvr Obj Phase [3-Cleanup] has succeeded. The restore job has failed. 7080 2668 09/16 13:31:27 2388 Scheduler -> FAILED <- @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : spiderman File : MediaManager.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 7104 1d44 09/16 13:27:59 2388 MOUNT [17] DATAPATH SELECTED = , DRIVEPOOL <2> LIBRARY 7104 1dc0 09/16 13:28:12 2388 MOUNT [ ] MOUNT REQUEST from [spiderman] : JOB 2388 7104 1dc0 09/16 13:28:12 2388 MOUNT [17] DATAPATH SELECTED = , DRIVEPOOL <2> LIBRARY 7104 1dc0 09/16 13:28:12 2388 MOUNT [17] RESERVE VOL 17 AND DRIVE IN DRIVEPOOL 2 7104 1dc0 09/16 13:28:13 #### MOUNT [0 ] RESERVED RESERVATION ID [3142],RESOURCE USER [148], SP [], COPY [(ID:0)], MEDIAGROUP [1160], VOLUME [17], MEDIA [AEM394L6(ID:17)], DRIVE [HP Ultrium 6-SCSI_2(ID:2)], DRIVEPOOL [DrivePool(spiderman)2(ID:2)], LIBRARY [FUJITSU ETERNUS LT S2], HOST[spiderman] 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] JOB [2388] SUCCEEDED IN RESERVATION 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] USING RESERVATION ID [3142], DRIVE ID [2] 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] MOUNT PARAMS - JOB [2388] TOKEN [] 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] MEDIA INFO : BARCODE [AEM394L6], VOLUME [17], MEDIAID [17] 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] LIBRARY INFO : NAME [FUJITSU ETERNUS LT S2] 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] LIBRARY BLIND : FALSE 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] MNT TYPE: MOUNT_VOL_IN_ANY_DRIVEPOOL 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] DRIVE POOL ID: 2, TYPE: Regular 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] LIBRARY HOST ID: 2 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] DRIVE HOST: spiderman.hrt.hr 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] JOB [2388] IS A RESTORE JOB 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] REUSE CACHEMOUNT 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] REUSE VOLUME [17], BARCODE [AEM394L6] MOUNTED IN DRIVE [Lib2_Drive2] IN LIBRARY [Library2] 7104 1dc0 09/16 13:28:13 2388 MOUNT [17] DRIVE ACCESSPATH : \\.\Tape2, DRIVEPOOL 2, HOST 2, SERIAL# , 7104 1d44 09/16 13:30:34 2388 MOUNT [17] UNMOUNT PARAMS from [spiderman.hrt.hr] : JOB 2388, RESERVATION ID: 3142 RELEASE VOLUME : 1, RELEASE DRIVE : 1, LOGICAL UNMOUNT : 1, PHYSICAL UNMOUNT : 0, RESOURCE CONSUMER ID: 0 7104 1d44 09/16 13:30:34 2388 MOUNT [17] Unreserved Vol 17 Drive -1, ReservationId 3142 7104 1d44 09/16 13:30:34 2388 Resource Removed resource user 148 7104 1d44 09/16 13:30:34 #### Resource Released reservation 3142 @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : spiderman File : StartRestore.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 11876 25a4 09/16 13:27:16 2388 STARTRESTORE Resetting to time [0] to current time [1442402835] 11876 25a4 09/16 13:27:16 2388 STARTRESTORE To time is changed from [1442402835] to archive file creation time [1442370632] returned by getArchFileByTime for backupset [5] reference time [1442402835] 11876 25a4 09/16 13:27:16 2388 Init() - Initializing job control [token=No Token,cn=spiderman] in single threaded mode, serverName [Instance001], ControlFlag [1], Job Id [2388] 11876 25a4 09/16 13:27:16 2388 EvReturnData::begin() - Can't send because no server connection 11876 9c 09/16 13:27:17 2388 STARTRESTORE options - 0x880 11876 9c 09/16 13:27:17 2388 STARTRESTORE Restore Options - ER_PRESERVE_LEVEL | ER_NONFULLREGISTRY 11876 9c 09/16 13:27:17 2388 STARTRESTORE synthetic full - no 11876 9c 09/16 13:27:17 2388 STARTRESTORE commcell - 2 11876 9c 09/16 13:27:17 2388 STARTRESTORE source client - 3 11876 9c 09/16 13:27:17 2388 STARTRESTORE dest client - 1046 11876 9c 09/16 13:27:17 2388 STARTRESTORE apptype - 13 11876 9c 09/16 13:27:17 2388 STARTRESTORE instance - 1 11876 9c 09/16 13:27:17 2388 STARTRESTORE backupset = 5 11876 9c 09/16 13:27:17 2388 STARTRESTORE subclient - 6 11876 9c 09/16 13:27:17 2388 STARTRESTORE from time - 0 11876 9c 09/16 13:27:17 2388 STARTRESTORE to time - 1442370632 2015/09/16 04:30:32 11876 9c 09/16 13:27:17 2388 STARTRESTORE source path - [/svm01/vol_orabckp/expdp/pris/expdp_export_cumulative.log] 11876 9c 09/16 13:27:17 2388 STARTRESTORE dest path - [/tmp] 11876 9c 09/16 13:27:17 2388 STARTRESTORE copy - 0 11876 9c 09/16 13:27:17 2388 STARTRESTORE em function - 0 11876 9c 09/16 13:27:17 2388 STARTRESTORE em firstnode - 0 11876 9c 09/16 13:27:17 2388 STARTRESTORE em skipnodes - 0 11876 9c 09/16 13:27:17 2388 STARTRESTORE em page size - -1 11876 9c 09/16 13:27:17 2388 STARTRESTORE skip errors and continue - [false] 11876 9c 09/16 13:27:17 2388 STARTRESTORE checking whether super restore should be applied 11876 9c 09/16 13:27:17 2388 STARTRESTORE filter browse XML string [] 11876 9c 09/16 13:27:17 2388 STARTRESTORE converting restore job into a single subclient restore for subclient [6] 11876 9c 09/16 13:27:17 2388 STARTRESTORE starting regular restore 11876 9c 09/16 13:27:17 2388 FSSubclientConf::load(857) - +++ 11876 9c 09/16 13:27:17 2388 FSSubclientConf::load(857) - --- 0:00.088410 11876 9c 09/16 13:27:17 2388 STARTRESTORE start operation on subclient id [6] name [Orabckp] backupset id [5] 11876 9c 09/16 13:27:17 2388 STARTRESTORE SECURITY: canRestore() returned true for subclientId (6). User (2), commCell (2), srcClientId (3), destClientId (1046), appTypeId (13), instance (1), backupSet (5), inPlace = (false) impersonateUser = (false) machineUId=(). 11876 9c 09/16 13:27:17 2388 STARTRESTORE filter browse XML string [] 11876 9c 09/16 13:27:17 2388 STARTRESTORE MediaAgent 'pris2.hrt.hr' was extracted from the restore options table - getMediaAgent not called 11876 9c 09/16 13:27:17 2388 STARTRESTORE mangled name for 'pris2.hrt.hr' is 'pris2.hrt.hr*pris2*8400*8402' 11876 9c 09/16 13:27:17 2388 STARTRESTORE Non-snap restore for non-DB restore 11876 9c 09/16 13:27:17 2388 STARTRESTORE connecting to MediaAgent 'pris2.hrt.hr*pris2*8400*8402' 11876 9c 09/16 13:27:22 2388 STARTRESTORE Sending source path '/svm01/vol_orabckp/expdp/pris/expdp_export_cumulative.log' with strip level 4 11876 9c 09/16 13:27:22 2388 STARTRESTORE Sending destination path '/tmp' 11876 29cc 09/16 13:30:57 2388 STARTRESTORE File Statistics: Succeeded [0], Skipped [0] Failed [1] 11876 29cc 09/16 13:30:59 2388 STARTRESTORE Received FSR_MSG_RESTORE_END 11876 29cc 09/16 13:31:10 2388 STARTRESTORE Received disconnect request 11876 29cc 09/16 13:31:10 2388 STARTRESTORE Disconnected MA session completed restore 11876 9c 09/16 13:31:10 2388 STARTRESTORE Success | Partial Success | Failure: Total files [1], Succeeded [0], Transferred [0], Skipped [0], Failed [1], MaAttach [true] 11876 9c 09/16 13:31:10 2388 STARTRESTORE NAS: Since we are done with all the subclients and have no successful files failing the restore. 11876 9c 09/16 13:31:10 2388 Sending FAILED complete message to JM, 2388 11876 25a4 09/16 13:31:12 2388 ::StartRestore() - Got restart string from job manager as [1:1:0] 11876 25a4 09/16 13:31:12 2388 ::StartRestore() - Start Restore started for doing cleanup. 11876 25a4 09/16 13:31:12 2388 STARTRESTORE Resetting to time [0] to current time [1442402835] 11876 25a4 09/16 13:31:12 2388 STARTRESTORE To time is changed from [1442402835] to archive file creation time [1442370632] returned by getArchFileByTime for backupset [5] reference time [1442402835] 11876 25a4 09/16 13:31:12 2388 Init() - Initializing job control [token=No Token,cn=spiderman] in single threaded mode, serverName [Instance001], ControlFlag [1], Job Id [2388] 11876 25a4 09/16 13:31:12 2388 EvReturnData::begin() - Can't send because no server connection 11876 9c 09/16 13:31:12 2388 STARTRESTORE options - 0x880 11876 9c 09/16 13:31:12 2388 STARTRESTORE Restore Options - ER_PRESERVE_LEVEL | ER_NONFULLREGISTRY 11876 9c 09/16 13:31:12 2388 STARTRESTORE synthetic full - no 11876 9c 09/16 13:31:12 2388 STARTRESTORE commcell - 2 11876 9c 09/16 13:31:12 2388 STARTRESTORE source client - 3 11876 9c 09/16 13:31:12 2388 STARTRESTORE dest client - 1046 11876 9c 09/16 13:31:12 2388 STARTRESTORE apptype - 13 11876 9c 09/16 13:31:12 2388 STARTRESTORE instance - 1 11876 9c 09/16 13:31:12 2388 STARTRESTORE backupset = 5 11876 9c 09/16 13:31:12 2388 STARTRESTORE subclient - 6 11876 9c 09/16 13:31:12 2388 STARTRESTORE from time - 0 11876 9c 09/16 13:31:12 2388 STARTRESTORE to time - 1442370632 2015/09/16 04:30:32 11876 9c 09/16 13:31:12 2388 STARTRESTORE source path - [/svm01/vol_orabckp/expdp/pris/expdp_export_cumulative.log] 11876 9c 09/16 13:31:12 2388 STARTRESTORE dest path - [/tmp] 11876 9c 09/16 13:31:12 2388 STARTRESTORE copy - 0 11876 9c 09/16 13:31:12 2388 STARTRESTORE em function - 0 11876 9c 09/16 13:31:12 2388 STARTRESTORE em firstnode - 0 11876 9c 09/16 13:31:12 2388 STARTRESTORE em skipnodes - 0 11876 9c 09/16 13:31:12 2388 STARTRESTORE em page size - -1 11876 9c 09/16 13:31:12 2388 STARTRESTORE skip errors and continue - [false] 11876 9c 09/16 13:31:12 2388 STARTRESTORE checking whether super restore should be applied 11876 9c 09/16 13:31:12 2388 STARTRESTORE starting regular restore 11876 9c 09/16 13:31:12 2388 FSSubclientConf::load(857) - +++ 11876 9c 09/16 13:31:12 2388 FSSubclientConf::load(857) - --- 0:00.072851 11876 9c 09/16 13:31:12 2388 STARTRESTORE start operation on subclient id [6] name [Orabckp] backupset id [5] 11876 9c 09/16 13:31:12 2388 STARTRESTORE SECURITY: canRestore() returned true for subclientId (6). User (2), commCell (2), srcClientId (3), destClientId (1046), appTypeId (13), instance (1), backupSet (5), inPlace = (false) impersonateUser = (false) machineUId=(). 11876 9c 09/16 13:31:12 2388 STARTRESTORE filter browse XML string [] 11876 9c 09/16 13:31:12 2388 STARTRESTORE MediaAgent 'pris2.hrt.hr' was extracted from the restore options table - getMediaAgent not called 11876 9c 09/16 13:31:12 2388 STARTRESTORE mangled name for 'pris2.hrt.hr' is 'pris2.hrt.hr*pris2*8400*8402' 11876 9c 09/16 13:31:12 2388 STARTRESTORE Non-snap restore for non-DB restore 11876 9c 09/16 13:31:12 2388 STARTRESTORE connecting to MediaAgent 'pris2.hrt.hr*pris2*8400*8402' 11876 9c 09/16 13:31:15 2388 STARTRESTORE Sending source path 'cleanup' with strip level 0 11876 9c 09/16 13:31:15 2388 STARTRESTORE Sending destination path '/tmp' 11876 29cc 09/16 13:31:26 2388 STARTRESTORE Received disconnect request 11876 29cc 09/16 13:31:26 2388 STARTRESTORE Disconnect MA session received for incomplete restore 11876 27c8 09/16 13:31:26 2388 STARTRESTORE Restore for this subclient has failed. Please look into the clrestore log on client machine. 11876 27c8 09/16 13:31:26 2388 STARTRESTORE Success | Partial Success | Failure: Total files [0], Succeeded [0], Transferred [0], Skipped [0], Failed [0], MaAttach [true] 11876 27c8 09/16 13:31:26 2388 Sending PARTIALSUCCESS complete message to JM, 2388 @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : pris2 File : fsIndexedRestore.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 13887 b613e720 09/16 13:27:24 2388 DIRECTORY open: opendir /opt/snapprotect/MediaAgent/IndexCache/CV_Index/restores/2388 failed, errno 2 13887 b613e720 09/16 13:27:24 2388 DIRECTORY open: opendir /opt/snapprotect/MediaAgent/IndexCache/CV_Index/restores failed, errno 2 13887 b613e720 09/16 13:27:24 2388 CVArchive::ConnectSessionToArchiveManager() - Got CommServe name [spiderman.hrt.hr] from MediaAgent Platform Info 13887 b613e720 09/16 13:27:24 2388 CVArchive::ConnectSessionToArchiveManager() - Attaching to CommServer [spiderman.hrt.hr] from Platform Type 2 13887 b613e720 09/16 13:27:24 2388 CVArchive::ConnectSessionToArchiveManager() - Attached to CommServe 13887 b613e720 09/16 13:27:25 2388 setIndexingAfiles() - Latest Backup was found. CCell=2, appId=6, Copy=0, Time=2147483647. Returned afile=(2,140325171495018,4238) copy=110 created=1442370632. 13887 b613e720 09/16 13:27:26 2388 setIndexingAfiles() - LastInCycle Backup was found. CCell=2, appId=6, Copy=0, Time=1442370632. Returned afile=(2,140325171495018,4238) copy=110 created=1442370632. 13887 b613e720 09/16 13:27:27 2388 setIndexingAfiles() - Exact Backup was found. CCell=2, appId=6, Copy=0, Time=1442370632. Returned afile=(2,140325171495018,4238) copy=110 created=1442370632. 13887 b613e720 09/16 13:27:28 2388 DIRECTORY open: opendir /opt/snapprotect/MediaAgent/IndexCache/CV_Index/2/6 failed, errno 2 13887 b613e720 09/16 13:27:28 2388 CACHEFS: getIndex(): step [1: Next-In-Cache-Index Open]: searchDirectoryByTime() didn't find index in cache directory. Exact timestamp = [1442370632]. 13887 b613e720 09/16 13:27:29 2388 RESTORE step [1: Next-In-Cache-Index Open]: icd->openIndex() failed for subclient [Orabckp]. 13887 b613e720 09/16 13:27:29 2388 CACHEFS: locking the download.lck file to serialize download to the index cache 13887 b613e720 09/16 13:27:34 2388 CACHEFS: Sending request to local CVMA for download of the IndexCache [/opt/snapprotect/MediaAgent/IndexCache/CV_Index/2/6/1442370632] 13887 b613e720 09/16 13:27:34 2388 CXmlMsgRouter::initializeCommunicationRouter() connected successfully to CVMA on 'pris2.hrt.hr*pris2*8400*8402'. 13887 af9d9700 09/16 13:27:34 2388 xmlRouter receiveThread begin. 13887 b613e720 09/16 13:27:44 2388 CACHEFS: '/opt/snapprotect/MediaAgent/IndexCache/CV_Index/2/6/1442370632/TL_RST.cfg' not present - nothing to restore. 13887 b613e720 09/16 13:27:44 2388 CACHEFS: getIndex(): step [2: Last-In-Cycle-Index Download]: Index [/opt/snapprotect/MediaAgent/IndexCache/CV_Index/2/6/1442370632] is downloaded. 13887 b613e720 09/16 13:27:44 2388 CACHEFS: WARNING: CTree ISAM was initialized during check. 13887 b613e720 09/16 13:27:44 2388 CVArchive::ConnectSessionToArchiveManager() - Got CommServe name [spiderman.hrt.hr] from MediaAgent Platform Info 13887 b613e720 09/16 13:27:44 2388 CVArchive::ConnectSessionToArchiveManager() - Attaching to CommServer [spiderman.hrt.hr] from Platform Type 2 13887 b613e720 09/16 13:27:44 2388 CVArchive::ConnectSessionToArchiveManager() - Attached to CommServe 13887 b613e720 09/16 13:27:46 2388 CVArchive::ConnectSessionToArchiveManager() - Got CommServe name [spiderman.hrt.hr] from MediaAgent Platform Info 13887 b613e720 09/16 13:27:46 2388 CVArchive::ConnectSessionToArchiveManager() - Attaching to CommServer [spiderman.hrt.hr] from Platform Type 2 13887 b613e720 09/16 13:27:46 2388 CVArchive::ConnectSessionToArchiveManager() - Attached to CommServe 13887 b613e720 09/16 13:27:48 2388 RESTOREIDX restore accessing index '/opt/snapprotect/MediaAgent/IndexCache/CV_Index/2/6/1442370632' 13887 b613e720 09/16 13:27:48 2388 RESTOREIDX Continue with checking CS for presence of erase masks for timestamp [0] 13887 b613e720 09/16 13:27:48 2388 SDVERSION no indexing subclient for client 3, appType 13 13887 b613e720 09/16 13:27:48 2388 RESTORE open directory [/opt/snapprotect/MediaAgent/IndexCache/CV_Index/2/6/1442370632] to check for metadata collection flag 13887 b613e720 09/16 13:27:48 2388 NASOPTIMIZER optimizer limit dNASOPTIMLIMIT not found in MediaAgent registry folder, defaults to infinite 13887 b613e720 09/16 13:27:48 2388 RESTORE NAS Recurse optimization check is [false] for client [pris2] 13887 b613e720 09/16 13:27:48 2388 CVArchive::ConnectSessionToArchiveManager() - Got CommServe name [spiderman.hrt.hr] from MediaAgent Platform Info 13887 b613e720 09/16 13:27:48 2388 CVArchive::ConnectSessionToArchiveManager() - Attaching to CommServer [spiderman.hrt.hr] from Platform Type 2 13887 b613e720 09/16 13:27:48 2388 CVArchive::ConnectSessionToArchiveManager() - Attached to CommServe 13887 b613e720 09/16 13:27:49 2388 MediaAgent Interface name pris2.hrt.hr mangles to pris2.hrt.hr*pris2*8400*8402 13887 b613e720 09/16 13:27:50 2388 CVRestoreFiles::createRestoreProcess() - remote executable = nasRestore.exe, commandline args = -commcellid 2 -appid 6 -port 8400 -host pris2.hrt.hr -ptype 2 -destClientId 1046 -maHostName 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::acceptSession() - Client Session will be kept alive 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::acceptSession() - Keep Alive Messages will be sent every 1800 minutes 13887 b613e720 09/16 13:27:51 2388 Init() - Initializing job control [token=No Token,cn=pris2], serverName [spiderman.hrt.hr], ControlFlag [3], Job Id [2388] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - Sending initialization data: 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - seqNum = [4436701240199] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - appNumber = [6] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - appType = [13] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - commCellId = [2] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - copyId = [0] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - jobId = [2388] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - subClient = [Orabckp] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - numFiles = [1] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - srcClient = [hrtcluster.hrt.hr] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - destClient = [pris2.hrt.hr] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - userName = [NULL] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - password = [NULL] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - initRestartNumber = [0] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - noLossRestore = [0] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - mountDbsAfterRestore = [0] 13887 af958700 09/16 13:27:51 2388 CVRestoreFiles::jobCtrlThreadProcMember() - Thread jobCtrlThreadProc started. 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - Sent message FSR_MSG_INIT_DATA 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - Client version is [15] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::sendInitData() - Sent message FSR_MSG_INIT_DATA_VER2 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::init() - Initialization of client [pris2.hrt.hr] subclient [Orabckp] completed. 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::setRestoreParameters() - Sending restore parameters: 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::setRestoreParameters() - options = [1000478] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::setRestoreParameters() - destDir = [/tmp] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::setRestoreParameters() - numSrcPaths = [1] 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::setRestoreParameters() - Sending [1] pathnames to be restored 13887 b613e720 09/16 13:27:51 2388 CVRestoreFiles::setRestoreParameters() - pathname [0]: [/svm01/vol_orabckp/expdp/pris/expdp_export_cumulative.log] 13887 b613e720 09/16 13:27:51 2388 RESTORETABLE Rebuilding index for restore vector table 13887 b613e720 09/16 13:27:52 2388 RESTORETABLE restore vector index rebuilt 13887 b613e720 09/16 13:27:52 2388 RESTORETABLE Start processing of items with type 0 13887 b613e720 09/16 13:27:52 2388 CVRestoreFiles::restoreFile() - Sending FSR_MSG_OPEN_ARCHIVE (2,106,4236) 13887 b613e720 09/16 13:27:57 2388 CVRestoreFiles::restoreFile() - Launching feedbackThreadProc thread... 13887 af8d7700 09/16 13:27:57 2388 CVRestoreFiles::feedbackThreadProcMember() - Thread feedbackThreadProc started. 13887 b613e720 09/16 13:27:57 2388 CVRestoreFiles::waitForCompletion() - Sending FSR_MSG_CLOSE_ARCHIVE 13887 b613e720 09/16 13:27:57 2388 CVRestoreFiles::waitForCompletion() - Sending FSR_MSG_WAIT_ARCHIVE_CLOSED 13887 b613e720 09/16 13:27:57 2388 CVRestoreFiles::waitForCompletion() - Waiting for feedbackThreadProc to terminate... 13887 af8d7700 09/16 13:30:59 2388 CVRestoreFiles::feedbackThreadProcMember() - Received FSR_MSG_WAIT_ARCHIVE_CLOSED 13887 af8d7700 09/16 13:30:59 2388 CVRestoreFiles::feedbackThreadProcMember() - Feedback Thread is done... 13887 b613e720 09/16 13:30:59 2388 CVRestoreFiles::finalize() - Waiting for Job Control Thread to finish... 13887 af958700 09/16 13:30:59 2388 CVRestoreFiles::jobCtrlThreadProcMember() - Job Control Thread is done... 13887 b613e720 09/16 13:30:59 2388 CVRestoreFiles::finalize() - Launching feedbackThreadProc thread... 13887 af958700 09/16 13:30:59 2388 CVRestoreFiles::feedbackThreadProcMember() - Thread feedbackThreadProc started. 13887 b613e720 09/16 13:30:59 2388 CVRestoreFiles::finalize() - MSG_RESTORE_END sent to client 13887 b613e720 09/16 13:30:59 2388 CVRestoreFiles::finalize() - Waiting for feedbackThreadProc to terminate... 13887 af958700 09/16 13:31:00 2388 CVRestoreFiles::feedbackThreadProcMember() - Received FSR_MSG_RESTORE_END 13887 af958700 09/16 13:31:01 2388 CVRestoreFiles::feedbackThreadProcMember() - Received CVS_PM_DISCONNECT_REQ 13887 af958700 09/16 13:31:01 2388 CVRestoreFiles::SetExtentRestoreStatus() - going to release semaphore for image restore 13887 af958700 09/16 13:31:01 2388 CVRestoreFiles::SetExtentRestoreStatus() - released semaphore for image restore 13887 af958700 09/16 13:31:01 2388 CVRestoreFiles::feedbackThreadProcMember() - Feedback Thread is done... 13887 b613e720 09/16 13:31:01 2388 CVRestoreFiles::finalize() - Sending FSR_MSG_RESTORE_END to fsStartRestore 13887 b613e720 09/16 13:31:01 2388 CVRestoreFiles::restartNeeded() - restartNeeded: _fatalError=0, _stopRequest=0 13887 b613e720 09/16 13:31:01 2388 RESTORE 1 files restored 13887 b613e720 09/16 13:31:01 2388 FsIndexedRestore::run() - COMPLETED ::restore(). 13887 b613e720 09/16 13:31:11 2388 ::main() - Sending disconnect to FSStartRestore 13887 b613e720 09/16 13:31:13 2388 ::main() - Received disconnect reply 13887 b613e720 09/16 13:31:13 2388 ::main() - Exiting... 14175 1fea8720 09/16 13:31:17 2388 DIRECTORY open: opendir /opt/snapprotect/MediaAgent/IndexCache/CV_Index/restores/2388 failed, errno 2 14175 1fea8720 09/16 13:31:17 2388 FsIndexedRestore::run() - COMPLETED ::restore(). 14175 1fea8720 09/16 13:31:27 2388 ::main() - Sending disconnect to FSStartRestore 14175 1fea8720 09/16 13:31:28 2388 ::main() - Received disconnect reply 14175 1fea8720 09/16 13:31:28 2388 ::main() - Exiting... @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : pris2 File : CVNRDS.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 13925 952b0720 09/16 13:27:59 2388 main() - ============================================ 13925 952b0720 09/16 13:27:59 2388 main() - ----------------- STARTED ----------------- 13925 952b0720 09/16 13:27:59 2388 main() - ============================================ 13925 952b0720 09/16 13:27:59 2388 main() - /opt/snapprotect/iDataAgent/CVNRDS -l ndmp -p 33997d8ca623ed73d2fbc4355ef54f8b829f61912c84c6334 -j 2388 -cn pris2 -cn pris2 cvshost:pris2.hrt.hr*pris2 cvsport:29259:0 cvsmyplatform:4 cvsremoteplatform:2 -vm Instance001 13925 952b0720 09/16 13:27:59 2388 Init() - Initializing job control [token=,cn=pris2], serverName [spiderman.hrt.hr], ControlFlag [4], Job Id [2388] 13925 952b0720 09/16 13:27:59 2388 Cvcl::init() - CVCL: Running in FIPS Mode 13925 952b0720 09/16 13:27:59 2388 CompleteStartup() - Process was created using IPv4. 13925 952b0720 09/16 13:27:59 2388 CompleteStartup() - Going to listen on host:[pris2.hrt.hr]. Listening on all IPv4 interfaces. 13925 952b0720 09/16 13:27:59 2388 CompleteStartup() - Going to listen on socket [5] port [54710]. 13925 952b0720 09/16 13:27:59 2388 CompleteStartup() - Send to NAS iDA NDMP port [54710] binded to socket 13925 952b0720 09/16 13:28:02 2388 ndmp.cpp 3513 NOTIFY_CONNECTED: protocol_version[4] 13925 952b0720 09/16 13:28:02 2388 ndmp.cpp 3521 NOTIFY_CONNECTED: successful 13925 952b0720 09/16 13:28:02 2388 ndmp.cpp 3480 NDMP_CONNECT_OPEN reply 13925 952b0720 09/16 13:28:02 2388 ndmp.cpp 3491 NDMP_CONNECT_OPEN reply: successful 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4300 NDMP_CONFIG_GET_SERVER_INFO reply: Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] Auth:[2] 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4329 NDMP_CONFIG_GET_SERVER_INFO reply: successful 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4073 NDMP_CONFIG_GET_AUTH_ATTR reply: Error[0] AuthType[2] 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4095 NDMP_CONFIG_GET_AUTH_ATTR reply: successful 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4157 NDMP_CONNECT_CLIENT_AUTH reply: Error[0] 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4177 NDMP_CONNECT_CLIENT_AUTH reply: successful 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4054 AUTHENTICATION successful 13925 952b0720 09/16 13:28:02 2388 NRDS debug level as given by registry key NDMP_API/\nNRDSLOGLEVEL is set to 1 13925 952b0720 09/16 13:28:02 2388 runMainLoop() - Registering call backs for NRDS 13925 952b0720 09/16 13:28:02 2388 Waiting for next NDMP message. TimeOut [9000] 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4352 NDMP_CONFIG_GET_HOST_INFO reply: Host[pris2.hrt.hr] OsType[Linux] Version[2.6.32-504.12.2.el6.x86_64#1 SMP Wed Mar 11 12:19:26 PDT 2015] ID:[17475407] 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4378 NDMP_CONFIG_GET_HOST_INFO reply: successful 13925 952b0720 09/16 13:28:02 2388 Waiting for next NDMP message. TimeOut [9000] 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4300 NDMP_CONFIG_GET_SERVER_INFO reply: Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] Auth:[2] 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4329 NDMP_CONFIG_GET_SERVER_INFO reply: successful 13925 952b0720 09/16 13:28:02 2388 Waiting for next NDMP message. TimeOut [9000] 13925 952b0720 09/16 13:28:02 2388 ************ GET_EXTENSION_LIST ************ 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4231 NDMP_CONFIG_GET_EXT_LIST reply 13925 952b0720 09/16 13:28:02 2388 ndmp_v4.cpp 4276 NDMP_CONFIG_GET_EXT_LIST reply: successful 13925 952b0720 09/16 13:28:02 2388 ************ GET_EXTENSION_LIST[0] ************ 13925 952b0720 09/16 13:28:02 2388 Waiting for next NDMP message. TimeOut [9000] 13925 952b0720 09/16 13:28:12 2388 NdmpDataConnectHandler() - Creating socket to connect to tape server 13925 952b0720 09/16 13:28:12 2388 NdmpDataConnectHandler() - Attempting to connect to IP passed into NDMP_DATA_CONNECT. Using IPv4. 13925 952b0720 09/16 13:28:12 2388 NdmpDataConnectHandler() - Successfully connected to ip address 13925 952b0720 09/16 13:28:12 2388 ndmp_v4.cpp 5859 NDMP_DATA_CONNECT reply: Error[0] 13925 952b0720 09/16 13:28:12 2388 ndmp_v4.cpp 5879 NDMP_DATA_CONNECT reply: successful 13925 952b0720 09/16 13:28:12 2388 Waiting for next NDMP message. TimeOut [9000] 13925 952b0720 09/16 13:28:14 2388 processStartRecoverRequest() - DAR restore requested 13925 952b0720 09/16 13:28:14 2388 ndmp_v4.cpp 5729 NDMP_DATA_START_RECOVER_CV reply: Error[0] 13925 8ebcc700 09/16 13:28:14 2388 processDumpData() - Printing the START_RECOVER request variables 13925 8ebcc700 09/16 13:28:14 2388 printStartRecoverRequest() - NDMP_DATA_START_RECOVER_CV 13925 8ebcc700 09/16 13:28:14 2388 #environmental vars: [16] 13925 8ebcc700 09/16 13:28:14 2388 environmental vars: 13925 8ebcc700 09/16 13:28:14 2388 var 1 : name = ACL_START , value = 1557968033792 13925 952b0720 09/16 13:28:14 2388 ndmp_v4.cpp 5749 NDMP_DATA_START_RECOVER_CV reply: successful 13925 952b0720 09/16 13:28:14 2388 Waiting for next NDMP message. TimeOut [9000] 13925 8ebcc700 09/16 13:28:14 2388 var 2 : name = BASE_DATE , value = 14327177354 13925 8ebcc700 09/16 13:28:14 2388 var 3 : name = CV_FIRST_OFFSET , value = 365568 13925 8ebcc700 09/16 13:28:14 2388 var 4 : name = DEBUG , value = N 13925 8ebcc700 09/16 13:28:14 2388 var 5 : name = DIRECT , value = Y 13925 8ebcc700 09/16 13:28:14 2388 var 6 : name = DUMP_DATE , value = 18622231081 13925 8ebcc700 09/16 13:28:14 2388 var 7 : name = ENHANCED_DAR_ENABLED , value = T 13925 8ebcc700 09/16 13:28:14 2388 var 8 : name = FILESYSTEM , value = /svm01/vol_orabckp 13925 8ebcc700 09/16 13:28:14 2388 var 9 : name = HIST , value = N 13925 8ebcc700 09/16 13:28:14 2388 var 10 : name = NDMP_VERSION , value = 4 13925 8ebcc700 09/16 13:28:14 2388 var 11 : name = NO_ACLS , value = N 13925 8ebcc700 09/16 13:28:14 2388 var 12 : name = PATHNAME_SEPARATOR , value = / 13925 8ebcc700 09/16 13:28:14 2388 var 13 : name = RECURSIVE , value = N 13925 8ebcc700 09/16 13:28:14 2388 var 14 : name = TYPE , value = dump 13925 8ebcc700 09/16 13:28:14 2388 var 15 : name = UPDATE , value = Y 13925 8ebcc700 09/16 13:28:14 2388 var 16 : name = VERBOSE , value = N 13925 8ebcc700 09/16 13:28:14 2388 #recover names: [1] 13925 8ebcc700 09/16 13:28:14 2388 recover names: NOT LOGGED. See NasRestore.log or CvNasSnapRestore.log 13925 8ebcc700 09/16 13:28:14 2388 options = RESTORE_OPTION_NOT_IN_PLACE | RESTORE_OPTION_UNCOND_OVERWRITE 13925 8ebcc700 09/16 13:28:14 2388 | RESTORE_OPTION_RECURSIVE | RESTORE_OPTION_NDMP_RESTORE 13925 8ebcc700 09/16 13:28:14 2388 preprocessRestorePaths() - Sorted source pathnames in ascending order 13925 8ebcc700 09/16 13:28:14 2388 CvUCS::init_static() - Native charset="UTF-8". 13925 8ebcc700 09/16 13:28:14 2388 CvUCS::init_static() - Great! This system is using ISO/IEC 10646 character set for wchar_t. We will not be using iconv() API and will be converting between MBE and UTF/UCS using C MBR functions. 13925 8ebcc700 09/16 13:28:14 2388 CvUCS::init_static() - MBE happens to be UTF-8. Will use strcpy for MBE<=>UTF-8 conversion. 13925 8ebcc700 09/16 13:28:14 2388 preprocessRestorePaths() - Created the FsRestoreNTObjectsFactory factory successfully 13925 8ebcc700 09/16 13:28:14 2388 preprocessRestorePaths::Number of valid source paths: 1 13925 8ebcc700 09/16 13:28:14 2388 Creating the DumpParser & tape buffer for file server::NetApp 13925 8ebcc700 09/16 13:28:14 2388 fill_tape_buffer() - sending notify_data_read for offset [0], length [4194304] , chunk_offset [18446744073709551615], chunk_length [18446744073709551615] 13925 8ebcc700 09/16 13:28:14 2388 ndmp_v4.cpp 4697 NDMP_NOTIFY_DATA_READ: Offset:[0] Length:[4194304] 13925 8ebcc700 09/16 13:28:14 2388 ndmp_v4.cpp 4711 NDMP_NOTIFY_DATA_READ: successful 13925 8ebcc700 09/16 13:29:22 2388 checkDumpHeader() - Dump is a NOT compressed dump 13925 8ebcc700 09/16 13:29:22 2388 Dump date: Wed Sep 16 02:04:57 2015 13925 8ebcc700 09/16 13:29:22 2388 checkDumpHeader() - file system block size: 4096 bytes 13925 8ebcc700 09/16 13:29:22 2388 checkDumpHeader() - The longest permissible path length defined by Windows documentation: 1024 chars 13925 8ebcc700 09/16 13:29:22 2388 parseDumpStream() - Begin parsing file data ... 13925 8ebcc700 09/16 13:29:22 2388 parseDumpStream() - Restoring file [/expdp_export_cumulative.log] 13925 8ebcc700 09/16 13:29:22 2388 fill_tape_buffer() - sending notify_data_read for offset [1422527511552], length [4194304] , chunk_offset [18446744073709551615], chunk_length [18446744073709551615] 13925 8ebcc700 09/16 13:29:22 2388 ndmp_v4.cpp 4697 NDMP_NOTIFY_DATA_READ: Offset:[1422527511552] Length:[4194304] 13925 8ebcc700 09/16 13:29:22 2388 ndmp_v4.cpp 4711 NDMP_NOTIFY_DATA_READ: successful 13925 952b0720 09/16 13:30:14 2388 ndmp_v4.cpp 5612 NDMP_DATA_GET_STATE reply: BytesProcessed:[0] ReadOffset:[1422527511552] ReadLen:[4194304] 13925 952b0720 09/16 13:30:14 2388 ndmp_v4.cpp 5644 NDMP_DATA_GET_STATE reply: successful 13925 952b0720 09/16 13:30:14 2388 Waiting for next NDMP message. TimeOut [9000] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - PID 13925, signal 11 (Segmentation fault), address 0x1260 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (1) /lib64/libpthread.so.0() [0x3f40c0f710] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (2) /opt/snapprotect/Base/libFclRestore.so(_ZN10FclRestore32isDBRestoreFromMultiplexedBackupEv+0x10) [0x7f74a735ffce] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (3) /opt/snapprotect/Base/libFclRestore.so(_ZN27FsRestoreUnixObjectsFactory15preapreFileNameEPKcRSsS2_P12CXFileHeader+0x110) [0x7f74a73a9434] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (4) /opt/snapprotect/Base/libFclRestore.so(_ZN27FsRestoreUnixObjectsFactory19createRestoreObjectEP12CXFileHeaderm+0x2f2) [0x7f74a73b0440] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (5) /opt/snapprotect/iDataAgent/CVNRDS(_ZN22CVFileDataActionPolicy8openFileEPKcb+0x6ff) [0x44d689] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (6) /opt/snapprotect/iDataAgent/CVNRDS(_ZN12CVDumpParser11extractfileEPKc+0x20d5) [0x4547f5] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (7) /opt/snapprotect/iDataAgent/CVNRDS(_ZN12CVDumpParser15parseDumpStreamEv+0xf3f) [0x4569f1] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (8) /opt/snapprotect/iDataAgent/CVNRDS() [0x43621e] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (9) /opt/snapprotect/iDataAgent/CVNRDS(_Z10DataThreadPv+0x4ab) [0x436bec] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (10) /opt/snapprotect/Base/libCvLib.so(_ZN8CvThread10start_funcEPv+0x70) [0x7f74a800766a] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (11) /lib64/libpthread.so.0() [0x3f40c079d1] 13925 8ebcc700 09/16 13:30:35 2388 CvBacktracer() - [bt]: (12) /lib64/libc.so.6(clone+0x6d) [0x3f408e88fd] @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : pris2 File : IndexCacheServer.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3388 f494a700 09/16 13:27:34 2388 getAfileIdByTime: commCell 2 app 6 time 1442370632 afile 2/106/4238 type (requested) 2 size 609849695 createTime 1442370632 copyId 0 refCopy 0 3388 f494a700 09/16 13:27:37 2388 regular index 1442370632 of (2, 6) from job 2376 was last seen on MA spiderman.hrt.hr*spiderman*8400*8402 3388 f494a700 09/16 13:27:44 2388 TranLog_InlineFileTransfer (/opt/snapprotect/MediaAgent/IndexCache/CV_Index/2/6/1442370632): Total files [18] - received from [last seen MA] @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : pris2 File : nasRestore.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 13908 dc9d5720 09/16 13:27:51 2388 Init() - Initializing job control [token=No Token,cn=pris2], serverName [spiderman.hrt.hr], ControlFlag [4], Job Id [2388] 13908 dc9d5720 09/16 13:27:51 2388 FclRestore::initialize() - Fail for Seek Failure selected (job option), restore would fail if seek failures happen. 13908 dc9d5720 09/16 13:27:51 2388 CVArchive::Construct() - Constructing CVArchive Object 13908 dc9d5720 09/16 13:27:51 2388 CVArchive::Construct() - Enable CVArchive Big Buffer [true] 13908 dc9d5720 09/16 13:27:51 2388 CVArchive::SetJobCtrlClient() - JobCtrlClient does not have a valid job token 13908 dc9d5720 09/16 13:27:51 2388 FclRestore::initialize() - GUI progress updates will be sent every [300] secs for app xd 13908 dc9d5720 09/16 13:27:51 2388 FclRestore::initialize() - Keep Alive Messages will be sent every 30 minutes 13908 d61ef700 09/16 13:27:51 2388 Multiple Tag Headers per Pipeline Buffer is Supported 13908 dc9d5720 09/16 13:27:51 2388 NasMedia::initialize() - Using data mover max mount retry registry key value [0] 13908 dc9d5720 09/16 13:27:51 2388 NasMedia::initialize() - Using data mover max mount retry sleep time registry key value [0] minutes. 13908 dc9d5720 09/16 13:27:51 2388 NasRestore::initializeNasRestore() - Restore from copy precedence [0] 13908 dc9d5720 09/16 13:27:51 2388 NasRestore::initializeNasRestore() - Init data: [#IcdPath="/opt/snapprotect/MediaAgent/IndexCache/CV_Index/2/6/1442370632"] 13908 d61ef700 09/16 13:27:51 2388 FClRestore::processRestoreMsgs() - Processing FSR_MSG_INIT_DATA_VER2 13908 d61ef700 09/16 13:27:51 2388 FclRestore::OnMsgInitDataVer2() - This is not a file level snap restore from disk backup SnapRestore=[0l] bkpType=[0l] rstType=[0l] 13908 d61ef700 09/16 13:27:51 2388 FClRestore::processRestoreMsgs() - Processing FSR_MSG_SET_PARAMS 13908 d61ef700 09/16 13:27:51 2388 FclRestore::OnMsgSetParams() - Options=1000478, numSrcPaths=1, destDir='/tmp' 13908 d61ef700 09/16 13:27:51 2388 JOBRESCACHEDIR: job 2388 creating '/opt/snapprotect/iDataAgent/jobResults/CV_JobResults/2/0/2388' 13908 d61ef700 09/16 13:27:51 2388 CvUCS::init_static() - Native charset="UTF-8". 13908 d61ef700 09/16 13:27:51 2388 CvUCS::init_static() - Great! This system is using ISO/IEC 10646 character set for wchar_t. We will not be using iconv() API and will be converting between MBE and UTF/UCS using C MBR functions. 13908 d61ef700 09/16 13:27:51 2388 CvUCS::init_static() - MBE happens to be UTF-8. Will use strcpy for MBE<=>UTF-8 conversion. 13908 d61ef700 09/16 13:27:52 2388 FclRestore::OnMsgSetParams() - Setting the compatibilityOptions - SEND_NO_RAW_DEVICE_DATA 13908 d61ef700 09/16 13:27:52 2388 FClRestore::processRestoreMsgs() - Processing FSR_MSG_SRC_PATH 13908 d61ef700 09/16 13:27:52 2388 NasRestore::OnMsgSrcPath() - Source path: Strip level [4] index [0] path [/svm01/vol_orabckp/expdp/pris/expdp_export_cumulative.log] 13908 d61ef700 09/16 13:27:52 2388 NasRestore::OnMsgSrcPath() - Option to update the web server DB is not set. 13908 d61ef700 09/16 13:27:52 2388 FClRestore::processRestoreMsgs() - Processing FSR_MSG_OPEN_ARCHIVE 13908 d61ef700 09/16 13:27:52 2388 MapFileRestoreSelected() - EvRstTask::getOptionString() returned empty path for map file. 13908 d61ef700 09/16 13:27:52 2388 CVArchive::Construct() - Constructing CVArchive Object 13908 d61ef700 09/16 13:27:52 2388 CVArchive::Construct() - Enable CVArchive Big Buffer [true] 13908 d61ef700 09/16 13:27:52 2388 NasMedia::getCopyID() - FIREWALL: Calling open[arch]: pid = 13908, thread = -702613760 13908 d61ef700 09/16 13:27:52 2388 CVArchive::ConnectSessionToArchiveManager() - Got CommServe name [spiderman.hrt.hr] from MediaAgent Platform Info 13908 d61ef700 09/16 13:27:52 2388 CVArchive::ConnectSessionToArchiveManager() - Attaching to CommServer [spiderman.hrt.hr] from Platform Type 2 13908 d61ef700 09/16 13:27:52 2388 CVArchive::ConnectSessionToArchiveManager() - Attached to CommServe 13908 d61ef700 09/16 13:27:53 2388 NasMedia::getCopyID() - archive manager output copy ID [110] 13908 d61ef700 09/16 13:27:54 2388 NasRestore::OnMsgOpenArchive() - calling ArchiveManagerDS::getAfileInfo() with parameters: 13908 d61ef700 09/16 13:27:54 2388 NasRestore::OnMsgOpenArchive() - afileNumber = 4236 13908 d61ef700 09/16 13:27:54 2388 NasRestore::OnMsgOpenArchive() - storagePolicyNumber = 106 13908 d61ef700 09/16 13:27:54 2388 NasRestore::OnMsgOpenArchive() - commCellId = 2 13908 d61ef700 09/16 13:27:54 2388 NasRestore::OnMsgOpenArchive() - copyId = 110 13908 d61ef700 09/16 13:27:54 2388 CVArchive::ConnectSessionToArchiveManager() - Got CommServe name [spiderman.hrt.hr] from MediaAgent Platform Info 13908 d61ef700 09/16 13:27:54 2388 CVArchive::ConnectSessionToArchiveManager() - Attaching to CommServer [spiderman.hrt.hr] from Platform Type 2 13908 d61ef700 09/16 13:27:54 2388 CVArchive::ConnectSessionToArchiveManager() - Attached to CommServe 13908 d61ef700 09/16 13:27:55 2388 ArMgrDS::getAfileInfo Returns afcFlags [32] encType [0] encKeyLen [0] needPassPhrase [0] drToolAccess [0] dataMoverType [1] 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - ArchiveManagerDS::getAfileInfo returned: 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - appNumber = 6 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - commCellId = 2 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - agroupNumber = 106 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - afileNumber = 4236 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - name = /svm01/vol_orabckp 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - fileType = 1 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - backupTime = 1442361708 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - backupLevel = 2 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - objName1 = ACL_START=1557968033792;CV_FIRST_OFFSET=365568;BASE_DATE=14327177354;CV_BUTYPE=dump;CV_RECORDSIZE=65536;DEBUG=N;DUMP_DATE=18622231081;ENHANCED_DAR_ENABLED=T;HIST=Y;NDMP_VERSION=4;NO_ACLS=N;PATHNAME_SEPARATOR=/;TYPE=dump;UPDATE=Y;VERBOSE=N; 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - afc flags = 32 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - encryption type = 0 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - ArchiveManagerDS::listAfileInfo called with parameters: 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - appNumber = 6 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - commCellId = 2 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - fileType = 1 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - beforeDate = 1442361708 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - afileName = /svm01/vol_orabckp 13908 d61ef700 09/16 13:27:55 2388 NasRestore::OnMsgOpenArchive() - jobId = 2376 13908 d61ef700 09/16 13:27:56 2388 CVArchive::ConnectSessionToArchiveManager() - Got CommServe name [spiderman.hrt.hr] from MediaAgent Platform Info 13908 d61ef700 09/16 13:27:56 2388 CVArchive::ConnectSessionToArchiveManager() - Attaching to CommServer [spiderman.hrt.hr] from Platform Type 2 13908 d61ef700 09/16 13:27:56 2388 CVArchive::ConnectSessionToArchiveManager() - Attached to CommServe 13908 d61ef700 09/16 13:27:57 2388 NasRestore::OnMsgOpenArchive() - ArchiveManagerDS::listAfileInfo archive selected for restore: 13908 d61ef700 09/16 13:27:57 2388 NasRestore::OnMsgOpenArchive() - backupTime = 1442361708 13908 d61ef700 09/16 13:27:57 2388 NasRestore::OnMsgOpenArchive() - backupLevel = 2 13908 d61ef700 09/16 13:27:57 2388 NasRestore::OnMsgOpenArchive() - afileNumber = 4236 13908 d61ef700 09/16 13:27:57 2388 NasRestore::OnMsgOpenArchive() - createJobId = 2376 13908 d61ef700 09/16 13:27:57 2388 NasRestore::OnMsgOpenArchive() - name = /svm01/vol_orabckp 13908 d61ef700 09/16 13:27:57 2388 NasRestore::OnMsgOpenArchive() - afileSize = 1557968041088 13908 d61ef700 09/16 13:27:57 2388 NasRestore::OnMsgOpenArchive() - ------------------------------------ 13908 d61ef700 09/16 13:27:58 2388 NasRestore::findStripLevel(): Source path [/svm01/vol_orabckp/expdp/pris/expdp_export_cumulative.log] matched with [/svm01/vol_orabckp/expdp/pris/expdp_export_cumulative.log]. 13908 d61ef700 09/16 13:27:58 2388 FClRestore::processRestoreMsgs() - Processing FSR_MSG_CLOSE_ARCHIVE 13908 d61ef700 09/16 13:27:58 2388 NasRestore::OnMsgCloseArchive() - NDMP data server [pris2.hrt.hr] not a file server, kicking off open systems restore. 13908 d61ef700 09/16 13:27:58 2388 kickOffRemoteServer() - remote exec name is [CVNRDS] with command line args [-l ndmp -p 33997d8ca623ed73d2fbc4355ef54f8b829f61912c84c6334 -j 2388 -cn pris2 ] 13908 d61ef700 09/16 13:27:59 2388 kickOffRemoteServer() - Received port number 54710(IPv flag 1) from remote NRS/NRDS process. 13908 d616e700 09/16 13:27:59 2388 NasRestore::progressReport() - Starting progress-reporting thread... 13908 d61ef700 09/16 13:27:59 2388 CVArchive::Construct() - Constructing CVArchive Object 13908 d61ef700 09/16 13:27:59 2388 CVArchive::Construct() - Enable CVArchive Big Buffer [true] 13908 d61ef700 09/16 13:27:59 2388 NasMedia::getCopyID() - FIREWALL: Calling open[arch]: pid = 13908, thread = -702613760 13908 d61ef700 09/16 13:27:59 2388 CVArchive::ConnectSessionToArchiveManager() - Got CommServe name [spiderman.hrt.hr] from MediaAgent Platform Info 13908 d61ef700 09/16 13:27:59 2388 CVArchive::ConnectSessionToArchiveManager() - Attaching to CommServer [spiderman.hrt.hr] from Platform Type 2 13908 d61ef700 09/16 13:27:59 2388 CVArchive::ConnectSessionToArchiveManager() - Attached to CommServe 13908 d61ef700 09/16 13:28:00 2388 NasMedia::getCopyID() - archive manager output copy ID [110] 13908 d61ef700 09/16 13:28:01 2388 NasMedia::lookupAfileInfo() - GetNextChunk hostname set to [pris2.hrt.hr] 13908 d61ef700 09/16 13:28:01 2388 NasMedia::lookupAfileInfo() - Retrieved chunk [10214] for afile [4236] Logical size [4280221824] Physical Size [4293912480] 13908 d61ef700 09/16 13:28:01 2388 NasMedia::setDrivePoolId() - destination client id set to [1046], destination client is [pris2.hrt.hr] 13908 d61ef700 09/16 13:28:01 2388 NasMedia::setDrivePoolIdForDestClient() - set drive pool ID [2] 13908 d61ef700 09/16 13:28:01 2388 kickOffRemoteServer() - remote exec name is [CVNdmpRemoteServer] with command line args [-l ndmp -p 33997d8ca623ed73d2fbc4355ef54f8b829f61912c84c6334 -j 2388 -cn spiderman -RstDestClientId 1046] 13908 d61ef700 09/16 13:28:02 2388 kickOffRemoteServer() - Received port number 64886(IPv flag 1) from remote NRS/NRDS process. 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - Calling NdmpRestore constructor with parameters: 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - destMach = pris2.hrt.hr 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - dataServerLogin= ndmp 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - dataServerOS = 5 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - dataServerVers = 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - dataServerPort = 54710 13908 d61ef700 09/16 13:28:02 2388 NasMedia::getTapeDevice() - CVMMreserveMount::getMntPnt failed. 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - tapeDeviceName = 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - tapeServer = spiderman.hrt.hr 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - moverLogin = ndmp 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - moverVersion = V2 - Galaxy 7.0 or later 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - moverPort = 64886 13908 d61ef700 09/16 13:28:02 2388 NasMedia::getTapeDevice() - CVMMreserveMount::getMntPnt failed. 13908 d61ef700 09/16 13:28:02 2388 NdmpRestore::NdmpRestore,2() - received NULL tape device. 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - Calling NdmpRestore::initialize with parameters: 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - destDir = /tmp 13908 d61ef700 09/16 13:28:02 2388 NDMP Restore Initialization: 13908 d61ef700 09/16 13:28:02 2388 destDir is -/tmp- 13908 d61ef700 09/16 13:28:02 2388 restoreACLs = false 13908 d61ef700 09/16 13:28:02 2388 DAR = OFF 13908 d61ef700 09/16 13:28:02 2388 Image = true 13908 d61ef700 09/16 13:28:02 2388 CommVault Backup Env = -ACL_START=1557968033792;CV_FIRST_OFFSET=365568;BASE_DATE=14327177354;CV_BUTYPE=dump;CV_RECORDSIZE=65536;DEBUG=N;DUMP_DATE=18622231081;ENHANCED_DAR_ENABLED=T;HIST=Y;NDMP_VERSION=4;NO_ACLS=N;PATHNAME_SEPARATOR=/;TYPE=dump;UPDATE=Y;VERBOSE=N;- 13908 d61ef700 09/16 13:28:02 2388 total size of all archive files in list [1557968041088] 13908 d61ef700 09/16 13:28:02 2388 Data server listen port number is 54710 13908 d61ef700 09/16 13:28:02 2388 Mover server listen port number is 64886 13908 d61ef700 09/16 13:28:02 2388 m_bNRDSisDataServer is [1] 13908 d61ef700 09/16 13:28:02 2388 extended options are [0x680] 13908 d61ef700 09/16 13:28:02 2388 NAS options are [1664] 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - NdmpRestore::restoreDump called with parameters: 13908 d61ef700 09/16 13:28:02 2388 NasRestore::OnMsgCloseArchive() - dumpRoot = /svm01/vol_orabckp 13908 d61ef700 09/16 13:28:02 2388 NAS RESTORE. 9.0 13908 d61ef700 09/16 13:28:02 2388 ASCII to UTF8 Translation by this procss is [n]. NRDS is [true]. 13908 d61ef700 09/16 13:28:02 2388 LOGIN TO CLIENT: NRDS[true] 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 3054 CONNECT: opening socket connection to host [pris2.hrt.hr] port [54710] family [IPv4] 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 3088 CONNECT successful: Now waiting for NOTIFY_CONNECTED message. 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 2749 NDMP_NOTIFY_CONNECTED: received ndmp_notify_connected. Version:[4], Reason:[0] Text:[Connected] 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 3137 NDMP_CONNECT_OPEN: protocol_version[4] 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 3152 NDMP_CONNECT_OPEN: successful 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 2804 NDMP_NOTIFY_CONNECTED: successful. Version is [4] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 873 NDMP_CONFIG_GET_SERVER_INFO: 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 905 NDMP_CONFIG_GET_SERVER_INFO: successful. Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] AuthType[2] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 787 NDMP_CONNECT_CLIENT_AUTH: login[ndmp] mode[2=NDMP_AUTH_MD5] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 807 NDMP_CONNECT_CLIENT_AUTH: successful 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 827 NDMP_CONFIG_GET_HOST_INFO: 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 849 NDMP_CONFIG_GET_HOST_INFO: successful. Host[pris2.hrt.hr] OsType[Linux] Version[2.6.32-504.12.2.el6.x86_64#1 SMP Wed Mar 11 12:19:26 PDT 2015] HostId[17475407] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 873 NDMP_CONFIG_GET_SERVER_INFO: 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 905 NDMP_CONFIG_GET_SERVER_INFO: successful. Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] AuthType[2] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 1322 NDMP_CONFIG_GET_EXT_LIST: 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 1372 NDMP_CONFIG_GET_EXT_LIST: successful 13908 d61ef700 09/16 13:28:02 2388 Data server connect complete. 13908 d61ef700 09/16 13:28:02 2388 LOGIN TO MOVER 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 3054 CONNECT: opening socket connection to host [spiderman.hrt.hr] port [64886] family [IPv4] 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 3088 CONNECT successful: Now waiting for NOTIFY_CONNECTED message. 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 2749 NDMP_NOTIFY_CONNECTED: received ndmp_notify_connected. Version:[4], Reason:[0] Text:[Connected] 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 3137 NDMP_CONNECT_OPEN: protocol_version[4] 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 3152 NDMP_CONNECT_OPEN: successful 13908 d61ef700 09/16 13:28:02 2388 ndmp.cpp 2804 NDMP_NOTIFY_CONNECTED: successful. Version is [4] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 873 NDMP_CONFIG_GET_SERVER_INFO: 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 905 NDMP_CONFIG_GET_SERVER_INFO: successful. Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] AuthType[2] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 787 NDMP_CONNECT_CLIENT_AUTH: login[ndmp] mode[2=NDMP_AUTH_MD5] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 807 NDMP_CONNECT_CLIENT_AUTH: successful 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 827 NDMP_CONFIG_GET_HOST_INFO: 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 849 NDMP_CONFIG_GET_HOST_INFO: successful. Host[spiderman.hrt.hr] OsType[Windows Server x64] Version[6.2Build 9200: ] HostId[A01503A] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 873 NDMP_CONFIG_GET_SERVER_INFO: 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 905 NDMP_CONFIG_GET_SERVER_INFO: successful. Vendor[CommVault Systems] Product[Galaxy] Revision[10.0.0(BUILD116)] AuthType[2] 13908 d61ef700 09/16 13:28:02 2388 New NRS:[true] Version:[10.0.0(BUILD116)] 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 1322 NDMP_CONFIG_GET_EXT_LIST: 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 1372 NDMP_CONFIG_GET_EXT_LIST: successful 13908 d61ef700 09/16 13:28:02 2388 Data mover connect complete. 13908 d61ef700 09/16 13:28:02 2388 Set NDMP Variables() - Back-up NDMP variable backup type set to [dump]. 13908 d61ef700 09/16 13:28:02 2388 Set NDMP Variables() - Back-up record size set to [65536]. 13908 d61ef700 09/16 13:28:02 2388 NDMP Variable Setup() - backup type is dump 13908 d61ef700 09/16 13:28:02 2388 Set NDMP Variables() - NDMP server type is 5 13908 d61ef700 09/16 13:28:02 2388 Opening tape for archive [4236]... 13908 d61ef700 09/16 13:28:02 2388 Construct Open Device Name() - got subclientID 6 and clientID 3 13908 d61ef700 09/16 13:28:02 2388 Construct Open Device Name() - constructed virtual tape name is R:0:2388:4236:106:0:1:0:2:3:6:6:13:4436701240199:0:0 13908 d61ef700 09/16 13:28:02 2388 ndmp_v4.cpp 1686 NDMP_TAPE_OPEN [spiderman.hrt.hr]: Device[R:0:2388:4236:106:0:1:0:2:3:6:6:13:4436701240199:0:0] Mode[0] 13908 d61ef700 09/16 13:28:09 2388 Log Message() - received NDMP_LOG_MESSAGE [spiderman.hrt.hr][CVNRS: Tape opened. AfileId=4236 CopyId=0 Stream=1] 13908 d61ef700 09/16 13:28:09 2388 ndmp.cpp 2225 Message not replied to yet. 13908 d61ef700 09/16 13:28:11 2388 ndmp_v4.cpp 1706 NDMP_TAPE_OPEN: successful 13908 d61ef700 09/16 13:28:11 2388 Restore Request() - MAX Restore List Length set to [1048576]. 13908 d61ef700 09/16 13:28:11 2388 ndmp_v4.cpp 2829 NDMP_MOVER_SET_WINDOW [spiderman.hrt.hr]: Offset[0] Length[1557968040960] 13908 d61ef700 09/16 13:28:11 2388 ndmp_v4.cpp 2846 NDMP_MOVER_SET_WINDOW: successful 13908 d61ef700 09/16 13:28:11 2388 ndmp_v4.cpp 2712 NDMP_MOVER_LISTEN [spiderman.hrt.hr]: mode[1] addr_type[1] 13908 d61ef700 09/16 13:28:12 2388 ndmp_v4.cpp 2735 NDMP_MOVER_LISTEN: successful 13908 d61ef700 09/16 13:28:12 2388 ndmp_v4.cpp 2742 --- address[0xa018063] port[64909] 13908 d61ef700 09/16 13:28:12 2388 ndmp_v4.cpp 2143 NDMP_DATA_CONNECT(tcp): 13908 d61ef700 09/16 13:28:12 2388 ndmp_v4.cpp 2147 --- address[0xa018063] port[64909] 13908 d61ef700 09/16 13:28:12 2388 ndmp_v4.cpp 2192 NDMP_DATA_CONNECT: successful 13908 d61ef700 09/16 13:28:12 2388 re-initialized tape server for next block of files. 13908 d61ef700 09/16 13:28:12 2388 CVArchive::ConnectSessionToArchiveManager() - Got CommServe name [spiderman.hrt.hr] from MediaAgent Platform Info 13908 d61ef700 09/16 13:28:12 2388 CVArchive::ConnectSessionToArchiveManager() - Attaching to CommServer [spiderman.hrt.hr] from Platform Type 2 13908 d61ef700 09/16 13:28:13 2388 CVArchive::ConnectSessionToArchiveManager() - Attached to CommServe 13908 d61ef700 09/16 13:28:13 2388 Successfully translated archFileId 4236 (commCellId 2) to client Id 3 13908 d61ef700 09/16 13:28:14 2388 Back-up Vendor() - Source Client ID = 3, back-up vendor = 1 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2385 NDMP_DATA_START_RECOVER_CV: RestoreType[dump] BackupVendor[NetApp] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [ACL_START]=[1557968033792] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [BASE_DATE]=[14327177354] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [CV_FIRST_OFFSET]=[365568] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [DEBUG]=[N] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [DIRECT]=[Y] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [DUMP_DATE]=[18622231081] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [ENHANCED_DAR_ENABLED]=[T] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [FILESYSTEM]=[/svm01/vol_orabckp] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [HIST]=[N] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [NDMP_VERSION]=[4] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [NO_ACLS]=[N] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [PATHNAME_SEPARATOR]=[/] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [RECURSIVE]=[N] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [TYPE]=[dump] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [UPDATE]=[Y] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2395 ENV [VERBOSE]=[N] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2416 FILE Offset[1422527511552] Inode[20265] Mtime[1442342090] Size[5273444] [expdp/pris/expdp_export_cumulative.log] to [/tmp/expdp_export_cumulative.log] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2448 NDMP_DATA_START_RECOVER_CV: successful 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2975 NDMP_MOVER_READ [spiderman.hrt.hr]: Offset[0] Length[4194304] 13908 d61ef700 09/16 13:28:14 2388 ndmp_v4.cpp 2992 NDMP_MOVER_READ: successful 13908 d61ef700 09/16 13:29:22 2388 ndmp_v4.cpp 2975 NDMP_MOVER_READ [spiderman.hrt.hr]: Offset[1422527511552] Length[4194304] 13908 d61ef700 09/16 13:29:22 2388 ndmp_v4.cpp 2992 NDMP_MOVER_READ: successful 13908 d61ef700 09/16 13:30:14 2388 ndmp_v4.cpp 2079 NDMP_DATA_GET_STATE: Timeout:[7200] 13908 d61ef700 09/16 13:30:14 2388 ndmp_v4.cpp 2105 NDMP_DATA_GET_STATE: successful. Operation[2] State[0x1] HaltReason[0] BytesProcessed[0] EstBytesRemain[0] ReadOffset[1422527511552] ReadLength[4194304] 13908 d61ef700 09/16 13:30:35 2388 ndmp.cpp 2591 RECV ERROR [pris2.hrt.hr]: received error [2=No such file or directory] from socket select/recv call. Local error code [-4][RECV ERROR]. 13908 d61ef700 09/16 13:30:35 2388 ndmp.cpp 2062 Cannot decode message header NDMP_DEVICE_BUSY_ERR 13908 d61ef700 09/16 13:30:35 2388 NDMP message processing from the data server returned error.. 13908 d61ef700 09/16 13:30:35 2388 NDMP data restore processing was not successful. 13908 d61ef700 09/16 13:30:35 2388 ndmp_v4.cpp 2900 NDMP_MOVER_ABORT [spiderman.hrt.hr]: 13908 d61ef700 09/16 13:30:37 2388 Mover Halted Notification() - received NDMP_MOVER_HALTED reason [NDMP_MOVER_HALT_ABORTED] 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 2225 Message not replied to yet. 13908 d61ef700 09/16 13:30:37 2388 ndmp_v4.cpp 2914 NDMP_MOVER_ABORT: successful 13908 d61ef700 09/16 13:30:37 2388 ndmp_v4.cpp 2934 NDMP_MOVER_STOP [spiderman.hrt.hr]: 13908 d61ef700 09/16 13:30:37 2388 ndmp_v4.cpp 2948 NDMP_MOVER_STOP: successful 13908 d61ef700 09/16 13:30:37 2388 ndmp_v4.cpp 2470 NDMP_DATA_ABORT: 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 2591 RECV ERROR [pris2.hrt.hr]: received error [2=No such file or directory] from socket select/recv call. Local error code [-4][RECV ERROR]. 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 2591 RECV ERROR [pris2.hrt.hr]: received error [2=No such file or directory] from socket select/recv call. Local error code [-4][RECV ERROR]. 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 2591 RECV ERROR [pris2.hrt.hr]: received error [2=No such file or directory] from socket select/recv call. Local error code [-4][RECV ERROR]. 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 2062 Cannot decode message header NDMP_DEVICE_BUSY_ERR 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 1709 process_messages() returned error. Dequeueing my message without receiving response. 13908 d61ef700 09/16 13:30:37 2388 ndmp_v4.cpp 2473 NDMP_DATA_ABORT: failed send 13908 d61ef700 09/16 13:30:37 2388 ndmp_v4.cpp 2551 NDMP_DATA_STOP: 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 2640 SEND ERROR[pris2.hrt.hr]: received error [32]=[Broken pipe] from socket send() call. 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 1154 NDMP_CONNECTION_CLOSED 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 1709 process_messages() returned error. Dequeueing my message without receiving response. 13908 d61ef700 09/16 13:30:37 2388 ndmp_v4.cpp 2554 NDMP_DATA_STOP: failed send 13908 d61ef700 09/16 13:30:37 2388 ndmp_v4.cpp 1735 NDMP_TAPE_CLOSE [spiderman.hrt.hr]: [R:0:2388:4236:106:0:1:0:2:3:6:6:13:4436701240199:0:0]. Timeout:[1200] 13908 d61ef700 09/16 13:30:37 2388 ndmp_v4.cpp 1752 NDMP_TAPE_CLOSE: successful 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 1038 NDMP_CONNECT_CLOSE [spiderman.hrt.hr] 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 1038 NDMP_CONNECT_CLOSE [pris2.hrt.hr] 13908 d61ef700 09/16 13:30:37 2388 ndmp.cpp 2640 SEND ERROR[pris2.hrt.hr]: received error [9]=[Bad file descriptor] from socket send() call. 13908 d61ef700 09/16 13:30:37 2388 Execute Restore() - Failed to construct and execute the NDMP restore message. 13908 d61ef700 09/16 13:30:37 2388 NasRestore::OnMsgCloseArchive() - NdmpRestore::restoreDump failed for archive file id [4236] 13908 d61ef700 09/16 13:30:37 2388 NasRestore::OnMsgCloseArchive() - Paths restored successfully:[0], Paths Failed[1]. 13908 d616e700 09/16 13:30:59 2388 NasRestore::progressReport() - Exiting progress reporting thread... 13908 d61ef700 09/16 13:30:59 2388 FClRestore::processRestoreMsgs() - Processing FSR_MSG_WAIT_ARCHIVE_CLOSED 13908 d61ef700 09/16 13:30:59 2388 FClRestore::processRestoreMsgs() - Processing FSR_MSG_RESTORE_END 13908 d61ef700 09/16 13:30:59 2388 FclRestore::OnMsgRestoreEnd() - Restore on client [pris2] subclient [Orabckp] completed... 13908 d61ef700 09/16 13:30:59 2388 FclRestore::OnMsgRestoreEnd() - File Statistics: Total [1], Succeeded [0], Skipped [0] Failed [1] 13908 d61ef700 09/16 13:30:59 2388 FclRestore::OnMsgRestoreEnd() - Byte Statistics: Total [0], Succeeded [0], Failed [0] 13908 d61ef700 09/16 13:30:59 2388 FclRestore::OnMsgRestoreEnd() - sending FSR_MSG_RESTORE_END to FSRestoreHead 13908 d61ef700 09/16 13:30:59 2388 FclRestore::sendMsgToRestoreHead() - Could not send FSR_MSG_RESTORE_END to Restore Head - not connected! 13908 d61ef700 09/16 13:30:59 2388 FClRestore::processRestoreMsgs() - Exiting the processRestoreMsgs thread... 13908 dc9d5720 09/16 13:31:00 2388 FclRestore::receiveRestoreMsgs() - Waiting for children threads to complete... 13908 dc9d5720 09/16 13:31:00 2388 FclRestore::receiveRestoreMsgs() - Finishing restore 13908 dc9d5720 09/16 13:31:00 2388 FclRestore::receiveRestoreMsgs() - Exiting the receiveRestoreMsgs thread... 13908 dc9d5720 09/16 13:31:00 2388 ::main() - Finished receiving messages. Shutting down. 13908 dc9d5720 09/16 13:31:00 2388 NasRestore::finalize() - Files restored : [0], Files that failed or had errors during restore : [1] 13908 dc9d5720 09/16 13:31:00 2388 NasRestore::finalize() - See list of failed files in restore.out in iDataAgent/JobResults/CV_JobResults/2388 directory on the MA. 13908 dc9d5720 09/16 13:31:00 2388 NasMedia::cleanup() - setting the current tape position to 0 - will reset the tape position. 13908 dc9d5720 09/16 13:31:00 2388 FclRestore::finalize() - DiskWrite: Bytes = 0, Time = 0.0 Sec(s), Average Speed = 0.0 G/h 13908 dc9d5720 09/16 13:31:00 2388 FclRestore::finalize() - readPipeline: Bytes = 0, Time = 0.0 Sec(s), Average Speed = 0.0 G/h 13908 dc9d5720 09/16 13:31:00 2388 FclRestore::finalize() - Closing pipeline... 13908 dc9d5720 09/16 13:31:00 2388 Using default close pipeline args for a backup, backupState is not being set 13908 dc9d5720 09/16 13:31:00 2388 FclRestore::finalize() - Restore successful - sending FSR_MSG_RESTORE_END 13908 dc9d5720 09/16 13:31:01 2388 ::main() - Exiting...