Compact fails with warning "The request is not supported. Failed to duplicate extent" on random file on each backup run

[DonZoomik]

A few days ago one job started giving warnings.

Examples

07.06.2019 13:10:44 :: Failed to compact full backup file Details: Agent: Failed to process method {Transform.CompileFIB}: The request is not supported.
Failed to duplicate extent. Target file: D:\Backups\Backup_Job_1\VM1.temp, Source file: D:\Backups\Backup_Job_1\VM1.vbk, TgtOffset: 22085632, SrcOffset: 379912192, DataSize: 65536

In backup log, it looks like that:

Code: Select all

[07.06.2019 13:10:47] < 20036> cli| ERR |Command 'FibWrite(0x000001D387D5E090)' has failed.
[07.06.2019 13:10:47] < 20036> cli| >>  |The request is not supported.
[07.06.2019 13:10:47] < 20036> cli| >>  |Failed to duplicate extent. Target file: D:\Backups\Backup_Job_1\VM1.temp, Source file: D:\Backups\Backup_Job_1\VM1.vbk, TgtOffset: 22085632, SrcOffset: 379912192, DataSize: 65536
[07.06.2019 13:10:47] < 20036> cli| >>  |--tr:Error code: 0x00000032
[07.06.2019 13:10:47] < 20036> cli| >>  |--tr:Failed to process de-duplicated block
[07.06.2019 13:10:47] < 20036> cli| >>  |--tr:Failed to write block to blocks store.
[07.06.2019 13:10:47] < 20036> cli| >>  |--tr:Failed to append block. FIB index: [0]. FIB: [VM1.vmx].
[07.06.2019 13:10:47] < 20036> cli| >>  |--tr:Failed to process area [Data block. Start offset: [0], Length: [2771], Area ID: [0].].
[07.06.2019 13:10:47] < 20036> cli| >>  |An exception was thrown from thread [20036].
[07.06.2019 13:10:47] < 16660> stg| ERR |Failed to finalize backup storage update using MTA invoker,FIB recorder '2008028668048', FIB 'Backup of the FIB VM1.vmx'.
[07.06.2019 13:10:47] < 16660> stg| >>  |The request is not supported.
[07.06.2019 13:10:47] < 16660> stg| >>  |Failed to duplicate extent. Target file: D:\Backups\Backup_Job_1\VM1.temp, Source file: D:\Backups\Backup_Job_1\VM1.vbk, TgtOffset: 22085632, SrcOffset: 379912192, DataSize: 65536
[07.06.2019 13:10:47] < 16660> stg| >>  |--tr:Error code: 0x00000032
[07.06.2019 13:10:47] < 16660> stg| >>  |--tr:Failed to process de-duplicated block
[07.06.2019 13:10:47] < 16660> stg| >>  |--tr:Failed to write block to blocks store.
[07.06.2019 13:10:47] < 16660> stg| >>  |--tr:Failed to append block. FIB index: [0]. FIB: [VM1.vmx].
[07.06.2019 13:10:47] < 16660> stg| >>  |--tr:Failed to process area [Data block. Start offset: [0], Length: [2771], Area ID: [0].].
[07.06.2019 13:10:47] < 16660> stg| >>  |--tr:Failed to wait for recorder invoke.
[07.06.2019 13:10:47] < 16660> stg| >>  |An exception was thrown from thread [20036].
[07.06.2019 13:10:47] < 16660> cli| ERR |Send thread (channel) has failed.
[07.06.2019 13:10:47] < 16660> cli| >>  |The request is not supported.
[07.06.2019 13:10:47] < 16660> cli| >>  |Failed to duplicate extent. Target file: D:\Backups\Backup_Job_1\VM1.temp, Source file: D:\Backups\Backup_Job_1\VM1.vbk, TgtOffset: 22085632, SrcOffset: 379912192, DataSize: 65536
[07.06.2019 13:10:47] < 16660> cli| >>  |--tr:Error code: 0x00000032
[07.06.2019 13:10:47] < 16660> cli| >>  |--tr:Failed to process de-duplicated block
[07.06.2019 13:10:47] < 16660> cli| >>  |--tr:Failed to write block to blocks store.
[07.06.2019 13:10:47] < 16660> cli| >>  |--tr:Failed to append block. FIB index: [0]. FIB: [VM1.vmx].
[07.06.2019 13:10:47] < 16660> cli| >>  |--tr:Failed to process area [Data block. Start offset: [0], Length: [2771], Area ID: [0].].
[07.06.2019 13:10:47] < 16660> cli| >>  |--tr:Failed to wait for recorder invoke.
[07.06.2019 13:10:47] < 16660> cli| >>  |--tr:Failed to finalize backup storage update using MTA invoker,FIB recorder '2008028668048', FIB 'Backup of the FIB VM1.vmx'.
[07.06.2019 13:10:47] < 16660> cli| >>  |An exception was thrown from thread [20036].
[07.06.2019 13:10:47] < 16660> cli| Thread finished. Role: 'Area writer: Backup of the FIB VM1.vmx'.

On each backup run, it seems to affect a different file/VM (per-VM files) - there are some repetitions, over 25 runs with warning there have been 10 different affected VMs. Also puzzling is fact that this stared on a Friday, but compact is scheduled for Saturday. And now it's been like that for a week.
<removed part - mixed up the days>

VBR 9.5 Update 4a.
Windows 2019 with ReFS based repository. 64GB of RAM for ~29TB of disk space containing ~16TB of data.
Forever incremental with weekly compact.

Anybody seen anything like that (before I contact support)?

[Shestakov]

Hello DonZoomik,
Please provide the support case number as required by the forum's rules when asking about technical error.
Thanks!

[DonZoomik]

ID# 03605818

[DonZoomik]

I forgot to update this issue. The issue just disappeared one day as strangely as it appeared. I can't correlate it to any events and SR was closed with undetermined cause.