File system backup fail (Archive Index phase fail)

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:

1. catalog migration to different path (once from the properties of MA, and once using change index server config workflow)
2. try using optimized scan
3. 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]