Hi,
File system backup jobs for a MediaAgent fails
Error Code: [19:1109]
Description: Please check the log files for this job for more details.
My troubleshooting steps that didn’t work:
- catalog migration to different path (once from the properties of MA, and once using change index server config workflow)
- try using optimized scan
- upgrade the commcell to the latest maintenance release 11.24.48
The Archive index logs:
16120 4530 05/27 20:06:24 680118 Begin Archival of Remote Loose Files (if available) and Action Logs, Argv [-j 680118 -a 2:457 -t 1 -jt 680118:11:12:0:32808 -ab 0 -parent 1 -c 363 -maxcolnum 3 -numcol 2 -numfolder 58 -incimage -incimage -idx2 -TJ -idx2 -new_scan -slt -hloff -r 1653668189 -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -c 0 -maxcolnum 3 -numcol 2 -IgnoreEarlyStubBackup -seb -quotamgmt -wfi ]
16120 4530 05/27 20:06:24 ###### CBackupBase::ParseArgs(242) - +++
16120 4530 05/27 20:06:24 ###### CBackupBase::ParseArgs(248) - DedupeForArchiveIndex=0
16120 4530 05/27 20:06:24 ###### CBackupBase::ParseArgs(252) - UseIncrementalImageMode=1
16120 4530 05/27 20:06:24 ###### CBackupBase::ParseArgs(256) - EndUserErase=0
16120 4530 05/27 20:06:24 ###### CBackupBase::ParseArgs(260) - earlyStubBackup=0
16120 4530 05/27 20:06:24 ###### CBackupBase::ParseArgs(267) - Adhoc backup=[False]
16120 4530 05/27 20:06:24 ###### CBackupBase::ParseArgs(270) - IgnoreEarlyStubBackup=0
16120 4530 05/27 20:06:24 ###### ::parse_plfs_bkargs() - Received backupRefTime 1653668189
16120 4530 05/27 20:06:24 ###### ::parse_plfs_bkargs() - Received quotamgmt
16120 4530 05/27 20:06:24 ###### ::parse_plfs_bkargs() - args parsed: backupType=1, commCellId=2, appId=457, jobId=680118, backupReftime=1653668189
16120 4530 05/27 20:06:24 ###### CBackupBase::ParseArgs(282) - earlyStubBackup=0 after parsing command line arguments.
16120 4530 05/27 20:06:24 ###### CBackupBase::ParseArgs(242) - --- 0:00.016051
16120 4530 05/27 20:06:24 ###### I2::Archiver::DoArchive() - [680118] got commserver name [sr-jab-commsrv] from CommVault Registry
16120 4530 05/27 20:06:24 ###### I2::Archiver::DoArchive() - [680118] going to initialize with jobmgr
16120 4530 05/27 20:06:24 680118 JM Client CVBkpJobClient::init(): Initializing job object with token [680118:11:12:0:32808].
16120 4530 05/27 20:06:24 ###### I2::Archiver::DoArchive() - [680118] going to initialize with jobmgr control
16120 4530 05/27 20:06:24 ###### Init() - Initializing job control [token=680118:11:12:0:32808,cn=SR-JAB-MACBIO] in single threaded mode, serverName [sr-jab-commsrv], ControlFlag [1], Job Id [680118]
16120 4530 05/27 20:06:24 680118 Remote File Cache Loose File Back up Enabled: [false]
16120 4530 05/27 20:06:24 ###### CBackupBase::Initialize2(1999) - +++
16120 4530 05/27 20:06:24 ###### CBackupBase::Initialize2(2093) - Flag failAfter=0 (0=don't fail!)
16120 4530 05/27 20:06:24 ###### CBackupBase::Initialize2(2134) - Getting new CVArchive
16120 4530 05/27 20:06:24 ###### CVArchive::Construct() - Constructing CVArchive Object. This=000001B2BE60E010
16120 4530 05/27 20:06:24 680118 CVArchive::Construct() - Enable CVArchive Big Buffer [true] [perf-update interval 600 seconds]
16120 4530 05/27 20:06:24 680118 Enable Dedup for Index data [false]
16120 4530 05/27 20:06:24 680118 CBackupBase::Initialize2(2172) - Going to setup pipeline through CVArchive
16120 4530 05/27 20:06:24 680118 CVArchive::LookupPipelineInfo() - Incoming SIDBStoreId: 37
16120 4530 05/27 20:06:24 680118 CVArchive::getPipelineMode() - Using default pipeline mode [SDT] for [Bkp] pipe
16120 4530 05/27 20:06:24 680118 CVArchive::LookupPipelineInfo() - New block alignment enabled for this client
16120 4530 05/27 20:06:24 680118 CVSingleInstTarget[1] singleInstLvl[2] sigWhere[3] sigScheme[4] singleInstMinObjSizeKB[50] compressWhere[0] encType[0] rsaKeys[0] Flag[303] rsrcConsumerId[4358520] CloudLaptopClnt[0]
16120 4530 05/27 20:06:24 680118 Configuring Compression for DataType 2
16120 4530 05/27 20:06:24 680118 CVArchive::ConfigureBlockAlignment() - Deduplication is not enabled. Disabling block alignment.
16120 4530 05/27 20:06:24 680118 Encryption is disabled for DataType 2
16120 4530 05/27 20:06:24 680118 Current pipeline module configuration: compression [0][CV_COMPRESS_SOURCE], signature [0][CV_SIGNATURE_NOWHERE] and encryption [0][CV_ENCRYPT_NOWHERE]
16120 4530 05/27 20:06:24 680118 N/w agents configured before/after firewall check = [2/2]. Firewalled = 0
16120 4530 05/27 20:06:24 680118 CVArchive::StartPipeline() - StartPipeline SI configuration -[srcClientName - SR-JAB-MACBIO] Block Level [false], Block Size [128], File Level [false], Min Signature Size [0]
16120 4530 05/27 20:06:24 680118 CCVAPipelayer::StartPipeline() - Forcing single tag buffers to true
16120 4530 05/27 20:06:24 680118 Ignoring call to enable/disable multi-tag buffers. parameter [false].
16120 4530 05/27 20:06:24 680118 CPipelayer::InitiatePipeline Initiating SDT connection [000001B2C13EA010] from SR-JAB-MACBIO.sd.zain.com:8400(SR-JAB-MACBIO) to SR-JAB-MACBIO.sd.zain.com:8400(SR-JAB-MACBIO)
16120 4530 05/27 20:06:24 680118 CPipelayer::InitiatePipeline compressionType [CV_COMPRESS], compressWhere [CV_COMPRESS_SOURCE]
16120 4530 05/27 20:06:24 680118 CPipelayer::InitiatePipeline encryptionType [CV_NO_ENCRYPT], encryptionWhere [CV_ENCRYPT_NOWHERE]
16120 4530 05/27 20:06:24 680118 CPipelayer::InitiatePipeline signatureType [CV_NO_SIGNATURE], signatureWhere [CV_SIGNATURE_NOWHERE]
16120 4530 05/27 20:06:24 680118 CPipelayer::InitiatePipeline Lan-Free - 1
16120 4530 05/27 20:06:24 680118 CPipelayer::InitiatePipeline Num Buffers [90], Buffer size [65536]
16120 4530 05/27 20:06:24 680118 CvFwClient::connectDirectly(): Connected to SR-JAB-MACBIO.sd.zain.com:8400/8400 using direct system connect
16120 4530 05/27 20:06:24 680118 CPipelayer::connectToDest Connected pipeline to (SR-JAB-MACBIO)SR-JAB-MACBIO.sd.zain.com:8400/8400, ConType 1 (Direct), Proxy []
16120 4530 05/27 20:06:24 680118 CPipelayer::InitiatePipeline SDT is using socket 4188 for connection 1/2
16120 4530 05/27 20:06:24 680118 CPipelayer::InitiatePipeline SDT Pipeline ID is [SDTPipe_SR-JAB-MACBIO_SR-JAB-MACBIO_680118_1653674784_16120_17712_000001B2C13EA010]
16120 4530 05/27 20:06:24 680118 SdtNetLink() - WAN Padding is OFF
16120 4530 05/27 20:06:24 ###### Single Threaded Head [false]
16120 4530 05/27 20:06:24 680118 SdtBase::cfgComp() - gzip comp level set to [-1]
16120 4530 05/27 20:06:24 680118 SdtNetLink::setSocket() - Switching socket 4188 to non-blocking mode.
16120 4530 05/27 20:06:24 680118 SdtNetLink::authenticate() - Connection authenticated successfully
16120 4530 05/27 20:06:24 680118 MODULE_SEQUENCE Adding compression at index [1] RCId [4358520]
16120 4530 05/27 20:06:24 680118 SdtBase::cfgProcs() - Total Bufs=90, allocators=1
16120 4530 05/27 20:06:24 680118 SdtBase::cfgProcs() - Free Bufs [90]
16120 4530 05/27 20:06:24 680118 SdtBase::cfgProcs() - Free Bufs [0]
16120 4530 05/27 20:06:24 680118 SdtBase::cfgProcs() - Free Bufs [0]
16120 4530 05/27 20:06:24 680118 SdtBase::cfgProcs() - Free Bufs [0]
16120 4530 05/27 20:06:24 680118 Switching socket 4188 (1/2) to non-blking mode. RCId [4358520]
16120 4530 05/27 20:06:24 680118 CPipelayer::FattenSdt Fattening SDT pipe by 1 more connection(s).
16120 4530 05/27 20:06:24 680118 CvFwClient::connectDirectly(): Connected to SR-JAB-MACBIO.sd.zain.com:8400/8400 using direct system connect
16120 4530 05/27 20:06:24 680118 CPipelayer::connectToDest Connected pipeline to (SR-JAB-MACBIO)SR-JAB-MACBIO.sd.zain.com:8400/8400, ConType 1 (Direct), Proxy []
16120 4530 05/27 20:06:24 680118 CPipelayer::FattenSdt SDT is using socket 4512 for connection 2/2
16120 4530 05/27 20:06:24 680118 Switching socket 4512 (2/2) to non-blking mode. RCId [4358520]
16120 4530 05/27 20:06:24 680118 InitializePerfCounters() - Initializing Perf counters message[Pipeline-ID - 4358520] [Starttime - 1653674784] [Starttime UTC - 1653667584]
16120 4530 05/27 20:06:24 680118 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 158 to MediaAgent, Waiting for Response...
16120 4530 05/27 20:06:24 680118 [PIPELAYER ] Tail response = Get PL_SET_NETWORK_CRC_PROPS Message Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 158 EventError = 0
16120 4530 05/27 20:06:24 680118 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 136 to MediaAgent, Waiting for Response...
16120 4530 05/27 20:06:25 680118 [PIPELAYER ] Tail response = dsBackup initialization success Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 136 EventError = 0
16120 4530 05/27 20:06:25 680118 CCVAPipelayer::InitializeBackupPipeline() - Disabling Client-Side-Deduplication SignatureWhere:0
16120 4530 05/27 20:06:25 680118 CCVAPipelayer::InitializeBackupPipeline() - Sent Command PL_INIT_SIGNATURE to MediaAgent [Client name - SR-JAB-MACBIO] [SIDBStoreId - 37] [isClientSideDedupEnabled - No] [CacheDBSize - 0 MB] [Cache-buffer-size - 4096 KB][Compress-enabled - Yes] [latencyOptimizeEnabled - No]
16120 4530 05/27 20:06:25 680118 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 319 to MediaAgent, Waiting for Response...
16120 4530 05/27 20:06:25 680118 [PIPELAYER ] Tail response = signature initialization success Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 319 EventError = 0
16120 4530 05/27 20:06:25 680118 JM Client CVBkpJobClient::init(): Initializing job object with token [680118:11:12:0:32808].
16120 4530 05/27 20:06:25 680118 CBackupBase::Initialize2(2184) - Pipeline setup completed
16120 4530 05/27 20:06:25 680118 CBackupBase::Initialize2(2192) - Disabling CVArchive's file signature as this is not a turbo job or not a FS job
16120 4530 05/27 20:06:25 680118 Ignoring call to enable/disable multi-tag buffers. parameter [true].
16120 4530 05/27 20:06:25 680118 Multiple Tag Headers per Pipeline Buffer is Supported
16120 4530 05/27 20:06:25 680118 CBackupBase::CreateNewArchiveFile(2356) - Creating archive file with parameters: IsValid=0, AppId=457, AppTypeId=0, ArchiveFileName=IdxLogs_V1, BackupLevel=1, ArchiveFileFLags=0x0, DataType=2 inputCTime=0
16120 4530 05/27 20:06:25 680118 CVArchive::AllocateArchiveFileId() - Sending allocate afileId request with copy = 51 ReUseArchiveFile [no]***
16120 4530 05/27 20:06:25 680118 CCVAPipelayer::SetEncryptProps() - Archfile(1951420 )
16120 4530 05/27 20:06:25 680118 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 156 to MediaAgent, Waiting for Response...
16120 4530 05/27 20:06:25 680118 [PIPELAYER ] Tail response = Get PL_SET_ENC_PROPS Message Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 156 EventError = 0
16120 4530 05/27 20:06:25 680118 CVArchive::CreateArchiveFile() - Archive file name 1951420 afilenum = 1951420
16120 4530 05/27 20:06:25 680118 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 131 to MediaAgent, Waiting for Response...
16120 4530 05/27 20:06:25 680118 [PIPELAYER ] Tail response = Archive File creation succeeded Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 131 EventError = 0
16120 4530 05/27 20:06:25 680118 CBackupBase::CreateNewArchiveFile(2369) - New archive file created. FileNumber=1951420, GroupNumber=49, CreateTime=1653674635 (5/27/2022 6:03:55 PMZ)
16120 4530 05/27 20:06:25 680118 CBackupBase::Initialize2(1999) - --- 0:01.174920
16120 4530 05/27 20:06:25 680118 CFileBackup::Init(289) - +++
16120 4530 05/27 20:06:25 680118 CFileBackup::Init(289) - --- 0:00.001584
16120 4530 05/27 20:06:25 680118 CFileBackupFSW2K::Init() - The Windows Dedupe content will backed up as OPTIMIZED_FOR_RESTORE
16120 4530 05/27 20:06:25 680118 CFileBackupFSW2K::initialize(299) - +++
16120 4530 05/27 20:06:25 680118 CFileBackup::initialize(559) - +++
16120 4530 05/27 20:06:25 680118 CFileBackup::initialize(833) - ACL collection for client 0 is not enabled
16120 4530 05/27 20:06:25 680118 CFileBackup::initialize(834) - Catalog Additional file attribute for client 0 is not enabled
16120 4530 05/27 20:06:25 680118 CFileBackup::GetPerfCounterLoggingInterval(13902) - Using default performance counters logging interval [30 Minutes]
16120 4530 05/27 20:06:25 680118 CFileBackup::initialize(559) - --- 0:00.045843
16120 4530 05/27 20:06:25 680118 CFileBackupFSW2K::initialize(322) - Will Not Backup RSS Data
16120 4530 05/27 20:06:25 680118 CFileBackupFSW2K::initialize(299) - --- 0:00.083711
16120 4530 05/27 20:06:25 680118 Quota checks are disabled at Archive Index. To enable set registry under Indexing ENABLE_ARCHIVE_INDEX_QUOTA_CHECK 1
16120 4530 05/27 20:06:25 680118 Log Directory [T:\MACBIOindex\MACBIOindexLOGs\CvIdxLogs\2\A287EA7D-D5B3-4E6E-969B-C5559088AEC5\J680118] does not exist!, Setting Hard Indexing Failure
16120 4530 05/27 20:06:25 680118 Closing archive file
16120 4530 05/27 20:06:25 680118 CCVAPipelayer::CloseArchiveFile() - Closing archive file[afilenum=1951420] in BACKUP
16120 4530 05/27 20:06:25 680118 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 132 to MediaAgent, Waiting for Response...
16120 4530 05/27 20:06:26 680118 [PIPELAYER ] Tail response = Close archive file succeeded Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 132 EventError = 0
16120 4530 05/27 20:06:26 680118 Closing pipeline.
16120 4530 05/27 20:06:26 680118 Sending PL_LAST to tail.
16120 4530 05/27 20:06:26 680118 backupState(1=good) = 1, closePlArgs.backupState = 1
16120 4530 05/27 20:06:26 680118 CVArchive::ClosePipeline() - Resetting allocated stream
16120 4530 05/27 20:06:26 680118 CCVAPipelayer::ClosePipeline() - About to destroy Data Mover
16120 4530 05/27 20:06:26 680118 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 133 to MediaAgent, Waiting for Response...
16120 4530 05/27 20:06:27 680118 [PIPELAYER ] Tail response = DataMover destroyed Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 133 EventError = 0
16120 4530 05/27 20:06:27 680118 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 2 to MediaAgent, Waiting for Response...
16120 4530 05/27 20:06:27 680118 [PIPELAYER ] Tail response = Tail Generated STOP_PL and ready to Terminate Status = 0 dwCode = 0 MsgType = 4 MsgSubType = 2 EventError = 0
16120 4530 05/27 20:06:27 680118 CPipelayer::ShutdownPipeline() - stat- SDT [000001B2C13EA010] [duration - 3 seconds]
16120 4530 05/27 20:06:27 680118 CPipelayer::ShutdownPipeline() - SDT [000001B2C13EA010] Shutdown completed.
16120 4530 05/27 20:06:27 680118 SdtBase::relRef: Going to delete SdtBase as ref count is down to 0. RCId [4358520]
16120 4530 05/27 20:06:27 680118 SdtBase is being destroyed. RCId [4358520]
16120 4530 05/27 20:06:27 680118 Name [Head], Start Delay [2.41 s], Avg [300.92 ms], Procsng Time [170.50 us], Avg [21.31 us], Bytes [2.08 KB], Speed [11.91 MB/s], Samples [8] RCId [4358520]
16120 4530 05/27 20:06:27 680118 Name [Head Compression], Start Delay [408.80 us], Avg [51.10 us], Procsng Time [130.00 us], Avg [16.25 us], Bytes [2.08 KB], Speed [15.63 MB/s], Samples [8] RCId [4358520]
16120 4530 05/27 20:06:27 680118 Name [Head CRC32], Start Delay [1.40 us], Avg [175.00 ns], Procsng Time [2.05 ms], Avg [256.74 us], Bytes [2.09 KB], Speed [1019.40 KB/s], Samples [8] RCId [4358520]
16120 4530 05/27 20:06:27 680118 Name [Head Network], Start Delay [48.90 us], Avg [6.11 us], Procsng Time [1.00 ms], Avg [125.31 us], Bytes [2.09 KB], Speed [2.04 MB/s], Samples [8] RCId [4358520]
16120 4530 05/27 20:06:27 680118 Performing graceful connection termination RCId [4358520]
16120 4530 05/27 20:06:27 680118 Closing all sockets. RCId [4358520]
16120 4530 05/27 20:06:27 680118 back from closePipeline
16120 4530 05/27 20:06:27 680118 ~CVArchive() - Destroying CVArchive. This=000001B2BE60E010
16120 4530 05/27 20:06:27 ###### SdtTailSrvPool::Rel: Resetting SrvPool as ref. count is 0.
16120 4530 05/27 20:06:27 680118 [680118] Notifying Job Manager of phase failure.
16120 4530 05/27 20:06:27 680118 BKP CALLED COMPLETE (PHASE Status::FAIL), 680118. Token [680118:11:12:0:32808]