AzCopy sync failes to write hash data when using a readonly VSS shadow copy as the source

[ktrace2]

Which version of the AzCopy was used?

10.23.0

Which platform are you using?

Windows

What command did you run?

sync #SourcePath# #BlobStoragePath# --recursive=true --exclude-pattern=*humbs.db --exclude-attributes=S;H --put-md5 --delete-destination=true --compare-hash=md5 --cap-mbps=900

What problem was encountered?

Seeing this in the output:
INFO: One or more hash storage operations (read/write) have failed. Check the scanning log for details.

Seeing this in the logs:
failed to write hash data for #RelativePath#/#Filename#: failed to open data stream: open \?\C:\Backup\SymbolicLink#RelativePath##Filename#:.azcopysyncmeta: The media is write protected.

How can we reproduce the problem in the simplest way?

• Create a VSS snapshot of a volume using diskshadow.exe
• Create a Symbolic Link to the shadow copy
  cmd /c mklink /d $SymbolicLinkPath "$ShadowDevicePath"
• Run AzCopy sync using the Symbolic Link as the source

Have you found a mitigation/solution?

No

The sync works but I am not clear if this will cause issues long term. It seems AzCopy saves the hash of every file as an Alternate Data Stream on the source files however this is now failing because the shadow copy is read only.

I ran the sync command directly on the source files before I started using VSS snapshots. Will this now cause problems because the read only snapshot copy has an out of date hash that can no longer be updated? I am seeing a lot of these messages:

File #FilePath# was skipped because the source has the same hash

[adreed-msft]

I'd recommend you use the --hash-meta-dir flag and use a different, non-RO directory. This flag also requires the use of --local-hash-storage-mode=HiddenFiles.

[adreed-msft]

(also, please re-open this issue if this doesn't entirely solve your issue" ^)

[ktrace2]

I am trying this but it is failing with the following error (for every file):

failed to write hash data for Folder1/Filename.doc: failed to open hash meta file: open T:\AzCopyMetdata\ContainerA\Folder1\.Filename.doc.azcopysyncmeta: The system cannot find the path specified.

The arguments I passed were the following:

--compare-hash=md5 --local-hash-storage-mode=HiddenFiles --hash-meta-dir=T:\AzCopyMetdata\ContainerA

To confirm, T:\AzCopyMetdata\ContainerA is an empty directory. Should AzCopy create all the directories and files in here automatically?

[adreed-msft]

Typically, the meta directory root should already be created. In hindsight, I think what I'll do is re-open this issue and file a quick PR to add some automatic directory creation.

[ktrace2]

@adreed-msft thank you!

While waiting for a fix for this I used robocopy to mirror the directory structure to the metdata folder so I could test. This did allow it to go further and it creates all the metadata files now. However I am still seeing the following error in the scanning log duplicated for every file:

failed to write hash data for Folder1/Filename.doc: failed to hide file: The media is write protected.
failed to write hash data for Folder1/Filename2.doc: failed to hide file: The media is write protected.
failed to write hash data for Folder2/FilenameABC.doc: failed to hide file: The media is write protected.

I checked the code and it seems the SetHashData function in hash_data_adapter_hidden_files.go is trying to hide the data file instead of the metaFile which seems odd. Is this a bug?

[ktrace2]

@adreed-msft

I am using azcopy on two different volumes. Both use to work fine but now one of them is crashing:

Capturing this error is dificult as it only shows up in console. No errors are logged to the log files.

75364 Files Scanned at Source, 0 Files Scanned at Destination
81855 Files Scanned at Source, 0 Files Scanned at Destination
88484 Files Scanned at Source, 0 Files Scanned at Destination
94584 Files Scanned at Source, 0 Files Scanned at Destination
102581 Files Scanned at Source, 0 Files Scanned at Destination
104073 Files Scanned at Source, 12514 Files Scanned at Destination
104073 Files Scanned at Source, 22916 Files Scanned at Destination
104073 Files Scanned at Source, 41081 Files Scanned at Destination
104073 Files Scanned at Source, 64449 Files Scanned at Destination
104073 Files Scanned at Source, 84358 Files Scanned at Destination
runtime: VirtualAlloc of 1048576 bytes failed with errno=1455
fatal error: out of memory

runtime stack:
runtime.throw({0x10d495e?, 0xc036f71000?})
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/panic.go:1047 +0x65 fp=0x2f3cfce0 sp=0x2f3cfcb0 pc=0x43a5c5
runtime.sysUsedOS(0xc036ec8000, 0x100000)
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/mem_windows.go:83 +0x1c9 fp=0x2f3cfd40 sp=0x2f3cfce0 pc=0x4190e9
runtime.sysUsed(0x19ca3b0?, 0x80?, 0x41a436?)
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/mem.go:77 +0x25 fp=0x2f3cfd60 sp=0x2f3cfd40 pc=0x418be5
runtime.(*mheap).allocSpan(0x19ca3a0, 0x80, 0x0, 0x1)
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/mheap.go:1342 +0x619 fp=0x2f3cfdf8 sp=0x2f3cfd60 pc=0x429659
runtime.(*mheap).alloc.func1()
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/mheap.go:918 +0x65 fp=0x2f3cfe40 sp=0x2f3cfdf8 pc=0x428c45
runtime.systemstack()
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/asm_amd64.s:492 +0x4e fp=0x2f3cfe48 sp=0x2f3cfe40 pc=0x4682ee

goroutine 37047 [running]:
runtime.systemstack_switch()
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/asm_amd64.s:459 fp=0xc00474d578 sp=0xc00474d570 pc=0x468280
runtime.(*mheap).alloc(0x100000?, 0x80?, 0x70?)
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/mheap.go:912 +0x65 fp=0xc00474d5c0 sp=0xc00474d578 pc=0x428b85
runtime.(*mcache).allocLarge(0xc002ec0cb0?, 0x100000, 0x1)
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/mcache.go:233 +0x85 fp=0xc00474d610 sp=0xc00474d5c0 pc=0x417c85
runtime.mallocgc(0x100000, 0xeccba0, 0x1)
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/malloc.go:1029 +0x57e fp=0xc00474d688 sp=0xc00474d610 pc=0x40df9e
runtime.makeslice(0x10?, 0xc000313400?, 0xc00228cea0?)
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/slice.go:103 +0x52 fp=0xc00474d6b0 sp=0xc00474d688 pc=0x44f4f2
github.com/Azure/azure-storage-azcopy/v10/common.(*multiSizeSlicePool).RentSlice(0xc00000000c?, 0xfae4d)
	D:/a/1/s/common/multiSizeSlicePool.go:175 +0x14e fp=0xc00474d710 sp=0xc00474d6b0 pc=0xcc7e4e
github.com/Azure/azure-storage-azcopy/v10/common.(*singleChunkReader).blockingPrefetch(0xc003982b60, {0x12cea00, 0xc000a28c20}, 0x0)
	D:/a/1/s/common/singleChunkReader.go:241 +0x202 fp=0xc00474d830 sp=0xc00474d710 pc=0xcd04a2
github.com/Azure/azure-storage-azcopy/v10/common.(*singleChunkReader).BlockingPrefetch(0xc003982b60, {0x12cea00, 0xc000a28c20}, 0xc0?)
	D:/a/1/s/common/singleChunkReader.go:211 +0x87 fp=0xc00474d890 sp=0xc00474d830 pc=0xcd01a7
github.com/Azure/azure-storage-azcopy/v10/ste.scheduleSendChunks({0x12e53c0, 0xc0004b5570}, {0xc002ec0cb0, 0x65}, {0x12d2648?, 0xc000a28c20}, 0xfae4d, {0x12d8b60, 0xc002bf2a50}, 0xc0039db0f8, ...)
	D:/a/1/s/ste/xfer-anyToRemote-file.go:432 +0x5b8 fp=0xc00474da98 sp=0xc00474d890 pc=0xd98438
github.com/Azure/azure-storage-azcopy/v10/ste.anyToRemote_file({0x12e53c0, 0xc0004b5570}, 0xc000399a20, {0x2b1b6028, 0xc00030a4c0}, 0x1174b98, 0x1174bb8)
	D:/a/1/s/ste/xfer-anyToRemote-file.go:370 +0xe0c fp=0xc00474dd80 sp=0xc00474da98 pc=0xd9786c
github.com/Azure/azure-storage-azcopy/v10/ste.anyToRemote({0x12e53c0, 0xc0004b5570}, {0x2b1b6028, 0xc00030a4c0}, 0xc00474dea8?, 0xd6f275?)
	D:/a/1/s/ste/xfer-anyToRemote-file.go:204 +0x2ff fp=0xc00474de20 sp=0xc00474dd80 pc=0xd968df
github.com/Azure/azure-storage-azcopy/v10/ste.computeJobXfer.func5({0x12e53c0?, 0xc0004b5570?}, {0x2b1b6028?, 0xc00030a4c0?})
	D:/a/1/s/ste/xfer.go:75 +0x3a fp=0xc00474de60 sp=0xc00474de20 pc=0xda339a
github.com/Azure/azure-storage-azcopy/v10/ste.(*jobPartMgr).StartJobXfer(0x19505e0?, {0x12e53c0?, 0xc0004b5570?})
	D:/a/1/s/ste/mgr-JobPartMgr.go:472 +0x42 fp=0xc00474de90 sp=0xc00474de60 pc=0xd6ace2
github.com/Azure/azure-storage-azcopy/v10/ste.(*jobPartTransferMgr).StartJobXfer(0xc0004b5570?)
	D:/a/1/s/ste/mgr-JobPartTransferMgr.go:245 +0x32 fp=0xc00474deb8 sp=0xc00474de90 pc=0xd6bdd2
github.com/Azure/azure-storage-azcopy/v10/ste.(*jobMgr).transferProcessor.func1({0x12e53c0, 0xc0004b5570})
	D:/a/1/s/ste/mgr-JobMgr.go:1093 +0x199 fp=0xc00474df28 sp=0xc00474deb8 pc=0xd68119
github.com/Azure/azure-storage-azcopy/v10/ste.(*jobMgr).transferProcessor(0xc000580400, 0xc005806c60?)
	D:/a/1/s/ste/mgr-JobMgr.go:1105 +0xbd fp=0xc00474dfc0 sp=0xc00474df28 pc=0xd67ebd
github.com/Azure/azure-storage-azcopy/v10/ste.NewJobMgr.func2()
	D:/a/1/s/ste/mgr-JobMgr.go:200 +0x2a fp=0xc00474dfe0 sp=0xc00474dfc0 pc=0xd6268a
runtime.goexit()
	C:/hostedtoolcache/windows/go/1.19.12/x64/src/runtime/asm_amd64.s:1594 +0x1 fp=0xc00474dfe8 sp=0xc00474dfe0 pc=0x46a5e1
created by github.com/Azure/azure-storage-azcopy/v10/ste.NewJobMgr
	D:/a/1/s/ste/mgr-JobMgr.go:200 +0xc17

This is just the first two stack traces. The full output is over 5mb.

[gapra-msft]

@ktrace2

This issue should be resolved with our next release since the PR above has been merged. Closing this as a fix has been merged to main.