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 Explorer 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