β06-03-2018 05:24 PM
[8572] 2018-06-03T05:52:49.517 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:52:49.517 [loops] - BackupBSDProcessor(): Received MSG_RWF_METADATA message from raws.
[8572] 2018-06-03T05:52:49.517 - Status 'E_SSP_DISABLED (0xE000A200)' for '((BESTATUS)0xE000A200L)' in 'BackupJob::SetRwfMetadata:11255'
[8572] 2018-06-03T05:52:49.517 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0xf204
[8572] 2018-06-03T05:52:49.517 [tpfmt] - TF_NDMPGetResult(): MediaServer thread done, returning TFLE 0x00000000
[8572] 2018-06-03T05:52:49.518 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:52:49.518 [loops] - stream data[DEFAULT] halted: SUCCESSFUL
[8572] 2018-06-03T05:52:49.518 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0xf36e
[8572] 2018-06-03T05:52:49.518 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:52:49.518 [loops] - data halted: SUCCESSFUL
[8572] 2018-06-03T05:52:49.518 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0x501
[8572] 2018-06-03T05:52:49.518 [tpfmt] - TF_FreeTapeBuffers: from 0 to 0 buffers
[8572] 2018-06-03T05:52:49.668 [ndmp\ndmpcomm] - ndmpSendRequest: message:0x400
[8572] 2018-06-03T05:52:49.668 [ndmp\ndmpcomm] - sent seq#: 89 msg: 0x400
[8572] 2018-06-03T05:52:49.668 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:52:49.668 [ndmp\ndmpcomm] - got expected reply msg: 0x400
[8572] 2018-06-03T05:52:49.668 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0x400
[8572] 2018-06-03T05:52:49.669 [loops] - BaseBSDProcessor::PollDataServer: Shutting down.
[8572] 2018-06-03T05:52:49.669 - Status 'E_SSP_DISABLED (0xE000A200)' for '((BESTATUS)0xE000A200L)' in 'BackupBSDProcessor::GenerateSspRwfFile:5442'
[8572] 2018-06-03T05:52:49.669 [loops] - BackupBSDProcessor::GenerateDRFile() - Enter
[8572] 2018-06-03T05:52:49.669 [loops] - BackupBSDProcessor::GenerateDRFile() - Info: Not a Simplified System Protection Job. Ignoring .DR file creation.
[8572] 2018-06-03T05:52:49.669 [ndmp\ndmpcomm] - ndmpSendRequest: message:0x407
[8572] 2018-06-03T05:52:49.669 [ndmp\ndmpcomm] - sent seq#: 90 msg: 0x407
[8572] 2018-06-03T05:52:49.669 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:52:49.669 [ndmp\ndmpcomm] - got expected reply msg: 0x407
[8572] 2018-06-03T05:52:49.669 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0x407
[8572] 2018-06-03T05:52:49.669 [tpfmt] - TF_GetAndResetBytesWrittenToCurrentMedia returning 5231738880 bytes written to media 000027L5, {9197cb9e-f137-4a75-b535-22dae87e9004}.
[8572] 2018-06-03T05:52:49.669 [server] - BackupMessageHandler - update_cat_fragment_storage_usage - Passing 5231738880 bytes for media id {9197cb9e-f137-4a75-b535-22dae87e9004}.
[8572] 2018-06-03T05:52:49.670 - Status 'E_SSP_DISABLED (0xE000A200)' for '((BESTATUS)0xE000A200L)' in 'BackupJob::GetRwfMetadata:11286'
[8572] 2018-06-03T05:52:49.670 - Restore Work Flow (RWF) Metadata. Size:94. XML:'<?xml version="1.0" encoding="utf-16"?>
<RestoreMetadata RestoreType="1" RestoreSubType="1"/>
'. in 'BackupJob::GetRwfMetadata:11291'
[8572] 2018-06-03T05:52:50.024 - Resetting Restore Work Flow (RWF) Metadata. in 'BackupJob::ResetRwfMetadata:11146'
[8572] 2018-06-03T05:52:51.480 [tpfmt] - WriteEndSet( 1 ) returning 0x00000000
[8572] 2018-06-03T05:52:53.800 [tpfmt] - WriteEndSet( 1 ) returning 0x00000000
[8572] 2018-06-03T05:52:53.800 [tpfmt] - OTC_Close: Closing otc_sm_fptr 0x748a2680.
[8572] 2018-06-03T05:52:53.800 [tpfmt] - WriteEndSet( 0 ) returning 0x00000000
[8572] 2018-06-03T05:52:53.827 [tpfmt] - HARDWARE COMPRESSION ===> Setting compression off.
[8572] 2018-06-03T05:52:53.843 [tpfmt] - TF_FreeTapeBuffers: from 0 to 0 buffers
[8572] 2018-06-03T05:52:54.028 [server] - Source Path set in jobHistoryDetail \\hkftpwvs01\D:
[8572] 2018-06-03T05:52:54.028 [server] - Family Guid set in jobHistoryDetail 8603FBC9-727A-4C0A-8948-173D1EAAB4E8
[8572] 2018-06-03T05:52:54.028 [server] - (3243) EndOperation(2, 0x0)
[8572] 2018-06-03T05:52:54.028 [server] - Job::DetermineFinalStatusForResource( fs-2, ec-0x0 ) - 19
[8572] 2018-06-03T05:52:54.147 [loops] - Enter NDMPSnapHostBackupEngine::TrackSnappedBSD
[8572] 2018-06-03T05:52:54.147 [ndmp\ndmpcomm] - ndmpSendRequest: message:0xf335
[8572] 2018-06-03T05:52:54.147 [ndmp\ndmpcomm] - sent seq#: 91 msg: 0xf335
[8572] 2018-06-03T05:52:54.147 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:03.621 [ndmp\ndmpcomm] - got expected reply msg: 0xf335
[8572] 2018-06-03T05:53:03.622 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0xf335
[8572] 2018-06-03T05:53:03.622 [ndmp\ndmpcomm] - ndmpSendRequest: message:0xf301
[8572] 2018-06-03T05:53:03.622 [ndmp\ndmpcomm] - sent seq#: 92 msg: 0xf301
[8572] 2018-06-03T05:53:03.622 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:03.701 [ndmp\ndmpcomm] - got expected reply msg: 0xf301
[8572] 2018-06-03T05:53:03.701 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0xf301
[8572] 2018-06-03T05:53:03.701 [loops] - Exit NDMPSnapHostBackupEngine::TrackSnappedBSD
[8572] 2018-06-03T05:53:03.701 [loops] - Enter NDMPSnapHostBackupEngine::AdvanceToNextBSD
[8572] 2018-06-03T05:53:03.701 [loops] - Exit NDMPSnapHostBackupEngine::AdvanceToNextBSD
[8572] 2018-06-03T05:53:03.701 [loops] - NDMPSnapHostBackupEngine::ProcessBSDList Top of the loop
[8572] 2018-06-03T05:53:03.701 [loops] - snapResult = 0x0, result = 0x0
[8572] 2018-06-03T05:53:03.701 [loops] - Enter NDMPSnapHostBackupEngine::CreateBSDProcessor
[8572] 2018-06-03T05:53:03.701 [loops] - PDI processor not needed, performing traditional backup
[8572] 2018-06-03T05:53:03.701 [loops] - Enter NDMPSnapHostBackupEngine::SnapSingleVolume
[8572] 2018-06-03T05:53:03.701 [loops] - IsLocalAgent:beclass::BEConvertServerNamePlus returned error: 87
[8572] 2018-06-03T05:53:03.702 [loops] - NDMPSnapshotWrapper::SnapshotPrepare2() Retry settings, MaxRetries=1
[8572] 2018-06-03T05:53:03.702 [besc] - ndmpcSnapshotPrepare2: Warning. No devices to snap. Returning with NDMP_SNAPSHOT_NO_DEVICES2SNAP
[8572] 2018-06-03T05:53:03.702 [loops] - NDMPSnapshotWrapper::SnapshotPrepare2() reply_msg == NULL which could mean connection error, skipping retry logic
[8572] 2018-06-03T05:53:03.702 [loops] - NDMPSnapshotWrapper::SnapshotPrepare2() Total Snapshot Attempts=0
[8572] 2018-06-03T05:53:03.702 [loops] - Exit NDMPSnapHostBackupEngine::SnapSingleVolume
[8572] 2018-06-03T05:53:03.702 [loops] - DeviceIsNT4Server: agent info: [Major Version=6 Minor Version=1 Build Number=7601 ServicePack Major=1 ServicePack Minor=0 SuiteMask=272 ProductType=3 ProcessorType=AMD64].
[8572] 2018-06-03T05:53:03.702 [loops] - DeviceIsIA64Server: agent info: [Major Version=6 Minor Version=1 Build Number=7601 ServicePack Major=1 ServicePack Minor=0 SuiteMask=272 ProductType=3 ProcessorType=AMD64].
[8572] 2018-06-03T05:53:03.702 [loops] - DeviceIsW2kServer: agent info: [Major Version=6 Minor Version=1 Build Number=7601 ServicePack Major=1 ServicePack Minor=0 SuiteMask=272 ProductType=3 ProcessorType=AMD64].
[8572] 2018-06-03T05:53:03.725 [tpfmt] - HARDWARE COMPRESSION ===> Compression is configurable.
[8572] 2018-06-03T05:53:03.725 [tpfmt] - HARDWARE ENCRYPTION ===> Encryption is NOT supported.
[8572] 2018-06-03T05:53:03.726 [tpfmt] - GET_DRV_INF: containerGUID = {00000000-0000-0000-0000-000000000000}
[8572] 2018-06-03T05:53:03.726 [tpfmt] - GET_DRV_INF: bsize = 65536
[8572] 2018-06-03T05:53:03.726 [tpfmt] - GET_DRV_INF: preferredBlockSize = 65536
[8572] 2018-06-03T05:53:03.726 [tpfmt] - SetupFormatEnv( fmt=0 )
[8572] 2018-06-03T05:53:03.726 [loops] - ******** InitCommonFieldsInVCB() - 0x50da7245-0x79b8-0x44c7
[8572] 2018-06-03T05:53:03.726 [tpfmt] - OTC_OpenSM: Opened set map file for appending and _access != -1. otc_sm_fptr = 0x748a2680.
[8572] 2018-06-03T05:53:03.726 [tpfmt] - HARDWARE COMPRESSION ===> Setting compression on.
[8572] 2018-06-03T05:53:03.738 [ndmp\ndmpclient] - (6477)ndmpcGetUsernamePassword: resourceFlags - 0x1
[8572] 2018-06-03T05:53:03.738 [loops] - Media Server to initiate connection for data transfer
[8572] 2018-06-03T05:53:03.738 [ndmp\ndmpcomm] - ndmpSendRequest: message:0x409
[8572] 2018-06-03T05:53:03.739 [ndmp\ndmpcomm] - sent seq#: 93 msg: 0x409
[8572] 2018-06-03T05:53:03.739 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:03.739 [ndmp\ndmpcomm] - got expected reply msg: 0x409
[8572] 2018-06-03T05:53:03.739 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0x409
[8572] 2018-06-03T05:53:03.740 [ndmp\ndmpcomm] - TF_InitMediaServerReverseConnection : Data Connection information: A connection was established between end-points 10.10.209.205:60214 and 10.10.234.48:58570.
[8572] 2018-06-03T05:53:03.740 [ndmp\ndmpcomm] - ndmpSendRequest: message:0x401
[8572] 2018-06-03T05:53:03.741 [ndmp\ndmpcomm] - sent seq#: 94 msg: 0x401
[8572] 2018-06-03T05:53:03.741 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:05.018 [ndmp\ndmpcomm] - got expected reply msg: 0x401
[8572] 2018-06-03T05:53:05.018 [ndmp\ndmpclient] -
dataStartBackup: ndmpSendRequest returned: 0x0, 0
[8572] 2018-06-03T05:53:05.018 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0x401
[8572] 2018-06-03T05:53:05.019 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:05.020 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0xf397
[8572] 2018-06-03T05:53:08.721 [ndmp\ndmpcomm] - ndmpSendRequest: message:0x400
[8572] 2018-06-03T05:53:08.721 [ndmp\ndmpcomm] - sent seq#: 95 msg: 0x400
[8572] 2018-06-03T05:53:08.721 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:33.859 [ndmp\ndmpcomm] - got expected reply msg: 0x400
[8572] 2018-06-03T05:53:33.859 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0x400
[8572] 2018-06-03T05:53:33.860 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:33.860 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0xf337
[8572] 2018-06-03T05:53:33.860 [ndmp\ndmpcomm] - ndmpSendRequest: message:0x400
[8572] 2018-06-03T05:53:33.860 [ndmp\ndmpcomm] - sent seq#: 96 msg: 0x400
[8572] 2018-06-03T05:53:33.860 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:33.861 [server] - SetResourceBackupMethod. NormalizedBackupMethod: 1. fsSpecificBackupMethod: 1.
[8572] 2018-06-03T05:53:33.861 [server] - Not SSP Job: Un set A2_VCB_RESOURCE_IS_CRITICAL_BIT
[8572] 2018-06-03T05:53:33.861 [server] - bIsFullBackup - 1 (bu method - 1)
[8572] 2018-06-03T05:53:34.128 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0xf204
[8572] 2018-06-03T05:53:34.128 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:34.128 [ndmp\ndmpcomm] - got expected reply msg: 0x400
[8572] 2018-06-03T05:53:34.128 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0x400
[8572] 2018-06-03T05:53:34.129 [tpfmt] - TF_NDMPStartWrite(): Started MediaServerWriteThread 4288
[8572] 2018-06-03T05:53:34.129 [ndmp\ndmpcomm] - ndmp_recv_msg
[8572] 2018-06-03T05:53:34.129 [ndmp\ndmpcomm] - ndmpFreeMessage: message:0xf204
Solved! Go to Solution.
β06-03-2018 10:32 PM
Can you try to turn on software encryption for this job. It has been seen that sometime the connections are broken with certain type of data flowing in the network. In backup job , edit the job settings and turn on software encryption. Save and run the backup. Let us know how it goes.
β06-03-2018 05:40 PM
Please help me...
β06-03-2018 09:17 PM - edited β06-03-2018 09:19 PM
β06-03-2018 10:17 PM
Thanks your reply.
Other server can backup success, only this ftp server fail. I think isn't the problem of network connection, because I long ping the backup server, nothing happen to interrupt. FTP server backup only have system files and data, didn't have database.
β06-03-2018 10:32 PM
Can you try to turn on software encryption for this job. It has been seen that sometime the connections are broken with certain type of data flowing in the network. In backup job , edit the job settings and turn on software encryption. Save and run the backup. Let us know how it goes.
β06-03-2018 11:25 PM
Thanks for your reply.
I will try it and send the result after one hour. Thank you.
β06-04-2018 12:32 AM
I test the solution, I can backup success now ,but I not sure it has been fixed. Maybe I should wait tomorrow schedule job whether it can be finished. Tomorrow I will update the result, Thanks a lot.