Error seeking to write in Catalyst

Hi,

from time to time the Backup of a special VM inside a JOB will fail with the following error:

Unable to open DataSession on Catalyst store vmexp01 object VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_6 with Exception message:Error seeking to write in Catalyst (OSCLT_ERR_WRITE_IN_PLACE_NOT_SUPPORTED -3201)

It could be that this error wont come for weeks or over a month and then 2 times in one week, 1 week nothing, the next week it will come for one or two times. There is no recognizable pattern or me.

It´s only one VM that will have this error. Other VM's will be OK doing thier Backup in the same Catalyst Store.

VMware ESXi 6.0.0 build-5224934

VM ExplorerRegistered 7.1.001 (64-bit)

From the VMExplorer Log

[4212] 19.11.2018 12:07:39,170        INFO  [1706644] Agent Incremental Backup Task started for VM:'XXXXXXXX' (VMX: 7.1.001.0)
[4212] 19.11.2018 12:07:39,170        INFO  [1706644] Agent Incremental Backup transport mode is compressed: False. Keep backup compressed: False. Encrypt: False
[4212] 19.11.2018 12:07:39,170        INFO  [1706644] Agent Incremental Backup write data directly to disk: False
[4212] 19.11.2018 12:07:39,170        INFO  [1706644] Trying to use agent for flat-file downloads
[4212] 19.11.2018 12:07:39,170        INFO  [1706644] Searching for VM XXXXXXXX on ESX Server XXX.XX.XX.XXX (c15a6ff5-3e45-42b3-b3dd-62a1e6008eef)
[4212] 19.11.2018 12:07:40,855        INFO  [1706644] Source: 'dmzesxi1' (License 'ESXHypervisorCpuPackage') Target: 'StoreOnce' ([vmexp01])
[4212] 19.11.2018 12:07:42,680        INFO  [1706644] Looking for incremental backups in Catalyst store: [vmexp01]
[4212] 19.11.2018 12:07:42,711        INFO  [1706644] Found 2 full incremental backups
[4212] 19.11.2018 12:07:42,711        INFO  [1706644] Checking full incremental backup a07b797d-9097-4f89-991e-40d49fe6a6fc
[4212] 19.11.2018 12:07:42,711        INFO  [7122952] Search existing full backup GUID = "a07b797d-9097-4f89-991e-40d49fe6a6fc", search incremental backup = True
[4212] 19.11.2018 12:07:43,475        INFO  [7122952] Found 5 backups
[4212] 19.11.2018 12:07:43,475        INFO  [7122952] Check incremental backup integrity
[4212] 19.11.2018 12:07:43,475        INFO  [1706644] Checking full incremental backup bb133754-b22e-436b-beb9-a68aa231fc0a
[4212] 19.11.2018 12:07:43,475        INFO  [4763705] Search existing full backup GUID = "bb133754-b22e-436b-beb9-a68aa231fc0a", search incremental backup = True
[4212] 19.11.2018 12:07:43,881        INFO  [4763705] Found 6 backups
[4212] 19.11.2018 12:07:43,881        INFO  [4763705] Check incremental backup integrity
[4212] 19.11.2018 12:08:12,398        INFO  [1706644] Existing backup integrity OK. There are 5 versions.
[4212] 19.11.2018 12:08:12,398        INFO  [1706644] Make Full incremental backup. Backup missed on saturday every week (Make a full backup every saturday every week). Last full backup Monday 12.11.2018 12:08
[4212] 19.11.2018 12:08:12,398        INFO  [1706644] Start FULL backup/replication
[4212] 19.11.2018 12:08:12,398        INFO  [1706644] ForceSnapshot is enabled.
[4212] 19.11.2018 12:08:12,398        INFO  [1706644] Checking backup size
[4212] 19.11.2018 12:08:12,398        INFO  [1706644] It was not possible to determine the target datastore free space
[4212] 19.11.2018 12:08:12,616        INFO  [1706644] Creating backup snapshot "Backup Snapshot 2018-11-19-120739" on VM: XXX.XX.XX.XXX/XXXXXXXX(memory=False, quiesce=False)
[4212] 19.11.2018 12:08:14,332        INFO  [1706644] Snapshot created on VM: XXX.XX.XX.XXX/XXXXXXXX
[4212] 19.11.2018 12:08:15,705        INFO  [1706644] Creating target .vmx file XXXXXXXX.vmx
[4212] 19.11.2018 12:08:55,735        INFO  [1706644] Target object 'XXXXXXXX.vmx' created: VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_1
[4212] 19.11.2018 12:08:55,735        INFO  [1706644] Creating target .vmsd file: XXXXXXXX.vmsd
[4212] 19.11.2018 12:09:15,204        INFO  [1706644] Target object 'XXXXXXXX.vmsd' created: VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_2
[4212] 19.11.2018 12:09:15,204        INFO  [1706644] Copying [localstorage] XXXXXXXX/XXXXXXXX.vmxf
[4212] 19.11.2018 12:09:23,846        INFO  [1706644] StreamTransferFile => from '[localstorage] XXXXXXXX/XXXXXXXX.vmxf' to '[vmexp01] VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_3' (263 bytes)
[4212] 19.11.2018 12:09:40,024        INFO  [1706644] Target object 'XXXXXXXX.vmxf' transferred: VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_3
[4212] 19.11.2018 12:09:40,024        INFO  [1706644] Copying [localstorage] XXXXXXXX/XXXXXXXX.nvram
[4212] 19.11.2018 12:09:48,573        INFO  [1706644] StreamTransferFile => from '[localstorage] XXXXXXXX/XXXXXXXX.nvram' to '[vmexp01] VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_4' (8684 bytes)
[4212] 19.11.2018 12:10:04,688        INFO  [1706644] Target object 'XXXXXXXX.nvram' transferred: VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_4
[4212] 19.11.2018 12:10:04,688        INFO  [1706644] Copying [localstorage] XXXXXXXX/XXXXXXXX.vmdk
[4212] 19.11.2018 12:10:13,736        INFO  [1706644] StreamTransferFile => from '[localstorage] XXXXXXXX/XXXXXXXX.vmdk' to '[vmexp01] VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_5' (503 bytes)
[4212] 19.11.2018 12:10:47,713        INFO  [1706644] Target object 'XXXXXXXX.vmdk' transferred: VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_5
[4212] 19.11.2018 12:10:47,713        INFO  [1706644] Copying [localstorage] XXXXXXXX/XXXXXXXX-flat.vmdk
[4212] 19.11.2018 12:11:04,545        INFO  [1706644] Running Download on Agent: /vmfs/volumes/localstorage/XXXXXXXX/XXXXXXXX-flat.vmdk
[4212] 19.11.2018 13:23:08,082        ERROR [3543812] Exception while writing to Catalyst Error writing to Catalyst (OSCLT_ERR_DEDUPE_ERROR -3400)
[4212] 19.11.2018 13:23:08,784        ERROR 1706644File transfer error. An exception occurred while writing to HPE StoreOnce Catalyst fixed block stream
[4212] 19.11.2018 13:23:08,784        ERROR [3543812] Exception while writing to Catalyst Error writing to Catalyst (OSCLT_CLTERR_DATA_SESSION_IN_ERROR_STATE -3999)
[4212] 19.11.2018 13:23:08,784        ERROR DataSession is in error mode for HPE StoreOnce Catalyst fixed block stream
[4212] 19.11.2018 13:23:08,799        ERROR [1706644] Download on Agent problem - Download error: An exception occurred while writing to HPE StoreOnce Catalyst fixed block stream
[4212] 19.11.2018 13:23:08,799        INFO  [1706644] Download on Agent re-trying in 10s
[4212] 19.11.2018 13:23:18,815        INFO  [1706644] Re-trying Download on Agent [1]
[4212] 19.11.2018 13:23:55,584        ERROR OpenDataSession: Error seeking to write in Catalyst (OSCLT_ERR_WRITE_IN_PLACE_NOT_SUPPORTED -3201)
[4212] 19.11.2018 13:23:55,584        ERROR [3543812] Unable to open DataSession on Catalyst store vmexp01 object VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_6 with Exception message:Error seeking to write in Catalyst (OSCLT_ERR_WRITE_IN_PLACE_NOT_SUPPORTED -3201) 
[4212] 19.11.2018 13:23:55,584        ERROR [1706644] Downloading from TDC (Unable to open DataSession on Catalyst store vmexp01 object VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_6 with Exception message:Error seeking to write in Catalyst (OSCLT_ERR_WRITE_IN_PLACE_NOT_SUPPORTED -3201) )
[4212] 19.11.2018 13:23:55,584        ERROR [1706644] An error occurred while transferring the delta file: Unable to open DataSession on Catalyst store vmexp01 object VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_6 with Exception message:Error seeking to write in Catalyst (OSCLT_ERR_WRITE_IN_PLACE_NOT_SUPPORTED -3201) 
[4212] 19.11.2018 13:23:55,600        INFO  [1706644] Rolling back, deleting Catalyst backup objects...
[4212] 19.11.2018 13:23:55,600        INFO  [1706644] Deleting XXXXXXXX.vmx - VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_1
[4212] 19.11.2018 13:23:56,629        INFO  [1706644] Deleting XXXXXXXX.vmsd - VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_2
[4212] 19.11.2018 13:23:56,692        INFO  [1706644] Deleting XXXXXXXX.vmxf - VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_3
[4212] 19.11.2018 13:23:56,738        INFO  [1706644] Deleting XXXXXXXX.nvram - VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_4
[4212] 19.11.2018 13:23:56,785        INFO  [1706644] Deleting XXXXXXXX.vmdk - VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_5
[4212] 19.11.2018 13:23:56,848        INFO  [1706644] Deleting XXXXXXXX-flat.vmdk - VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_6
[4212] 19.11.2018 13:23:56,894        INFO  [1706644] Rollback completed
[4212] 19.11.2018 13:23:56,894        INFO  [1706644] Removing Backup snapshot on: XXX.XX.XX.XXX/XXXXXXXX
[4212] 19.11.2018 13:36:39,365        INFO  [1706644] Backup snapshot removed: XXX.XX.XX.XXX/XXXXXXXX
[4212] 19.11.2018 13:36:39,365        ERROR [1706644] BackupExecutor: Unable to open DataSession on Catalyst store vmexp01 object VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_6 with Exception message:Error seeking to write in Catalyst (OSCLT_ERR_WRITE_IN_PLACE_NOT_SUPPORTED -3201) 
[4212] 19.11.2018 13:36:39,365        ERROR [1706644] Perform ESX Agent Incremental Backup exception: Unable to open DataSession on Catalyst store vmexp01 object VMXBackup_3625187c-6aa7-4e15-ae3c-99f17469e5c1_6 with Exception message:Error seeking to write in Catalyst (OSCLT_ERR_WRITE_IN_PLACE_NOT_SUPPORTED -3201) 
[4212] 19.11.2018 13:36:40,925        INFO  [9258039] ---------------------------------------------------------------------------------------XXX.XX.XX.XXX

I would appreciate any help.

Thank you.

With best regards,

B. Thillmann

 

 

Parents Reply Children
No Data