search

openzfsonwindows / openzfs

OpenZFS on Linux and FreeBSD
https://openzfs.github.io/openzfs-docs
Other
455 stars 15 forks source link

Cannot copy to dataset using rclone or robocopy #389

Open thesn10 opened 3 months ago

thesn10 commented 3 months ago

System information

Type Version/Name
Distribution Name Windows
Distribution Version 11
Architecture amd64
OpenZFS Version zfswin-2.2.3rc6

Describe the problem you're observing

If i try to copy a directory that has a subfolder to the root Z:\ it will work, but if you copy to the zfs dataset Z:\dataset, it will fail. I have tried 3 tools and 2 of them fail to copy to the dataset x Z:\ Z:\dataset
rclone ✅success 🔴fail
robocopy ✅success 🔴fail
copy ✅success ✅ success

Describe how to reproduce the problem

Create the a directory structure that has a subfolder on your ntfs drive

copytest
│   file.txt
│
└───subfolder
        subfolder-file.txt

Create pool and dataset:

zpool.exe create \
    -O casesensitivity=insensitive \
    -O normalization=formD \
    -O compression=lz4 \
    -O atime=off \
    -O ashift=12 \
    tank PHYSICALDRIVE1

zfs set driveletter=Z tank

zfs create tank/dataset

Now if you try to copy this directory to the root Z:\ it will work, but if you copy to the zfs dataset Z:\dataset it will fail

RClone

Copying to root works:

> rclone copy copytest "Z:\copytest" -v

2024/06/23 00:40:34 INFO  : file.txt: Copied (new)
2024/06/23 00:40:34 INFO  : subfolder/subfolder-file.txt: Copied (new)
2024/06/23 00:40:34 INFO  : subfolder: Set directory modification time (using DirSetModTime)
2024/06/23 00:40:34 INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Transferred:            2 / 2, 100%
Elapsed time:         0.1s

Copying to dataset fails:

> rclone copy copytest "Z:\dataset\copytest" -v

2024/06/23 00:34:11 ERROR : file.txt: Failed to copy: mkdir \\?\Z:\dataset: Cannot create a file when that file already exists.
2024/06/23 00:34:11 ERROR : subfolder/subfolder-file.txt: Failed to copy: mkdir \\?\Z:\dataset: Cannot create a file when that file already exists.
2024/06/23 00:34:11 ERROR : subfolder: Failed to update directory timestamp or metadata: chtimes \\?\Z:\dataset\copytest\subfolder: The system cannot find the file specified.
2024/06/23 00:34:11 ERROR : Attempt 1/3 failed with 4 errors and: failed to set directory modtime: chtimes \\?\Z:\dataset\copytest\subfolder: The system cannot find the file specified.
2024/06/23 00:34:11 ERROR : file.txt: Failed to copy: mkdir \\?\Z:\dataset: Cannot create a file when that file already exists.
2024/06/23 00:34:11 ERROR : subfolder/subfolder-file.txt: Failed to copy: mkdir \\?\Z:\dataset: Cannot create a file when that file already exists.
2024/06/23 00:34:11 ERROR : subfolder: Failed to update directory timestamp or metadata: chtimes \\?\Z:\dataset\copytest\subfolder: The system cannot find the file specified.
2024/06/23 00:34:11 ERROR : Attempt 2/3 failed with 4 errors and: failed to set directory modtime: chtimes \\?\Z:\dataset\copytest\subfolder: The system cannot find the file specified.
2024/06/23 00:34:11 ERROR : file.txt: Failed to copy: mkdir \\?\Z:\dataset: Cannot create a file when that file already exists.
2024/06/23 00:34:11 ERROR : subfolder/subfolder-file.txt: Failed to copy: mkdir \\?\Z:\dataset: Cannot create a file when that file already exists.
2024/06/23 00:34:11 ERROR : subfolder: Failed to update directory timestamp or metadata: chtimes \\?\Z:\dataset\copytest\subfolder: The system cannot find the file specified.
2024/06/23 00:34:11 ERROR : Attempt 3/3 failed with 4 errors and: failed to set directory modtime: chtimes \\?\Z:\dataset\copytest\subfolder: The system cannot find the file specified.
2024/06/23 00:34:11 INFO  :
Transferred:              0 B / 0 B, -, 0 B/s, ETA -
Errors:                 4 (retrying may help)
Elapsed time:         0.1s

Robocopy

Copying to root works:

> robocopy D:\copytest Z:\copytest /MIR

-------------------------------------------------------------------------------
   ROBOCOPY     ::     Robust File Copy for Windows
-------------------------------------------------------------------------------

  Started: Sunday, June 23, 2024 00:47:06
   Source : D:\copytest\
     Dest = Z:\copytest\

    Files : *.*

  Options: *.* /S /E /DCOPY:DA /COPY:DAT /PURGE /MIR /R:1000000 /W:30

------------------------------------------------------------------------------

                           1    D:\copytest\
                           1    D:\copytest\subfolder\

------------------------------------------------------------------------------

           Total    Copied    Skipped    Mismatch    FAILED    Extras
Dirs        :         2         0         2         0         0         0
Files       :         2         0         2         0         0         0
Bytes       :         0         0         0         0         0         0
Times       :   0:00:00   0:00:00                       0:00:00   0:00:00
   Ended: Sunday, June 23, 2024 00:47:06

Copying to dataset fails:

> robocopy D:\copytest Z:\dataset\copytest /MIR

-------------------------------------------------------------------------------
   ROBOCOPY     ::     Robust File Copy for Windows
-------------------------------------------------------------------------------

  Started: Sunday, June 23, 2024 00:46:05
   Source : D:\copytest\
     Dest = Z:\dataset\copytest\

    Files : *.*

  Options: *.* /S /E /DCOPY:DA /COPY:DAT /PURGE /MIR /R:1000000 /W:30

------------------------------------------------------------------------------

                           1    D:\copytest\
            New File                 0        file.txt
2024/06/23 00:46:05 ERROR 3 (0x00000003) Copying File D:\copytest\file.txt
The system cannot find the path specified.
thesn10 commented 3 months ago

I have just run FileSpy, and it seems like the cause is both rclone and robocopy use FASTIO_QUERY_OPEN which fails. Is FASTIO_QUERY_OPEN not implemented on zfs?

Robocopy image Rclone image

lundman commented 3 months ago

Hey, interesting but probably not the issue. All the FASTIO calls, if they fail, it will then go and do a full IRP call instead. There is a FASTIO_QUERY_OPEN but it can decide to fail it, if needed, and I think STATUS_REPARSE is one of those.

https://github.com/openzfsonwindows/openzfs/blob/development/module/os/windows/zfs/zfs_vnops_windows.c#L8189

lundman commented 3 months ago

Also when you FileSpy, you need to add Z: as you have, but also add path of the reparse point Z:/subfolder so you can see requests sent there.

thesn10 commented 3 months ago

Also when you FileSpy, you need to add Z: as you have, but also add path of the reparse point Z:/subfolder so you can see requests sent there.

Done. Z:\dataset reparses to Volume{1c14792a-a278-3dbe-a5ab-9e78981503d2} i think image

lundman commented 3 months ago

Yeah that is it. FILE_OVERWRITE_IF and PATH_NOT_FOUND hmm.

FILE_OVERWRITE_IF: If the file does not exist, it creates a new file.

So that seems wrong, we should create the file, right

thesn10 commented 3 months ago

@lundman Yeah true, but also in line 21, IRP_MJ_CREATE it seems to return STATUS_OBJECT_NAME_NOT_FOUND and there is no FILE_OVERWRITE_IF. Is that correct behavior?

lundman commented 3 months ago

Line 21 seem ok, it's checking if it is already there, to see if it needs updating, overwrite etc. But (I am guessing) the file does not exist, so the error is expected, and it gets ready to copy.

thesn10 commented 3 months ago

Rclone is even more weird, there seems to be buffer overflows and collisions image

lundman commented 3 months ago

Nah that is fine, they call the function with a 0-size buffer, we reply with BUFFER_OVERFLOW and how much space it would need, they should call it again with bigger buffer.

lundman commented 3 months ago

OK, so ZFS is on E: and E:\dataset. Created NTFS vxhd on F: and F:\dataset

NTFS

rclone.exe FASTIO_QUERY_OPEN \Device\HarddiskVolume10\README.md STATUS_OBJECT_NAME_NOT_FOUND FileNetworkOpenInformation CreateTime: 0 LastAccTime: 0 LastWrtTime: 0 ChangeTime: 0 AllocationSize: 00000000-00000000 EndOfFile: 00000000-00000000 Attrib: 0

ZFS

rclone.exe FASTIO_QUERY_OPEN E:\dataset\README.md FAILURE  
rclone.exe IRP_MJ_CREATE E:\dataset\README.md STATUS_REPARSE FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 
rclone.exe FASTIO_QUERY_OPEN \README.md FAILURE  
rclone.exe IRP_MJ_CREATE \README.md STATUS_OBJECT_NAME_NOT_FOUND FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0

So interestingly, NTFS FASTIO_QUERY_OPEN says SUCCESS with error STATUS_OBJECT_NAME_NOT_FOUND inside it. ZFS says FAILURE, then it tries the full IRP way, and we eventually say STATUS_OBJECT_NAME_NOT_FOUND.

Should be equivalent.

Differs here:

NTFS:

rclone.exe IRP_MJ_CREATE F:\dataset STATUS_REPARSE FILE_OPEN CreOpts: 00004020 Access: 00100080 Share:  0 Attrib: 0 
rclone.exe IRP_MJ_CREATE \Device\HarddiskVolume10 STATUS_SUCCESS FILE_OPEN CreOpts: 00004021 Access: 00100080 Share:  0 Attrib: 0 Result: FILE_OPENED 
rclone.exe IRP_MJ_QUERY_VOLUME_INFORMATION \Device\HarddiskVolume10 STATUS_BUFFER_OVERFLOW FileFsVolumeInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION \Device\HarddiskVolume10 STATUS_SUCCESS FileAllInformation  CreateTime: 0045004C-00490046 LastAccTime: 01DAC85C-01B88F0F LastWrtTime: 01DAC85C-CFC20C87 ChangeTime: 01DAC85C-CFC20C87 Attrib: 0593AAC0  AllocationSize: 00000016-400589C8 EndOfFile: 00000000-00001000 NumberOfLinks: 0 DeletePending: TRUE  IdxNum: 00000001-00000000  EaSize: 40058A00  AccFlags: 00050000

ZFS:

rclone.exe IRP_MJ_CREATE E:\dataset STATUS_REPARSE FILE_OPEN CreOpts: 00004020 Access: 00100080 Share:  0 Attrib: 0 
rclone.exe FASTIO_QUERY_OPEN E: FAILURE  
rclone.exe IRP_MJ_CREATE E: STATUS_SUCCESS FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 Result: FILE_OPENED 
rclone.exe FASTIO_QUERY_NETWORK_OPEN_INFO E: STATUS_SUCCESS  
rclone.exe IRP_MJ_CLEANUP E: STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E: STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_OBJECT_NAME_COLLISION FILE_CREATE CreOpts: 00204021 Access: 00100001 Share:  00000003 Attrib: 00000080

It is peculiar it tries to create E:\dataset

lundman commented 3 months ago

Whatever decisions were made, NTFS will

rclone.exe IRP_MJ_CREATE F:\dataset\README.md.wupaweh2.partial STATUS_REPARSE FILE_OVERWRITE_IF CreOpts: 00004020 Access: 00120196 Share:  00000007 Attrib: 00000080

and because it is FILE_OVERWRITE_IF it will create the file.

ZFS

rclone.exe IRP_MJ_CREATE E:\dataset\README.md.xoqudeq5.partial STATUS_REPARSE FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0

we only ever get FILE_OPEN so it never creates the file.

thesn10 commented 3 months ago

So this is a bug on rclones side because they do not handle the reparse correctly and tries to create E:\dataset?

thesn10 commented 3 months ago

@lundman Take a look at this part of the rclone source code: https://github.com/rclone/rclone/blob/754e53dbcc87425ff88dbf95d1b516139c58df0c/lib/file/mkdir_windows.go#L19

I think The os.Stat call most likely fails with error and then it tries the "Slow path" by creating every parent directory.

My theory is that it cannot parse the result of the ZFS drivers FASTIO_QUERY_NETWORK_OPEN_INFO response, which causes os.Stat call to fail, triggering the "Slow path" which tries to create the parent directory, which fails. What do you think, does it make sense?

lundman commented 3 months ago

Nah, it's ZFS fault, we do something wrong. Just need to figure out why.

Yeah I'll check that, change how FASTIO_QUERY_NETWORK_OPEN_INFO return errors.

lundman commented 3 months ago

OK note to self:

Disable FastIO for ntfs so we can more easily compare FileSpy trace outputs


Break into Debugger
0: kd> .reload
0: kd> ? Ntfs!NtfsFastIoDispatch
Evaluate expression: -8765036533424 = fffff807`3b1c6860

0: kd> dt _FAST_IO_DISPATCH fffff807`3b1c6860
AppXDeploymentClient!_FAST_IO_DISPATCH
   +0x000 SizeOfFastIoDispatch : 0xf0
   +0x008 FastIoCheckIfPossible : 0xfffff807`3b36fff0     unsigned char  Ntfs!NtfsFastIoCheckIfPossible+0
   +0x010 FastIoRead       : 0xfffff807`3b24a310     unsigned char  Ntfs!NtfsCopyReadA+0
   +0x018 FastIoWrite      : 0xfffff807`3b249a60     unsigned char  Ntfs!NtfsCopyWriteA+0
   +0x020 FastIoQueryBasicInfo : 0xfffff807`3b265b30     unsigned char  Ntfs!NtfsFastQueryBasicInfo+0
   +0x028 FastIoQueryStandardInfo : 0xfffff807`3b2647f0     unsigned char  Ntfs!NtfsFastQueryStdInfo+0
   +0x030 FastIoLock       : 0xfffff807`3b265fd0     unsigned char  Ntfs!NtfsFastLock+0
   +0x038 FastIoUnlockSingle : 0xfffff807`3b266a10     unsigned char  Ntfs!NtfsFastUnlockSingle+0
   +0x040 FastIoUnlockAll  : 0xfffff807`3b36e1b0     unsigned char  Ntfs!NtfsFastUnlockAll+0
   +0x048 FastIoUnlockAllByKey : 0xfffff807`3b36e460     unsigned char  Ntfs!NtfsFastUnlockAllByKey+0
   +0x050 FastIoDeviceControl : (null) 
   +0x058 AcquireFileForNtCreateSection : (null) 
   +0x060 ReleaseFileForNtCreateSection : 0xfffff807`3b141060     void  Ntfs!NtfsReleaseForCreateSection+0
   +0x068 FastIoDetachDevice : (null) 
   +0x070 FastIoQueryNetworkOpenInfo : 0xfffff807`3b255dc0     unsigned char  Ntfs!NtfsFastQueryNetworkOpenInfo+0
   +0x078 AcquireForModWrite : 0xfffff807`3b137470     long  Ntfs!NtfsAcquireFileForModWrite+0
   +0x080 MdlRead          : 0xfffff807`3b246b50     unsigned char  Ntfs!NtfsMdlReadA+0
   +0x088 MdlReadComplete  : 0xfffff807`38d735a0     unsigned char  nt!FsRtlMdlReadCompleteDev+0
   +0x090 PrepareMdlWrite  : 0xfffff807`3b276270     unsigned char  Ntfs!NtfsPrepareMdlWriteA+0
   +0x098 MdlWriteComplete : 0xfffff807`3920a4e0     unsigned char  nt!FsRtlMdlWriteCompleteDev+0
   +0x0a0 FastIoReadCompressed : (null) 
   +0x0a8 FastIoWriteCompressed : (null) 
   +0x0b0 MdlReadCompleteCompressed : (null) 
   +0x0b8 MdlWriteCompleteCompressed : (null) 
   +0x0c0 FastIoQueryOpen  : 0xfffff807`3b1fa500     unsigned char  Ntfs!NtfsNetworkOpenCreate+0
   +0x0c8 ReleaseForModWrite : 0xfffff807`3b142880     long  Ntfs!NtfsReleaseFileForModWrite+0
   +0x0d0 AcquireForCcFlush : 0xfffff807`3b137060     long  Ntfs!NtfsAcquireFileForCcFlush+0
   +0x0d8 ReleaseForCcFlush : 0xfffff807`3b141a90     long  Ntfs!NtfsReleaseFileForCcFlush+0

00 out the dispatchers for FastIoQueryNetworkOpenInfo and FastIoQueryOpen  

resume VM.

Create and mount NTFS on E: and E:\dataset, rclone copy README.md E:\dataset -v

Trace

==> ntfs-nofastio2.txt <==
 rocess Request Path Status More info
rclone.exe FASTIO_QUERY_OPEN E:\dataset FAILURE  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 Result: FILE_OPENED 
rclone.exe FASTIO_QUERY_NETWORK_OPEN_INFO E:\dataset FAILURE  
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileNetworkOpenInformation CreateTime: 01DAC912-D2189F1F LastAccTime: 01DAC912-D71638B8 LastWrtTime: 01DAC912-D2189F1F ChangeTime: 01DAC912-D8EB3C05 AllocationSize: 00000000-00000000 EndOfFile: 00000000-00000000 Attrib: 00000410 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204020 Access: 00100080 Share:  0 Attrib: 0 Result: FILE_OPENED 
rclone.exe IRP_MJ_QUERY_VOLUME_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileFsVolumeInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileAllInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileAttributeTagInformation 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E:\dataset STATUS_SUCCESS  
rclone.exe FASTIO_QUERY_OPEN E:\dataset\README.md FAILURE  
rclone.exe IRP_MJ_CREATE E:\dataset\README.md STATUS_REPARSE FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 
rclone.exe FASTIO_QUERY_OPEN \Device\HarddiskVolume8\README.md FAILURE  
rclone.exe IRP_MJ_CREATE \Device\HarddiskVolume8\README.md STATUS_OBJECT_NAME_NOT_FOUND FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 
rclone.exe IRP_MJ_CREATE E:\dataset\README.md STATUS_REPARSE FILE_OPEN CreOpts: 00204020 Access: 00100080 Share:  0 Attrib: 0 
rclone.exe IRP_MJ_CREATE \Device\HarddiskVolume8\README.md STATUS_OBJECT_NAME_NOT_FOUND FILE_OPEN CreOpts: 00204020 Access: 00100080 Share:  0 Attrib: 0 
rclone.exe FASTIO_QUERY_OPEN E:\dataset FAILURE  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 Result: FILE_OPENED 
rclone.exe FASTIO_QUERY_NETWORK_OPEN_INFO E:\dataset FAILURE  
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileNetworkOpenInformation CreateTime: 01DAC912-D2189F1F LastAccTime: 01DAC912-D71638B8 LastWrtTime: 01DAC912-D2189F1F ChangeTime: 01DAC912-D8EB3C05 AllocationSize: 00000000-00000000 EndOfFile: 00000000-00000000 Attrib: 00000410 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204020 Access: 00100080 Share:  0 Attrib: 0 Result: FILE_OPENED 
rclone.exe IRP_MJ_QUERY_VOLUME_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileFsVolumeInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileAllInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileAttributeTagInformation 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_REPARSE FILE_OPEN CreOpts: 00004020 Access: 00100080 Share:  0 Attrib: 0 
rclone.exe IRP_MJ_CREATE \Device\HarddiskVolume8 STATUS_SUCCESS FILE_OPEN CreOpts: 00004021 Access: 00100080 Share:  0 Attrib: 0 Result: FILE_OPENED 
rclone.exe IRP_MJ_QUERY_VOLUME_INFORMATION \Device\HarddiskVolume8 STATUS_BUFFER_OVERFLOW FileFsVolumeInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION \Device\HarddiskVolume8 STATUS_SUCCESS FileAllInformation  CreateTime: 0045004C-00490046 LastAccTime: 01DAC912-D8CE0527 LastWrtTime: 01DAC912-D8CE0527 ChangeTime: 01DAC912-D8CE0527 Attrib: 00547830  AllocationSize: 00000016-400589C8 EndOfFile: 00000000-00001000 NumberOfLinks: 0 DeletePending: TRUE  IdxNum: 00000001-00000000  EaSize: 40058A00  AccFlags: 00050000 
rclone.exe IRP_MJ_QUERY_INFORMATION \Device\HarddiskVolume8 STATUS_SUCCESS FileAttributeTagInformation 
rclone.exe IRP_MJ_CLEANUP \Device\HarddiskVolume8 STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE \Device\HarddiskVolume8 STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset\README.md.xepuheh7.partial STATUS_REPARSE FILE_OVERWRITE_IF CreOpts: 00004020 Access: 00120196 Share:  00000007 Attrib: 00000080 
rclone.exe IRP_MJ_CREATE \Device\HarddiskVolume8\README.md.xepuheh7.partial STATUS_SUCCESS FILE_OVERWRITE_IF CreOpts: 00004020 Access: 00120196 Share:  00000007 Attrib: 00000080 Result: FILE_CREATED 
rclone.exe IRP_MJ_QUERY_VOLUME_INFORMATION \Device\HarddiskVolume8\README.md.xepuheh7.partial STATUS_SUCCESS FileFsSizeInformation TotalClusters: 7EDFF AvailClusters: 7DE1A SectorsPerClus: 8 BytesPerSect: 200 
rclone.exe IRP_MJ_SET_INFORMATION \Device\HarddiskVolume8\README.md.xepuheh7.partial STATUS_SUCCESS FileAllocationInformation AllocationSize: 00000000-00001000
lundman commented 3 months ago

Take out same functions from ZFS

Create pool on E: and lower dataset E:\dataset rclone copy README.md E:\dataset -v

Trace

==> zfs-nofastio2.txt <==
 rocess Request Path Status More info
rclone.exe FASTIO_QUERY_OPEN E:\dataset FAILURE  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 Result: FILE_OPENED 
rclone.exe FASTIO_QUERY_NETWORK_OPEN_INFO E:\dataset FAILURE  
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileNetworkOpenInformation CreateTime: 01DAC914-95EAD7B4 LastAccTime: 01DAC914-95EAD7B4 LastWrtTime: 01DAC914-95EAD7B4 ChangeTime: 01DAC914-95EAD7B4 AllocationSize: 00000000-00000000 EndOfFile: 00000000-00000000 Attrib: 00000410 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204020 Access: 00100080 Share:  0 Attrib: 0 Result: FILE_OPENED 
rclone.exe IRP_MJ_QUERY_VOLUME_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileFsVolumeInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileAllInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileAttributeTagInformation 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E:\dataset STATUS_SUCCESS  
rclone.exe FASTIO_QUERY_OPEN E:\dataset\README.md FAILURE  
rclone.exe IRP_MJ_CREATE E:\dataset\README.md STATUS_REPARSE FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 
rclone.exe FASTIO_QUERY_OPEN \README.md FAILURE  
rclone.exe IRP_MJ_CREATE \README.md STATUS_OBJECT_NAME_NOT_FOUND FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 
rclone.exe IRP_MJ_CREATE E:\dataset\README.md STATUS_REPARSE FILE_OPEN CreOpts: 00204020 Access: 00100080 Share:  0 Attrib: 0 
rclone.exe IRP_MJ_CREATE \README.md STATUS_OBJECT_NAME_NOT_FOUND FILE_OPEN CreOpts: 00204020 Access: 00100080 Share:  0 Attrib: 0 
rclone.exe FASTIO_QUERY_OPEN E:\dataset FAILURE  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 Result: FILE_OPENED 
rclone.exe FASTIO_QUERY_NETWORK_OPEN_INFO E:\dataset FAILURE  
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileNetworkOpenInformation CreateTime: 01DAC914-95EAD7B4 LastAccTime: 01DAC914-95EAD7B4 LastWrtTime: 01DAC914-95EAD7B4 ChangeTime: 01DAC914-95EAD7B4 AllocationSize: 00000000-00000000 EndOfFile: 00000000-00000000 Attrib: 00000410 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204020 Access: 00100080 Share:  0 Attrib: 0 Result: FILE_OPENED 
rclone.exe IRP_MJ_QUERY_VOLUME_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileFsVolumeInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileAllInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileAttributeTagInformation 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_REPARSE FILE_OPEN CreOpts: 00004020 Access: 00100080 Share:  0 Attrib: 0 
rclone.exe FASTIO_QUERY_OPEN E: FAILURE  
rclone.exe IRP_MJ_CREATE E: STATUS_SUCCESS FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 Result: FILE_OPENED 
rclone.exe FASTIO_QUERY_NETWORK_OPEN_INFO E: FAILURE  
rclone.exe IRP_MJ_QUERY_INFORMATION E: STATUS_SUCCESS FileNetworkOpenInformation CreateTime: 01DAC914-7F6EEE3E LastAccTime: 01DAC914-7F6EEE3E LastWrtTime: 01DAC914-966E6BD3 ChangeTime: 01DAC914-966E6BD3 AllocationSize: 00000000-00000000 EndOfFile: 00000000-00000000 Attrib: 00000010 
rclone.exe IRP_MJ_CLEANUP E: STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E: STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_OBJECT_NAME_COLLISION FILE_CREATE CreOpts: 00204021 Access: 00100001 Share:  00000003 Attrib: 00000080 
rclone.exe FASTIO_QUERY_OPEN E:\dataset FAILURE  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204000 Access: 00000080 Share:  00000007 Attrib: 0 Result: FILE_OPENED 
rclone.exe FASTIO_QUERY_NETWORK_OPEN_INFO E:\dataset FAILURE  
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileNetworkOpenInformation CreateTime: 01DAC914-95EAD7B4 LastAccTime: 01DAC914-95EAD7B4 LastWrtTime: 01DAC914-95EAD7B4 ChangeTime: 01DAC914-95EAD7B4 AllocationSize: 00000000-00000000 EndOfFile: 00000000-00000000 Attrib: 00000410 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CLOSE E:\dataset STATUS_SUCCESS  
rclone.exe IRP_MJ_CREATE E:\dataset STATUS_SUCCESS FILE_OPEN CreOpts: 00204020 Access: 00100080 Share:  0 Attrib: 0 Result: FILE_OPENED 
rclone.exe IRP_MJ_QUERY_VOLUME_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileFsVolumeInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_BUFFER_OVERFLOW FileAllInformation 
rclone.exe IRP_MJ_QUERY_INFORMATION E:\dataset STATUS_SUCCESS FileAttributeTagInformation 
rclone.exe IRP_MJ_CLEANUP E:\dataset STATUS_SUCCESS
lundman commented 3 months ago

Compare the two

image

lundman commented 3 months ago

First real difference is that NTFS gets the symlink name \Device\HarddiskVolume8 from somewhere that it prepends to \README.md. ZFS will just get \README.md.

Makes me wonder where that comes from, when it gets STATUS_REPARSE or does it possibly ask MountMgr?

thesn10 commented 3 months ago

First real difference is that NTFS gets the symlink name \Device\HarddiskVolume8 from somewhere that it prepends to \README.md. ZFS will just get \README.md.

Makes me wonder where that comes from, when it gets STATUS_REPARSE or does it possibly ask MountMgr?

Hmm, on my pc, there is no real difference and ZFS will also return a device path in STATUS_REPARSE:

ZFS returns \Device\Volume{1c14792a-a278-3dbe-a5ab-9e78981503d2} NTFS returns \Device\HarddiskVolume8

Looks ok to me So i dont think this is the cause Allthough it's kinda weird that it returns no device path on your pc, but on mine it does

lundman commented 3 months ago

I'm currently trying to correct the "half mounted" setup we get with sub-mounts, in that they don't show properly in mountvol like ntfs does.

I have exhausted chatgpt support, trying here next: https://community.osr.com/t/mountmgr-reparsepoint-mount/58862

lundman commented 2 months ago

Does anyone happen to know if win-btrfs, or dokan, (both sources on GH - or any other GH program) when mounted on a volume (f.e.x E:) - bonus as a reparse point (E:\dataset) - will show in the output of mountvol and disk part; list volume ?

Starting to think chatgpt doesn't know how to do the mounts either, some of the suggestions are starting to sound weird, like animal sacrifice etc.

lundman commented 2 months ago

Does anyone happen to know if win-btrfs, or dokan, (both sources on GH - or any other GH program) when mounted on a volume (f.e.x E:) - bonus as a reparse point (E:\dataset) - will show in the output of mountvol and disk part; list volume ?

Starting to think chatgpt doesn't know how to do the mounts either, some of the suggestions are starting to sound weird, like animal sacrifice etc.

sskras commented 2 months ago

trying here next: https://community.osr.com/t/mountmgr-reparsepoint-mount/58862

Did you try mounting it from userland, the manual way?

> mountvol E:\dataset \??\Volume{df46d39b-2857-11ef-82bd-58961d57db67}

Does anyone happen to know if win-btrfs, or dokan, [...] when mounted on a volume [...] will show in the output of mountvol and disk part; list volume ?

For me at least Winbtrfs does. I have a ~ 38 GiB FS mounted as BTRFS (disk 1, partition 5):

image

... and it's presented by diskpart, it's Volume 2 here:

C:\Windows\system32> echo LIST VOL | diskpart

Microsoft DiskPart version 10.0.19041.964

Copyright (C) Microsoft Corporation.
On computer: DESKTOP-O7JE7JE

DISKPART>
  Volume ###  Ltr  Label        Fs     Type        Size     Status     Info
  ----------  ---  -----------  -----  ----------  -------  ---------  --------
  Volume 0     D   New Volume   NTFS   Partition    931 GB  Healthy
  Volume 1     C   pagrindinis  NTFS   Partition    237 GB  Healthy    Boot
  Volume 2                             Partition     38 GB  Healthy
  Volume 3         NTFS Volume  NTFS   Partition    188 GB  Healthy
    D:\Another-volume\
  Volume 4                      FAT32  Partition    100 MB  Healthy    System
  Volume 5                      NTFS   Partition    505 MB  Healthy    Hidden

DISKPART>

... but the Ltr and Fs fields are absent here.

C:\Windows\system32> (echo SELECT DISK 1 && echo LIST PART) | diskpart

Microsoft DiskPart version 10.0.19041.964

Copyright (C) Microsoft Corporation.
On computer: DESKTOP-O7JE7JE

DISKPART>
Disk 1 is now the selected disk.

DISKPART>
  Partition ###  Type              Size     Offset
  -------------  ----------------  -------  -------
  Partition 1    System             100 MB  1024 KB
  Partition 2    Reserved            16 MB   101 MB
  Partition 3    Primary            237 GB   117 MB
  Partition 4    Recovery           505 MB   237 GB
  Partition 5    Primary             38 GB   238 GB
  Partition 6    Primary            188 GB   277 GB

DISKPART>
C:\Windows\system32>

Also mountvol shows it, the \\?\Volume{0869fa25-bd66-7074-6498-7f4d08d64db0}\:

C:\Windows\system32> mountvol
  <...>

Possible values for VolumeName along with current mount points are:

    \\?\Volume{8317bf2b-9709-4f92-be0f-6f3f3dd83aa4}\
        D:\

    \\?\Volume{3b7e9709-77dc-4d88-ab05-e923b26d95a3}\
        C:\

    \\?\Volume{878041e1-48c2-484b-bcc1-507b0ff19c4c}\
        *** NO MOUNT POINTS ***

    \\?\Volume{c27eb7f0-3284-43ef-9f12-c3405d3bcd64}\
        D:\Another-volume\

    \\?\Volume{5feefb5c-468a-4da8-9fcc-0dfba19dcab8}\
        *** NO MOUNT POINTS ***

    \\?\Volume{0869fa25-bd66-7074-6498-7f4d08d64db0}\
        E:\

C:\Windows\system32>
lundman commented 2 months ago

Looks like mountvol shows it ok, but I would argue diskpart does not. If you create a VHD and mount it, it will show drive letter in diskpart output. But perhaps I am striving for perfection when it isnt needed. If we are happy with btrfs level of support, I could stay there as well.

But I do need to get mountvol to show E:\dataset though, VHD will do that.

sskras commented 2 months ago

Looks like mountvol shows it ok, but I would argue diskpart does not. If you create a VHD and mount it, it will show drive letter in diskpart output.

Fair enough, Jorgen! I just wanted to state that the line is present. Now I see that even I have wiped out the partition, the line would stay the same. Sorry for not thinking about that earlier.

But perhaps I am striving for perfection when it isnt needed. If we are happy with btrfs level of support, I could stay there as well.

But I do need to get mountvol to show E:\dataset though, VHD will do that.

Sure. Soon after your comment I remembered the Ext4FSD project. I installed the version v0.71, created an additional additional 1 GiB long partition 7 on the same disk:

C:\Windows\system32> (echo SELECT DISK 1 && echo LIST PART) | diskpart

Microsoft DiskPart version 10.0.19041.964

Copyright (C) Microsoft Corporation.
On computer: DESKTOP-O7JE7JE

DISKPART>
Disk 1 is now the selected disk.

DISKPART>
  Partition ###  Type              Size     Offset
  -------------  ----------------  -------  -------
  Partition 1    System             100 MB  1024 KB
  Partition 2    Reserved            16 MB   101 MB
  Partition 3    Primary            237 GB   117 MB
  Partition 4    Recovery           505 MB   237 GB
  Partition 5    Primary             38 GB   238 GB
  Partition 6    Primary           4120 MB   277 GB
  Partition 7    Primary           1024 MB   281 GB

DISKPART>

Ext4FSD seems to include no tool to make a new FS. So I had to elevate my MSYS2 terminal and create the FS off-site.

It went somewhat along these lines <...>
```sh # dd if=/dev/zero of=/dev/sdb7 # dd if=/dev/sdb7 | pv | ssh -C omn "cat > w10-sdb7.img" # ssh omn $ ls -l w10-sdb7.img $ sudo losetup -f w10-sdb7.img $ sudo losetup -l $ mkfs.ext4 /dev/loop0 $ sudo losetup -d /dev/loop0 $ exit # ssh -C omn "cat w10-sdb7.img" | pv | dd of=/dev/sdb7 ```

Then I toyed with Ext2 Volume Manager a bit:

image

... and found out that its' mountpoint management offers only letter-mounts:

image

So I went back to the Disk Management console & assigned the non-letter mount point by hand: image

And you know, with Ext4FSD this worked!

image

Now diskpart sees the volume:

C:\Windows\system32> echo LIST VOL | diskpart

Microsoft DiskPart version 10.0.19041.964

Copyright (C) Microsoft Corporation.
On computer: DESKTOP-O7JE7JE

DISKPART>
  Volume ###  Ltr  Label        Fs     Type        Size     Status     Info
  ----------  ---  -----------  -----  ----------  -------  ---------  --------
  Volume 0     D   New Volume   NTFS   Partition    931 GB  Healthy
  Volume 1     C   pagrindinis  NTFS   Partition    237 GB  Healthy    Boot
  Volume 2                             Partition     38 GB  Healthy
  Volume 3         NTFS Volume  NTFS   Partition   4120 MB  Healthy
  Volume 4         An EXT4 vol  EXT4   Partition   1024 MB  Healthy
    D:\Another-volume\
  Volume 5                      FAT32  Partition    100 MB  Healthy    System
  Volume 6                      NTFS   Partition    505 MB  Healthy    Hidden

DISKPART>

And mounvol sees it too:

C:\Windows\system32> mountvol
  <...>

Possible values for VolumeName along with current mount points are:

    \\?\Volume{8317bf2b-9709-4f92-be0f-6f3f3dd83aa4}\
        D:\

    \\?\Volume{3b7e9709-77dc-4d88-ab05-e923b26d95a3}\
        C:\

    \\?\Volume{878041e1-48c2-484b-bcc1-507b0ff19c4c}\
        *** NO MOUNT POINTS ***

    \\?\Volume{c27eb7f0-3284-43ef-9f12-c3405d3bcd64}\
        *** NO MOUNT POINTS ***

    \\?\Volume{776c48ee-fe39-4fa4-8e7c-9d07a3a0d176}\
        D:\Another-volume\

    \\?\Volume{5feefb5c-468a-4da8-9fcc-0dfba19dcab8}\
        *** NO MOUNT POINTS ***

    \\?\Volume{0869fa25-bd66-7074-6498-7f4d08d64db0}\
        E:\

C:\Windows\system32>

Later I unmounted the volume and retried the same using mountvol. It also worked:

C:\Windows\system32> mountvol D:\Another-volume \\?\Volume{776c48ee-fe39-4fa4-8e7c-9d07a3a0d176}
C:\Windows\system32>

HTH

EDIT: Also please note, that the FSD code is license under GNU GPLv2. For the rest of the project (Ext2Srv, Ext2Mgr, Setup) I found no clear indication of the code's license.

This may mean that for staying legally clear you should take breaks between reading the code and rewriting it on your own (to avoid legal uncertainties / clashes of CDDL against GPLv2:)

sskras commented 2 months ago

PS. The Ext2 Volume Manager includes nice details about IRP usage, just press F8:

image

lundman commented 2 months ago

Ah ok, good to see it can/should work. I have something I want to try out in code today first, getting a clearer picture how it hangs together

lundman commented 3 weeks ago

OK should re-test this after 2.2.6rc1

$ ./rclone.exe copy README.md /e/dataset/README.md -v
2024/09/05 14:26:13 INFO  : README.md: Copied (new)
2024/09/05 14:26:13 INFO  :
Transferred:        1.990 KiB / 1.990 KiB, 100%, 0 B/s, ETA -
Transferred:            1 / 1, 100%
Elapsed time:         1.1s