Special character (backslash) in the vSAN storage policy will cause replication to fail and create 0 byte unassociated objects.
search cancel

Special character (backslash) in the vSAN storage policy will cause replication to fail and create 0 byte unassociated objects.

book

Article ID: 326980

calendar_today

Updated On:

Products

VMware Live Recovery VMware vSAN VMware vSphere ESXi

Issue/Introduction


The purpose of this KB article is to advise the best course of action when there is a backslash in the vSAN storage policy.

Symptoms:
If the VM have a storage policy with a backslash (\) in the name and if we configure vSphere replication for the same VM then following symptoms can be seen.
  • vSphere replication will fail with "RPO Violation" after the threshold of the RPO violation is passed.
  • vSAN enable ESXi hosts will have the components in thousands which violates the maximum number of components in the ESXi host. 

Following is the logs excerpts to show what we expect to see if we have "\" in policy name. The policy name is "Test\Policy" with only 1 backslash and the VM is configured for replication with 5 minute RPO. The initial sync and replications are successful because the buffer for policy is not full. Each "sync" operation from replication will keep on duplicating the "\" every time a sync is issued from the vSphere replication and eventually the policy expression string size reached policy buffer limit and creation of object will fail but leave the 0 byte unassociated lock files.

++ Following is the policy details just after we kick off the replication. Notice that after first sync it has 2 backslashes.
  
uuid": "f8abaf5c-1041-9bf3-c651-005056af77d1",
   "owner": "5c0fe9e7-5053-7f49-1651-005056afa50d",
   "health": "Healthy",
   "revision": "0",
   "type": "POLICY",
   "flag": "2",
   "minHostVersion": "3",
   "md5sum": "554be2e787f27b7d2921673df6eb2720",
   "valueLen": "328",
   "content": {"stripeWidth": 1, "proportionalCapacity": 100, "hostFailuresToTolerate": 1, "spbmProfileId": "7d0d6ee1-ec0e-4ed4-929b-d2f500c80156", "spbmProfileGenerationNumber": 0, "CSN": 2, "spbmProfileName": "Test\\Policy"},

 
 
++ After some time the backslashes increased.
 
   "uuid": "efb0af5c-6849-be92-9ceb-005056afd4ad",
   "owner": "5c0fe9e8-f5bf-c29e-99c0-005056afd4ad",
   "health": "Healthy",
   "revision": "1",
   "type": "POLICY",
   "flag": "2",
   "minHostVersion": "3",
   "md5sum": "931b4f1e2cb607ef06cf9261cf5e7f49",
   "valueLen": "344",
   "content": {"stripeWidth": 1, "proportionalCapacity": [0, 100], "hostFailuresToTolerate": 1, "spbmProfileId": "7d0d6ee1-ec0e-4ed4-929b-d2f500c80156", "spbmProfileGenerationNumber": 0, "CSN": 2, "spbmProfileName": "Test\\\\\\\\\\\\\\\\Policy"},

 
  
++ And following is when the replication started to fail. The backslashes filled up and the buffer is full.
 
{
   "uuid": "d1beaf5c-ce09-8203-ec1c-005056afa50d",
   "owner": "5c0fe9e7-5053-7f49-1651-005056afa50d",
   "health": "Healthy",
   "revision": "1",
   "type": "POLICY",
   "flag": "2",
   "minHostVersion": "3",
   "md5sum": "0dd81a7c8d80efcd4455d1888f74ec98",
   "valueLen": "1360",
   "content": {"stripeWidth": 1, "proportionalCapacity": [0, 100], "hostFailuresToTolerate": 1, "spbmProfileId": "7d0d6ee1-ec0e-4ed4-929b-d2f500c80156", "spbmProfileGenerationNumber": 0, "CSN": 2, "spbmProfileName": "Test\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\Policy"},
   "errorStr": "(null)"
}
 
++ This is when the buffer (Policy) was not filled and the replication was successful. Notice the CreateChild call is successful.
 
2019-04-11T21:07:26.997Z info hostd[10581B70] [Originator@6876 sub=Vimsvc.TaskManager opID=hsl-43e247e6-eda1 user=vpxuser] Task Completed : haTask--vim.VirtualDiskManager.createChildDisk-155271504 Status success
2019-04-11T21:07:26.997Z verbose hostd[10581B70] [Originator@6876 sub=PropertyProvider opID=hsl-43e247e6-eda1 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.VirtualDiskManager.createChildDisk-155271504. Applied change to temp map.
2019-04-11T21:07:27.002Z verbose hostd[ED81B70] [Originator@6876 sub=PropertyProvider opID=fe59edad user=vpxuser] RecordOp ASSIGN: info, haTask--vmodl.query.PropertyCollector.Filter.destroy-155271506. Applied change to temp map.
2019-04-11T21:07:27.002Z verbose hostd[ED81B70] [Originator@6876 sub=PropertyProvider opID=fe59edad user=vpxuser] RecordOp ASSIGN: info, haTask--vmodl.query.PropertyCollector.Filter.destroy-155271506. Applied change to temp map.
2019-04-11T21:07:27.007Z info hostd[FCC2B70] [Originator@6876 sub=Vimsvc.TaskManager opID=hsl-43e247e6-edae user=vpxuser] Task Created : haTask--vim.NfcService.systemManagement-155271507
2019-04-11T21:07:27.007Z verbose hostd[FCC2B70] [Originator@6876 sub=PropertyProvider opID=hsl-43e247e6-edae user=vpxuser] RecordOp ADD: recentTask["haTask--vim.NfcService.systemManagement-155271507"], ha-taskmgr. Applied change to temp map.
2019-04-11T21:07:27.008Z verbose hostd[FCC2B70] [Originator@6876 sub=PropertyProvider opID=hsl-43e247e6-edae user=vpxuser] RecordOp ASSIGN: info, haTask--vim.NfcService.systemManagement-155271507. Applied change to temp map.
2019-04-11T21:07:27.009Z info hostd[FCC2B70] [Originator@6876 sub=Vimsvc.TaskManager opID=hsl-43e247e6-edae user=vpxuser] Task Completed : haTask--vim.NfcService.systemManagement-155271507 Status success
2019-04-11T21:07:27.009Z verbose hostd[FCC2B70] [Originator@6876 sub=PropertyProvider opID=hsl-43e247e6-edae user=vpxuser] RecordOp ASSIGN: info, haTask--vim.NfcService.systemManagement-155271507. Applied change to temp map.
2019-04-11T21:07:27.244Z info hostd[FC81B70] [Originator@6876 sub=Nfcsvc] PROXY connection to NFC(useSSL = \x01): found session ticket:[N9VimShared15NfcSystemTicketE:0x0e9e05bc]
2019-04-11T21:07:27.245Z info hostd[FC81B70] [Originator@6876 sub=Libs] Optimize socket buffer size.
2019-04-11T21:07:27.245Z info hostd[FC81B70] [Originator@6876 sub=Libs] NfcNet_OptimizeSocketBuffer: Setting buffer size using RTT=0 ms BANDWIDTH=134000 bytes/ms BUFFER_SIZE=40KB
2019-04-11T21:07:27.245Z info hostd[FC81B70] [Originator@6876 sub=Nfcsvc] Successfully initialized nfc callback for a write to the socket to be invoked on a separate thread
2019-04-11T21:07:27.245Z info hostd[FC81B70] [Originator@6876 sub=Nfcsvc] Plugin started

 
 
 
++ This is where the creation of child failed because of buffer full issue, also notice that we created a lock as well which was not release when the create child failed as well.
 
2019-04-11T22:02:57.372Z info hostd[FBC1B70] [Originator@6876 sub=Vimsvc.TaskManager opID=hsl-43e2488c-f490 user=vpxuser] Task Created : haTask--vim.VirtualDiskManager.createChildDisk-207066643
2019-04-11T22:02:57.372Z verbose hostd[FBC1B70] [Originator@6876 sub=PropertyProvider opID=hsl-43e2488c-f490 user=vpxuser] RecordOp ADD: recentTask["haTask--vim.VirtualDiskManager.createChildDisk-207066643"], ha-taskmgr. Applied change to temp map.
2019-04-11T22:02:57.372Z verbose hostd[FBC1B70] [Originator@6876 sub=PropertyProvider opID=hsl-43e2488c-f490 user=vpxuser] RecordOp ASSIGN: info, haTask--vim.VirtualDiskManager.createChildDisk-207066643. Applied change to temp map.
2019-04-11T22:02:57.378Z verbose hostd[FBC1B70] [Originator@6876 sub=PropertyProvider opID=hsl-43e2488c-f490 user=vpxuser] RecordOp ASSIGN: recentTask, vsan:526bcdc8654f4a5d-85e9a9593b3a7d3b. Sent notification immediately.
2019-04-11T22:02:57.378Z verbose hostd[FBC1B70] [Originator@6876 sub=PropertyProvider opID=hsl-43e2488c-f490 user=vpxuser] RecordOp ASSIGN: info.entity, haTask--vim.VirtualDiskManager.createChildDisk-207066643. Applied change to temp map.
2019-04-11T22:02:57.378Z verbose hostd[FBC1B70] [Originator@6876 sub=PropertyProvider opID=hsl-43e2488c-f490 user=vpxuser] RecordOp ASSIGN: info.entityName, haTask--vim.VirtualDiskManager.createChildDisk-207066643. Applied change to temp map.
2019-04-11T22:02:57.394Z info hostd[FBC1B70] [Originator@6876 sub=Libs opID=hsl-43e2488c-f490 user=vpxuser] OBJLIB-LIB:  ObjLib_SupportsNativeSparse: Parent disk supports native sparse. Parent object BE is 'vsan'. Child path is '/vmfs/volumes/vsan:526bcdc8654f4a5d-85e9a9593b3a7d3b/faabaf5c-9e1a-3dfe-8486-005056afd4ad/hbrdisk.RDID-7fd0868c-9711-405a-b32d-0a80740d459a.58927.62421580502963.vmdk'
2019-04-11T22:02:57.494Z info hostd[FBC1B70] [Originator@6876 sub=Libs opID=hsl-43e2488c-f490 user=vpxuser] OBJLIB-VSANOBJ: VsanObjCreateLockFile: Created lock file for object '91b9af5c-94bb-52b7-2622-005056afd4ad'
2019-04-11T22:02:57.498Z info hostd[FBC1B70] [Originator@6876 sub=Libs opID=hsl-43e2488c-f490 user=vpxuser] OBJLIB-VSANOBJ: VsanObjCreate: Vsan object created with UUID: 91b9af5c-94bb-52b7-2622-005056afd4ad
2019-04-11T22:02:57.694Z info hostd[FBC1B70] [Originator@6876 sub=Libs opID=hsl-43e2488c-f490 user=vpxuser] OBJLIB-VSANOBJ: VsanObjGetExtParams: could not convert policy to SPBM: Buffer too small to complete the operation (0xbad00db)
2019-04-11T22:02:57.696Z info hostd[FBC1B70] [Originator@6876 sub=Libs opID=hsl-43e2488c-f490 user=vpxuser] OBJLIB-LIB: ObjLib_GetExtParams : Failed to get ext params : Invalid argument (1441796)


Environment

VMware vSphere Replication 8.x
VMware vSAN 6.x

Cause

The backslash ('\') in the storage profile name will keep on duplicating every time a sync is issued from the vSphere replication and eventually the policy expression string size reached policy buffer limit.
Thus vSAN could not handle the policy and could not use it to create vSAN object any more, However when the request to create the disk comes to the vSAN, we create a lock and that lock is never released because of policy full and that lock ended up with the 0 byte unassociated objects.

Resolution

The resolution is to not use backslash or any other special characters in the vSAN storage policy.

Workaround:
The workaround is to remove the backslash from the policy name and then reconfigure the same VM again from SRM.

Additional Information

Impact/Risks:
  • The replication jobs will fail and hence the data will be at risk.
  • ESXi host will reach the component limit and because of that no other create operation from outside of the replication will also fail.
  • Cleanup of the 0 byte unassociated objects will be needed and that is time consuming.