Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Broken VSS after installing #406

Open
SomebodyOdd opened this issue Oct 15, 2024 · 23 comments
Open

Broken VSS after installing #406

SomebodyOdd opened this issue Oct 15, 2024 · 23 comments

Comments

@SomebodyOdd
Copy link

System information

Type Version/Name
Distribution Name Windows 11
Distribution Version 23H2
Architecture x64
OpenZFS Version 2.2.6 RC7

Describe the problem you're observing

Just installing OpenZFS 2.2.6 RC7 breaks VSS, even if there are no pools present on system.
Most notably - it manifests as errors during chkdsk runs.

Describe how to reproduce the problem

  1. Install driver and reboot system.
  2. Attempt to do chkdsk /scan on NTFS volume (or any operation that tries to create a shadow copy, really)

Include any warning/errors/backtraces from the system logs

This results in errors related to shadow copy provider from chkdsk command. Application event log contains VSS event 12289 with hr = 0x80070001, Incorrect function
This error is consistent no matter what tries to create a shadow copy - I was able to reproduce it using chkdsk, built-in System Restore feature and Macrium Reflect trial version.

@sskras
Copy link

sskras commented Oct 15, 2024

Might be a dup of https://github.com/openzfsonwindows/ZFSin/issues/354.

@marcal commented 2 weeks ago there:

From different troubleshoting I did vssadmin list writers gives errors so it is not specific to veeam agent.

@SomebodyOdd, might be worth checking?

@lundman
Copy link

lundman commented Oct 15, 2024

Incorrect function sounds interesting, should probably see if FileSpy.exe picks up what requests it sends to us that we fail on.

@lundman
Copy link

lundman commented Oct 17, 2024

OK it says

1	10:41:56.375	1	System	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000100 Access: 00100180 Share:  00000007 Attrib: 0 Result: FILE_OPENED
2	10:41:56.377		System	IRP_MJ_QUERY_VOLUME_INFORMATION	00060874	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_BUFFER_OVERFLOW	FileFsVolumeInformation
3	10:41:56.401		System	IRP_MJ_CLEANUP	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
4	10:41:56.401		System	IRP_MJ_CLOSE	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
5	10:41:56.463		System	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000100 Access: 00100180 Share:  00000007 Attrib: 0 Result: FILE_OPENED
6	10:41:56.463		System	IRP_MJ_QUERY_VOLUME_INFORMATION	00060874	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_BUFFER_OVERFLOW	FileFsVolumeInformation
7	10:41:56.495		System	IRP_MJ_CLEANUP	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
8	10:41:56.495	1	System	IRP_MJ_CLOSE	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	

@lundman
Copy link

lundman commented Oct 17, 2024

Interesting to note that if I change mimic to say ntfs we get a different output:

7	10:48:49.874	5	svchost.exe	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000060 Access: 00120089 Share:  00000003 Attrib: 00000080 Result: FILE_OPENED
8	10:48:49.880		svchost.exe	FASTIO_DEVICE_CONTROL		FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	FAILURE	IOCTL_VOLSNAP_QUERY_DIFF_AREA_MINIMUM_SIZE (00534058)
9	10:48:49.880		svchost.exe	IRP_MJ_DEVICE_CONTROL	00060070	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_NOT_SUPPORTED	IOCTL_VOLSNAP_QUERY_DIFF_AREA_MINIMUM_SIZE (00534058)
10	10:48:49.880		svchost.exe	IRP_MJ_CLEANUP	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
11	10:48:49.880		svchost.exe	IRP_MJ_CLOSE	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
12	10:48:49.964		svchost.exe	IRP_MJ_CLEANUP	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
13	10:48:49.964		svchost.exe	IRP_MJ_CLOSE	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
14	10:48:49.966		svchost.exe	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000060 Access: 00120089 Share:  00000003 Attrib: 00000080 Result: FILE_OPENED
15	10:48:49.966		svchost.exe	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_USER_FS_REQUEST	00060870	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_NOT_SUPPORTED	FSCTL_QUERY_DEPENDENT_VOLUME (000901F0)
16	10:48:49.966	2	svchost.exe	FASTIO_QUERY_BASIC_INFO		FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FileBasicInformation CreateTime: 01DB202C-1EB4DF1D LastAccTime: 01DB2035-AEE3BBD8 LastWrtTime: 01DB2032-7B1435F8 ChangeTime: 01DB2032-7B1435F8 Attrib: 00000010
17	10:48:49.968		svchost.exe	IRP_MJ_CLEANUP	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
18	10:48:49.968		svchost.exe	IRP_MJ_CLOSE	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
19	10:48:49.968	1	svchost.exe	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00800021 Access: 00100000 Share:  0 Attrib: 0 Result: FILE_OPENED
20	10:48:49.970		svchost.exe	IRP_MJ_QUERY_VOLUME_INFORMATION	00060870	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FileFsFullSizeInformation TotalClusters: 3199A CallerClusters: 31668 AvailClusters: 31668 SectorsPerClus: 1 BytesPerSect: 1000
21	10:48:49.970		svchost.exe	IRP_MJ_CLEANUP	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
22	10:48:49.970		svchost.exe	IRP_MJ_CLOSE	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
23	10:48:49.970		svchost.exe	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000060 Access: 00120089 Share:  00000003 Attrib: 00000080 Result: FILE_OPENED
24	10:48:49.970		svchost.exe	FASTIO_DEVICE_CONTROL		FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	FAILURE	IOCTL_VOLSNAP_QUERY_DIFF_AREA_MINIMUM_SIZE (00534058)
25	10:48:49.970	1	svchost.exe	IRP_MJ_DEVICE_CONTROL	00060070	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_NOT_SUPPORTED	IOCTL_VOLSNAP_QUERY_DIFF_AREA_MINIMUM_SIZE (00534058)
26	10:48:49.972		svchost.exe	IRP_MJ_CLEANUP	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
27	10:48:49.972		svchost.exe	IRP_MJ_CLOSE	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
28	10:48:49.972		svchost.exe	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000060 Access: 0012019F Share:  00000003 Attrib: 00000080 Result: FILE_OPENED
29	10:48:49.972		svchost.exe	FASTIO_DEVICE_CONTROL		FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	FAILURE	IOCTL_VOLUME_GET_VOLUME_DISK_EXTENTS (00560000)
30	10:48:49.972		svchost.exe	IRP_MJ_DEVICE_CONTROL	00060070	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	IOCTL_VOLUME_GET_VOLUME_DISK_EXTENTS (00560000)
31	10:48:49.976	5	svchost.exe	FASTIO_DEVICE_CONTROL		FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	FAILURE	IOCTL_DISK_GET_DRIVE_GEOMETRY (00070000)
32	10:48:49.982	6	svchost.exe	IRP_MJ_DEVICE_CONTROL	00060070	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_INVALID_DEVICE_REQUEST	IOCTL_DISK_GET_DRIVE_GEOMETRY (00070000)
33	10:48:49.990	3	svchost.exe	IRP_MJ_CLEANUP	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
34	10:48:49.994	1	svchost.exe	IRP_MJ_CLOSE	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
35	10:48:55.806	4	svchost.exe	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000060 Access: 00120089 Share:  00000003 Attrib: 00000080 Result: FILE_OPENED
36	10:48:55.810		svchost.exe	IRP_MJ_QUERY_VOLUME_INFORMATION	00060870	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FileFsAttributeInformation FileSysAttr: 19C502FF MaxNameLen: 255 FsName: NTFS
37	10:48:55.810		svchost.exe	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00800021 Access: 00100000 Share:  0 Attrib: 0 Result: FILE_OPENED
38	10:48:55.810		svchost.exe	IRP_MJ_QUERY_VOLUME_INFORMATION	00060870	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FileFsFullSizeInformation TotalClusters: 3199A CallerClusters: 31668 AvailClusters: 31668 SectorsPerClus: 1 BytesPerSect: 1000
39	10:48:55.810		svchost.exe	IRP_MJ_CLEANUP	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
40	10:48:55.810		svchost.exe	IRP_MJ_CLOSE	00000404	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	
41	10:48:55.810	5	svchost.exe	IRP_MJ_CREATE	00000884	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000060 Access: 00120089 Share:  00000003 Attrib: 00000080 Result: FILE_OPENED
42	10:48:55.815		svchost.exe	FASTIO_DEVICE_CONTROL		FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	FAILURE	IOCTL_VOLSNAP_QUERY_DIFF_AREA_MINIMUM_SIZE (00534058)
43	10:48:55.815		svchost.exe	IRP_MJ_DEVICE_CONTROL	00060070	FFFF800F81E6EB88	\Device\ZFS{0b1bb601-af0b-32e8-a1d2-54c167af6277}	STATUS_NOT_SUPPORTED	IOCTL_VOLSNAP_QUERY_DIFF_AREA_MINIMUM_SIZE (00534058)


Wonder if we need to change the default back to always say ntfs. Far too many things in Windows do shitty test against the string "ntfs".

@sskras
Copy link

sskras commented Oct 17, 2024

Wonder if we need to change the default back to always say ntfs. Far too many things in Windows do shitty test against the string "ntfs".

Fair enough! Judging by the amount of similar effort put into WinBTRFS, eg. maharmstone/btrfs#681, now I think it's very much worth to mimic NTFS until OpenZFS driver gets bullet-proof.

The workarounds (needed to turn off the mimicking and stay a distinct FS) could be added later (or by additional contributors if the project gets some ones).

@lundman
Copy link

lundman commented Oct 17, 2024

I still don't get why VSS even wants to talk with ZFS, even when I report as ZFS. I don't claim to support it, so it is frustrating it even tries.

@SomebodyOdd
Copy link
Author

SomebodyOdd commented Oct 17, 2024

Dokany seems to not break VSS (at least, when I last dealt with it, I cannot try it for now) while dealing with being a filesystem itself, maybe something can be found in source code regarding that?
https://github.com/dokan-dev/dokany

Sorry for not providing further logs and diagnostics, I'm not near my windows machine and won't be for some time.

@lundman
Copy link

lundman commented Oct 17, 2024

I assume winbtrfs also doesnt break

@marcal
Copy link

marcal commented Nov 24, 2024

Hello,
I have made a test with the 2.2.6 RC10 and the problem is still there (with no zfs attached, only installation
What is strange is that all the GUID of the writers that have problems are differents between the two tests while the identical work.
Thank you
Not working
`vssadmin list writers

vssadmin 1.1 - Outil ligne de commande d’administration du service de cliché instantané de volume
(C) Copyright 2001-2013 Microsoft Corp.

Nom du rédacteur : 'Task Scheduler Writer'
ID du rédacteur : {d61d61c8-d73a-4eee-8cdd-f6f9786b7124}
ID de l’instance du rédacteur : {1bddd48e-5052-49db-9b07-b96f96727e6b}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'VSS Metadata Store Writer'
ID du rédacteur : {75dfb225-e2e4-4d39-9ac9-ffaff65ddf06}
ID de l’instance du rédacteur : {088e7a7d-09a8-4cc6-a609-ad90e75ddc93}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'Performance Counters Writer'
ID du rédacteur : {0bada1de-01a9-4625-8278-69e735f39dd2}
ID de l’instance du rédacteur : {f0086dda-9efc-47c5-8eb6-a944c3d09381}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'System Writer'
ID du rédacteur : {e8132975-6f93-4464-a53e-1050253ae220}
ID de l’instance du rédacteur : {3a440350-edf0-4b35-bbc0-2af9898666f7}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'ASR Writer'
ID du rédacteur : {be000cbe-11fe-4426-9c58-531aa6355fc4}
ID de l’instance du rédacteur : {a8999ca6-8b3a-4ad4-a311-b51e99daa15e}
État : [7] Échec
Dernière erreur : Délai dépassé

Nom du rédacteur : 'BITS Writer'
ID du rédacteur : {4969d978-be47-48b0-b100-f328f07ac1e0}
ID de l’instance du rédacteur : {636c0af2-5e52-4280-a466-afb7502e2587}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'Shadow Copy Optimization Writer'
ID du rédacteur : {4dc3bdd4-ab48-4d07-adb0-3bee2926fd7f}
ID de l’instance du rédacteur : {e9c7eca3-2701-4235-8098-8f6750ea39d9}
État : [7] Échec
Dernière erreur : Délai dépassé

Nom du rédacteur : 'WMI Writer'
ID du rédacteur : {a6ad56c2-b509-4e6c-bb19-49d8f43532f0}
ID de l’instance du rédacteur : {0de9eab6-2d59-4777-9576-c759bc3dc059}
État : [7] Échec
Dernière erreur : Délai dépassé

Nom du rédacteur : 'MSSearch Service Writer'
ID du rédacteur : {cd3f2362-8bef-46c7-9181-d62844cdc0b2}
ID de l’instance du rédacteur : {0be5b690-f802-4699-b55f-53d3f9a57a9a}
État : [7] Échec
Dernière erreur : Délai dépassé

Nom du rédacteur : 'Registry Writer'
ID du rédacteur : {afbab4a2-367d-4d15-a586-71dbb18f8485}
ID de l’instance du rédacteur : {6f568cc9-1548-4fef-9f52-824bf2ee8a5b}
État : [7] Échec
Dernière erreur : Délai dépassé

Nom du rédacteur : 'COM+ REGDB Writer'
ID du rédacteur : {542da469-d3e1-473c-9f4f-7847f01fc64f}
ID de l’instance du rédacteur : {bfe2083a-b4fe-446d-9471-328aa6c1085b}
État : [7] Échec
Dernière erreur : Délai dépassé
Working (without zfs) (need a reboot after uninstallation to work)vssadmin list writers

vssadmin 1.1 - Outil ligne de commande d’administration du service de cliché instantané de volume
(C) Copyright 2001-2013 Microsoft Corp.

Nom du rédacteur : 'Task Scheduler Writer'
ID du rédacteur : {d61d61c8-d73a-4eee-8cdd-f6f9786b7124}
ID de l’instance du rédacteur : {1bddd48e-5052-49db-9b07-b96f96727e6b}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'VSS Metadata Store Writer'
ID du rédacteur : {75dfb225-e2e4-4d39-9ac9-ffaff65ddf06}
ID de l’instance du rédacteur : {088e7a7d-09a8-4cc6-a609-ad90e75ddc93}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'Performance Counters Writer'
ID du rédacteur : {0bada1de-01a9-4625-8278-69e735f39dd2}
ID de l’instance du rédacteur : {f0086dda-9efc-47c5-8eb6-a944c3d09381}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'System Writer'
ID du rédacteur : {e8132975-6f93-4464-a53e-1050253ae220}
ID de l’instance du rédacteur : {3b575550-382e-4405-b260-739fde8f8cdf}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'ASR Writer'
ID du rédacteur : {be000cbe-11fe-4426-9c58-531aa6355fc4}
ID de l’instance du rédacteur : {4e07a3b7-f13c-4e54-be19-a137f5c47d29}
État : [5] En attente de la conclusion
Dernière erreur : Aucune erreur

Nom du rédacteur : 'BITS Writer'
ID du rédacteur : {4969d978-be47-48b0-b100-f328f07ac1e0}
ID de l’instance du rédacteur : {2d862dbb-ebed-400d-89dc-6e1f61ccbd44}
État : [1] Stable
Dernière erreur : Aucune erreur

Nom du rédacteur : 'Shadow Copy Optimization Writer'
ID du rédacteur : {4dc3bdd4-ab48-4d07-adb0-3bee2926fd7f}
ID de l’instance du rédacteur : {7b955057-fbf0-40ed-ad4c-fc7ea30901a3}
État : [5] En attente de la conclusion
Dernière erreur : Aucune erreur

Nom du rédacteur : 'WMI Writer'
ID du rédacteur : {a6ad56c2-b509-4e6c-bb19-49d8f43532f0}
ID de l’instance du rédacteur : {03e3e12e-f2d1-4b65-9b57-619760103303}
État : [5] En attente de la conclusion
Dernière erreur : Aucune erreur

Nom du rédacteur : 'MSSearch Service Writer'
ID du rédacteur : {cd3f2362-8bef-46c7-9181-d62844cdc0b2}
ID de l’instance du rédacteur : {f516a9c2-0b85-4336-8fb6-43a4cfd9a897}
État : [5] En attente de la conclusion
Dernière erreur : Aucune erreur

Nom du rédacteur : 'Registry Writer'
ID du rédacteur : {afbab4a2-367d-4d15-a586-71dbb18f8485}
ID de l’instance du rédacteur : {212268f7-5c67-4198-bb7a-7628e9f79eb8}
État : [5] En attente de la conclusion
Dernière erreur : Aucune erreur

Nom du rédacteur : 'COM+ REGDB Writer'
ID du rédacteur : {542da469-d3e1-473c-9f4f-7847f01fc64f}
ID de l’instance du rédacteur : {c7aa052e-fd08-4ee0-b684-5cda364d4567}
État : [5] En attente de la conclusion
Dernière erreur : Aucune erreur
`

@lundman
Copy link

lundman commented Nov 24, 2024

it is a great mystery, sometimes all pass, sometimes fail - I suspect it isnt the running at the time, but rather something that happens much earlier.

@HeadUntoWall
Copy link

DISKSHADOW> set verbose on
DISKSHADOW> set context clientaccessible
DISKSHADOW> set option differential
DISKSHADOW> add volume C:
DISKSHADOW> create

The last operation failed.
        - Returned HRESULT: 80042306
        - Error text: VSS_E_PROVIDER_VETO

Matching entry in event log:

Volume Shadow Copy Service error: Unexpected error CreateFileW(\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy2\,0x80000000,0x00000003,...).  hr = 0x80070001, Incorrect function.

Operation:
   Processing PreFinalCommitSnapshots

Context:
   Execution Context: System Provider

As expected. However, with an addition...

DISKSHADOW> set option noautorecover
DISKSHADOW> create

Alias VSS_SHADOW_1 for shadow ID {50ca3407-1494-4784-ac5a-58eb49df0f7d} set as environment variable.
Alias VSS_SHADOW_SET for shadow set ID {44e61b3c-aeee-4179-ba81-a40ce862d81d} set as environment variable.
Inserted file Manifest.xml into .cab file 2024-08-12_-27-04_LAB-RAT.cab
Inserted file DisDF62.tmp into .cab file 2024-08-12_-27-04_LAB-RAT.cab

Querying all shadow copies with the shadow copy set ID {44e61b3c-aeee-4179-ba81-a40ce862d81d}

        * Shadow copy ID = {50ca3407-1494-4784-ac5a-58eb49df0f7d}               %VSS_SHADOW_1%
                - Shadow copy set: {44e61b3c-aeee-4179-ba81-a40ce862d81d}       %VSS_SHADOW_SET%
                - Original count of shadow copies = 1
                - Original volume name: \\?\Volume{f44c1525-2e13-48ff-83d2-f31b6c9dfdbb}\ [C:\]
                - Creation time: 08/12/2024 01:27:03
                - Shadow copy device name: \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy3
                - Originating machine: LAB-RAT
                - Service machine: LAB-RAT
                - Not exposed
                - Provider ID: {b5946137-7b9f-4925-af80-51abd60b20d5}
                - Attributes:  No_Auto_Release Persistent Client_accessible No_Writers Differential

Number of shadow copies listed: 1

So apparently the problem isn't with creating shadows, strictly speaking. It happens later, on trying to access the shadow volume:

C:\Windows>dir /a \\.\HarddiskVolumeShadowCopy3\\
Incorrect function.

Even FileSpy fails to attach to it.
I also tried starting the system with the driver disabled, then enabling and starting it manually afterwards. Existing healthy shadow volumes remain accessible briefly, although creating new ones the normal way breaks immediately. A few minutes later, they are deleted:

The oldest shadow copy of volume C: was deleted to keep disk space usage for shadow copies of volume C: below the user defined limit.

Interesting... with 50GB already allocated of which none used, unbounded maximum and a 2TB disk, it thinks it's running out of space.

vssadmin list writers shows no errors at any point. The forced diskshadow snapshots from earlier do not survive a reboot, even if the driver doesn't start.
I'm not sure what else to try. It's like VSS freaks out so badly that it doesn't know what to blame.

@lundman
Copy link

lundman commented Dec 8, 2024

Woah ok that is interesting - didn't know any of these commands, so you are ahead of me. But a couple of things do sound interesting, like VSS_E_PROVIDER_VETO - did it ask us and we said no? Wonder if that adds anything to cbuf each time it is attempted.

Incorrect function. also interesting, especially since (I guess) HarddiskVolumeShadowCopy3 isn't ZFS.

@lundman
Copy link

lundman commented Dec 8, 2024

Poking around in these sources:

https://github.com/selfrender/Windows-Server-2003/blob/master/drivers/storage/volsnap/vss/modules/softprv/src/diff.cxx

It could be suggesting

    VSS_E_PROVIDER_VETO
        - Error in GetVolumeNameForVolumeMountPointW
        - Error in opening the IOCTL channel

Both of those could be true, no idea what the latter is. So errors from:

GetVolumeNameForVolumeMountPointW
ConvertVolMgmtVolumeNameIntoKernelObject
FindFirstVolumeW
FindNextVolumeW
IsVolumeSupported

Sadly, it seems VSS_E_PROVIDER_VETO is the generic error as well.

@HeadUntoWall
Copy link

On trying to create a normal snapshot with vssadmin, with an invalid noautorecover one from earlier already present:

14147	12:56:27.692		VSSVC.exe	IRP_MJ_CREATE	00000884	FFFFD603A79A75F0	C:	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000060 Access: 00120089 Share:  00000003 Attrib: 00000080 Result: FILE_OPENED
14148	12:56:27.692		VSSVC.exe	IRP_MJ_QUERY_VOLUME_INFORMATION	00060870	FFFFD603A79A75F0	C:	STATUS_SUCCESS	FileFsAttributeInformation FileSysAttr: 03E706FF MaxNameLen: 255 FsName: NTFS
14149	12:56:27.692		VSSVC.exe	IRP_MJ_CLEANUP	00000404	FFFFD603A79A75F0	C:	STATUS_SUCCESS	
14150	12:56:27.692		VSSVC.exe	IRP_MJ_CLOSE	00000404	FFFFD603A79A75F0	C:	STATUS_SUCCESS	
14151	12:56:27.692		VSSVC.exe	IRP_MJ_CREATE	00000884	FFFFD603A79A75F0	C:	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000060 Access: 00120089 Share:  00000003 Attrib: 00000080 Result: FILE_OPENED
14152	12:56:27.692		VSSVC.exe	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_USER_FS_REQUEST	00060870	FFFFD603A79A75F0	C:	STATUS_INVALID_DEVICE_REQUEST	FSCTL_QUERY_DEPENDENT_VOLUME (000901F0)
14153	12:56:27.692		VSSVC.exe	FASTIO_QUERY_BASIC_INFO		FFFFD603A79A75F0	C:	FAILURE	
14154	12:56:27.692		VSSVC.exe	IRP_MJ_QUERY_INFORMATION	00060870	FFFFD603A79A75F0	C:	STATUS_INVALID_PARAMETER	FileBasicInformation
14155	12:56:27.692		VSSVC.exe	FASTIO_DEVICE_CONTROL		FFFFD603A79A75F0	C:	FAILURE	IOCTL_STORAGE_GET_DEVICE_NUMBER (002D1080)
14156	12:56:27.692		VSSVC.exe	IRP_MJ_DEVICE_CONTROL	00060070	FFFFD603A79A75F0	C:	STATUS_SUCCESS	IOCTL_STORAGE_GET_DEVICE_NUMBER (002D1080)
14157	12:56:27.692		VSSVC.exe	FASTIO_DEVICE_CONTROL		FFFFD603A79A75F0	C:	FAILURE	Ioctl: 002D118C
14158	12:56:27.692		VSSVC.exe	IRP_MJ_DEVICE_CONTROL	00060070	FFFFD603A79A75F0	C:	STATUS_INVALID_DEVICE_REQUEST	Ioctl: 002D118C
14159	12:56:27.692		VSSVC.exe	IRP_MJ_CLEANUP	00000404	FFFFD603A79A75F0	C:	STATUS_SUCCESS	
14160	12:56:27.692		VSSVC.exe	IRP_MJ_CLOSE	00000404	FFFFD603A79A75F0	C:	STATUS_SUCCESS	
14161	12:56:28.223	421	System	IRP_MJ_WRITE	00060043	FFFF9206039C6170	C:\ProgramData\Microsoft\Windows Defender\Scans\mpenginedb.db-wal	STATUS_SUCCESS	Offset: 00000000-001FF000 ToWrite: 4000 Written: 3008 
14162	12:56:28.645		System	IRP_MJ_SET_INFORMATION	00000042	FFFF9206039C6170	C:\ProgramData\Microsoft\Windows Defender\Scans\mpenginedb.db-wal	STATUS_SUCCESS	FileEndOfFileInformation EndOfFile: 00000000-00202008
14163	12:56:28.645		System	IRP_MJ_SET_INFORMATION	00000042	FFFF9206039C6170	C:\ProgramData\Microsoft\Windows Defender\Scans\mpenginedb.db-wal	STATUS_SUCCESS	FileEndOfFileInformation EndOfFile: 00000000-00202008
14164	12:56:28.980		System	IRP_MJ_CREATE	00000884	0000000000000000	C:\System Volume Information	STATUS_FILE_IS_A_DIRECTORY	FILE_OPEN CreOpts: 00201060 Access: 00010000 Share:  00000007 Attrib: 0
14165	12:56:28.980		System	IRP_MJ_CREATE	00000884	FFFF9205FFD7FA00	C:\System Volume Information	STATUS_SUCCESS	FILE_OPEN_IF CreOpts: 00000021 Access: 001E0000 Share:  00000007 Attrib: 00000006 Result: FILE_OPENED
14166	12:56:28.980		System	IRP_MJ_QUERY_SECURITY	00000000	FFFF9205FFD7FA00	C:\System Volume Information	STATUS_BUFFER_OVERFLOW	
14167	12:56:28.980		System	IRP_MJ_QUERY_SECURITY	00000000	FFFF9205FFD7FA00	C:\System Volume Information	STATUS_SUCCESS	
14168	12:56:28.980		System	IRP_MJ_CLEANUP	00000404	FFFF9205FFD7FA00	C:\System Volume Information	STATUS_SUCCESS	
14169	12:56:28.980		System	IRP_MJ_CLOSE	00000404	FFFF9205FFD7FA00	C:\System Volume Information	STATUS_SUCCESS	
14171	12:56:28.980		System	IRP_MJ_CREATE	00000884	FFFF92060496D8F0	C:\System Volume Information\{504118d6-b557-11ef-8638-c3868cabe24f}{3808876b-c176-4e48-b7ae-04046e6cc752}	STATUS_SUCCESS	FILE_OVERWRITE_IF CreOpts: 00008062 Access: 0012019F Share:  0 Attrib: 00000006 Result: FILE_CREATED
14170	12:56:28.980		System	IRP_MJ_WRITE	00060043	FFFFD603A7D6FCA0	C:[-=Not In Cache=-]	STATUS_SUCCESS	Offset: 00000000-00012000 ToWrite: 2000 Written: 2000 
14172	12:56:28.980		System	IRP_MJ_SET_INFORMATION	00060830	FFFF92060496D8F0	C:\System Volume Information\{504118d6-b557-11ef-8638-c3868cabe24f}{3808876b-c176-4e48-b7ae-04046e6cc752}	STATUS_SUCCESS	FileDispositionInformation DeleteFile: 1
14173	12:56:28.980		System	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_USER_FS_REQUEST	00060870	FFFF92060496D8F0	C:\System Volume Information\{504118d6-b557-11ef-8638-c3868cabe24f}{3808876b-c176-4e48-b7ae-04046e6cc752}	STATUS_SUCCESS	FSCTL_GET_NTFS_VOLUME_DATA (00090064)
14176	12:56:28.980	8	System	IRP_MJ_SET_INFORMATION	00060830	FFFF92060496D8F0	C:\System Volume Information\{504118d6-b557-11ef-8638-c3868cabe24f}{3808876b-c176-4e48-b7ae-04046e6cc752}	STATUS_SUCCESS	FileEndOfFileInformation EndOfFile: 0000000C-80000000
14174	12:56:28.980	7	System	IRP_MJ_WRITE	00060043	FFFFD603A7D6FCA0	C:[-=Not In Cache=-]	STATUS_SUCCESS	Offset: 00000000-00003000 ToWrite: A000 Written: A000 
14175	12:56:28.988	1	System	IRP_MJ_WRITE	00060043	FFFFD603A7D6FCA0	C:[-=Not In Cache=-]	STATUS_SUCCESS	Offset: 00000000-0001C000 ToWrite: 1000 Written: 1000 
14179	12:56:28.989		System	IRP_MJ_SET_INFORMATION	00060830	FFFF92060496D8F0	C:\System Volume Information\{504118d6-b557-11ef-8638-c3868cabe24f}{3808876b-c176-4e48-b7ae-04046e6cc752}	STATUS_SUCCESS	FileAllocationInformation AllocationSize: 0000000C-80000000
14177	12:56:28.989		System	IRP_MJ_WRITE	00060043	FFFFD603A7D6FCA0	C:[-=Not In Cache=-]	STATUS_SUCCESS	Offset: 00000000-0000C000 ToWrite: 1000 Written: 1000 
14178	12:56:28.989		System	IRP_MJ_WRITE	00060043	FFFFD603A7D6FCA0	C:[-=Not In Cache=-]	STATUS_SUCCESS	Offset: 00000000-0001D000 ToWrite: 1000 Written: 1000 
14180	12:56:28.989		System	IRP_MJ_QUERY_VOLUME_INFORMATION	00060870	FFFF92060496D8F0	C:\System Volume Information\{504118d6-b557-11ef-8638-c3868cabe24f}{3808876b-c176-4e48-b7ae-04046e6cc752}	STATUS_SUCCESS	FileFsAttributeInformation FileSysAttr: 03E706FF MaxNameLen: 255 FsName: NTFS
14181	12:56:28.989		System	IRP_MJ_CREATE	00000884	FFFFD603A79A75F0	C:	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000020 Access: 00120089 Share:  00000007 Attrib: 0 Result: FILE_OPENED
14182	12:56:28.989		System	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_USER_FS_REQUEST	00060830	FFFF92060496D8F0	C:\System Volume Information\{504118d6-b557-11ef-8638-c3868cabe24f}{3808876b-c176-4e48-b7ae-04046e6cc752}	STATUS_SUCCESS	FSCTL_MARK_HANDLE (000900FC)
14183	12:56:28.989		System	IRP_MJ_CLEANUP	00000404	FFFFD603A79A75F0	C:	STATUS_SUCCESS	
14184	12:56:28.989		System	IRP_MJ_CLOSE	00000404	FFFFD603A79A75F0	C:	STATUS_SUCCESS	
14185	12:56:28.989		System	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_USER_FS_REQUEST	00060870	FFFF92060496D8F0	C:\System Volume Information\{504118d6-b557-11ef-8638-c3868cabe24f}{3808876b-c176-4e48-b7ae-04046e6cc752}	STATUS_SUCCESS	FSCTL_GET_NTFS_VOLUME_DATA (00090064)
14186	12:56:28.989		System	IRP_MJ_CREATE	00000884	FFFFD603A79A75F0	C:	STATUS_SUCCESS	FILE_OPEN CreOpts: 00000020 Access: 00120089 Share:  00000007 Attrib: 0 Result: FILE_OPENED
14187	12:56:28.989		System	IRP_MJ_QUERY_VOLUME_INFORMATION	00060870	FFFFD603A79A75F0	C:	STATUS_SUCCESS	FileFsAttributeInformation FileSysAttr: 03E706FF MaxNameLen: 255 FsName: NTFS
14188	12:56:28.989		System	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_USER_FS_REQUEST	00060870	FFFFD603A79A75F0	C:	STATUS_SUCCESS	FSCTL_GET_NTFS_VOLUME_DATA (00090064)

And then hundreds of these

14189	12:56:28.989		System	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_USER_FS_REQUEST	00060800	FFFFD603A79A75F0	C:	STATUS_BUFFER_OVERFLOW	FSCTL_GET_VOLUME_BITMAP (0009006F)

Until suddenly

15213	12:56:29.022		System	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_USER_FS_REQUEST	00060800	FFFFD603A79A75F0	C:	STATUS_SUCCESS	FSCTL_GET_VOLUME_BITMAP (0009006F)

And then it repeats over and over again. It only stops when the noautorecover snapshot gets deleted for alleged space problems.
Previously, on trying to attach in FileSpy or list contents in cmd.exe:

14082	12:53:49.490		FileSpy.exe	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_MOUNT_VOLUME	00000042			STATUS_INVALID_DEVICE_REQUEST	
14083	12:53:53.568		FileSpy.exe	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_MOUNT_VOLUME	00000042			STATUS_INVALID_DEVICE_REQUEST	
14084	12:53:57.739		cmd.exe	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_MOUNT_VOLUME	00000042			STATUS_INVALID_DEVICE_REQUEST	

It seems all attempts to mount the shadow volume, even if everything involved is NTFS, fail while the driver is present. There's also a bunch of these

20732	12:56:31.649		System	IRP_MJ_FILE_SYSTEM_CONTROL/IRP_MN_USER_FS_REQUEST	00060030			STATUS_INVALID_DEVICE_REQUEST	FSCTL_INVALIDATE_VOLUMES (00090054)

though I'm not sure of their significance, other than maybe implying that anything that treats it as a volume breaks.

Attaching the wall of text as a file.
filespy.log

@lundman
Copy link

lundman commented Dec 9, 2024

In the VSS sources, one of the checks it does is, calling FileFsAttributeInformation FileSysAttr: 03E706FF and comparing that that to VSS_IS_SUPPORTED. In this case, your C: replies with 03E706FF

FILE_CASE_SENSITIVE_SEARCH (0x00000001)
FILE_CASE_PRESERVED_NAMES (0x00000002)
FILE_UNICODE_ON_DISK (0x00000004)
FILE_PERSISTENT_ACLS (0x00000008)
FILE_FILE_COMPRESSION (0x00000010)
FILE_VOLUME_QUOTAS (0x00000020)
FILE_SUPPORTS_SPARSE_FILES (0x00000040)
FILE_SUPPORTS_REPARSE_POINTS (0x00000080)
FILE_SUPPORTS_REMOTE_STORAGE (0x00000100)
FILE_SUPPORTS_OBJECT_IDS (0x00010000)
FILE_SUPPORTS_ENCRYPTION (0x00020000)
FILE_NAMED_STREAMS (0x00040000)
FILE_SUPPORTS_TRANSACTIONS (0x00200000)
FILE_SUPPORTS_HARD_LINKS (0x00400000)
FILE_SUPPORTS_EXTENDED_ATTRIBUTES (0x00800000)
FILE_SUPPORTS_OPEN_BY_FILE_ID (0x01000000)
FILE_SUPPORTS_USN_JOURNAL (0x02000000)

and VSS_VOLATTR_SUPPORTED is defined as

FILE_SUPPORTS_REPARSE_POINTS (0x00000080)
FILE_SUPPORTS_TRANSACTIONS (0x00200000)
FILE_SUPPORTS_SPARSE_FILES (0x00000040)
FILE_SUPPORTS_USN_JOURNAL (0x02000000)

where all of those has to be set.

OpenZFS I reply with
https://github.com/openzfsonwindows/openzfs/blob/development/module/os/windows/zfs/zfs_vnops_windows.c#L2379-L2420

deliberately NOT including FILE_SUPPORTS_TRANSACTIONS FILE_SUPPORTS_USN_JOURNAL so that we won't be considered for VSS. That isn't quite working mind you, since it still tries to talk to us.

Then asks for FSCTL_QUERY_DEPENDENT_VOLUME, we say nuh-uh
https://github.com/openzfsonwindows/openzfs/blob/development/module/os/windows/zfs/zfs_vnops_windows.c#L4206

Then asks IOCTL_STORAGE_GET_DEVICE_NUMBER and I am not entirely sure what we should be returning here. I believe we just return 0
https://github.com/openzfsonwindows/openzfs/blob/development/module/os/windows/zfs/zfs_vnops_windows.c#L6224-L6226

ioctl 002D118C is a VSS range, interesting that C: says STATUS_INVALID_DEVICE_REQUEST

Then it writes to C:\System Volume Information which I have never seen it get that far on ZFS.

As for FSCTL_GET_VOLUME_BITMAP we just reply with STATUS_INVALID_DEVICE_REQUEST

@lundman
Copy link

lundman commented Dec 9, 2024

Not sure how chatgpt went from VSS_VOLATTR_SUPPORTED to listing those attributes, it seems to be just 1 in the code base.

@HeadUntoWall
Copy link

HeadUntoWall commented Jan 26, 2025

From a (admittedly blind) search for what exactly IOCTL_STORAGE_GET_DEVICE_NUMBER is supposed to give, I understand it is used to determine the physical disk associated with a volume. However:

https://devblogs.microsoft.com/oldnewthing/20201021-00/?p=104387

  • It fails to account for the case where the volume spans multiple physical drives.
  • In my experience, if the volume is a CD-ROM drive with no disk in the drive, the call reports that the physical drive number is 0, which is almost certainly incorrect.

In practice, it seems that if the volume spans multiple physical drives, the IOCTL_STORAGE_GET_DEVICE_NUMBER fails (with ERROR_INVALID_FUNCTION, it seems, which is the Win32 manifestation of the NT status code STATUS_INVALID_DEVICE_REQUEST)

https://devblogs.microsoft.com/oldnewthing/20201022-00/?p=104391

[...] if the volume does not have a unique physical disk, then the call will fail.

Does such a request even make sense here? Does the volume have a unique physical disk? It certainly does not in the case of RAID-Z.
Moreover, if it's a problem when the volume spans multiple disks, why does it break when this is not the case? And why does VSS not break when you are NTFS on software RAID-0, 1 or 5 created by Windows itself?

The fact that it breaks when there are no volumes makes me suspect that VSS is asking the question to something that isn't meant to answer it. Could the ROOT\OpenZFS virtual device be somehow responsible for the confusion?

@lundman
Copy link

lundman commented Jan 26, 2025

We do have a IOCTL_STORAGE_GET_DEVICE_NUMBER handle, and we always return 0 - but it is hard to imagine why that would be the issue when VSS also fails when nothing is mounted. You can't call IOCTL_STORAGE_GET_DEVICE_NUMBER without first opening the mounted volume to issue it to? But I suppose also, that could be an interesting debugging session, comment out more and more of the OpenZFS driver, until VSS works again.

@copyliu
Copy link

copyliu commented Feb 5, 2025

this VSS issue only appear after 2.2.6-rc*, I tested 2.2.3 in a VM at lease chkdsk /scan is normal

@lundman
Copy link

lundman commented Feb 5, 2025

Hmm so latest 2.2.3 and earliest 2.2.6 would be interesting to compare. It could be INF change, or that we added IRP_* to reply which didn't used to reply.

@copyliu
Copy link

copyliu commented Feb 5, 2025

after some painful compile and test , I can confirm this issue cause by 8c07c15

@lundman
Copy link

lundman commented Feb 5, 2025

Awesome thanks. That is where got mounting working, so it is a rather large commit, but it does narrow down what to look at.

@lundman
Copy link

lundman commented Feb 6, 2025

I got chkdsk to work after 66a4881
Doing a build now to see if it keeps working...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants