Windows Server 2K16 - cannot kill rclone process after S3 WinFSP mount failed

[mrlitsta]

What is the problem you are having with rclone?

I'm using rclone to mount an S3-compatible drive to a windows server. After successfully mounting and testing an "other" type s3 bucket in our network, I tried to mount an actual AWS S3 bucket to the machine from a powershell console. Explorer hung with a spinning wheel, so I tried to kill the rclone command. Upon hitting Ctrl-C, the console prints this message:

The service rclone has been stopped.

but rclone never exits, the drive letter is still mounted by windows, and I cannot kill the rclone process.

I discovered later that our border firewall is likely blocking the traffic to the S3 endpoint, but I'm surprised that I can't exit/kill the process.

I'd really like to not have to reboot this server for troubleshooting, if at all possible.

More detail at the end

Run the command 'rclone version' and share the full output of the command.

PS C:\Users\adm.t1.12514\src\s3bin\rclone> .\rclone version
rclone v1.62.2

• os/version: Microsoft Windows Server 2016 Standard 1607 (64 bit)
• os/kernel: 10.0.14393.5850 Build 14393.5850.5850 (x86_64)
• os/type: windows
• os/arch: amd64
• go/version: go1.20.2
• go/linking: static
• go/tags: cmount

winfsp-2.0.23075

Which cloud storage system are you using? (eg Google Drive)

Amazon S3

The command you were trying to run (eg rclone copy /tmp remote:tmp)

PS C:\Users\MYUSER\src\s3bin\rclone> .\rclone.exe mount mys3usw2:MYBUCKET s: --volname=\\mount\sql_remote -vv -o FileSecurity="D:P(A;;FA;;;WD)" --no-check-certificate --config rclone_remote.conf  --cache-dir F:\MYPATH\rclone_vfs_cache_remote --vfs-cache-mode full --vfs-read-ahead 512m --buffer-size 512m

The rclone config contents with secrets removed.

Yes, I know I did a very lazy thing by not using the actual type=S3 config and trying to change a single line to test. I also discovered later that I needed to add region= to actually make this work properly

[mys3usw2]
type = s3
provider = Other
access_key_id = AKIAMYKEY
secret_access_key = MYSECRETKEY
endpoint = s3.us-west-2.amazonaws.com

A log from the command with the -vv flag

2023/05/01 16:58:47 DEBUG : rclone: Version "v1.62.2" starting with parameters ["C:\\Users\\MYUSER\\src\\s3bin\\rclone\\rclone.exe" "mount" "mys3usw2:MYBUCKET" "s:" "--volname=\\\\mount\\sql_remote" "-vv" "-o" "FileSecurity
=D:P(A;;FA;;;WD)" "--no-check-certificate" "--config" "rclone_remote.conf" "--cache-dir" "F:\\MYPATH\\data\\rclone_vfs_cache_remote" "--vfs-cache-mode" "full" "--vfs-read-ahead" "512m" "--buffer-size" "512m"]
2023/05/01 16:58:47 DEBUG : Creating backend with remote "mys3usw2:MYBUCKET"
2023/05/01 16:58:47 DEBUG : Using config file from "C:\\Users\\MYUSER\\src\\s3bin\\rclone\\rclone_remote.conf"
2023/05/01 16:58:47 DEBUG : Resolving service "s3" region "us-east-1"
2023/05/01 16:58:47 INFO  : S3 bucket MYBUCKET: poll-interval is not supported by this remote
2023/05/01 16:58:47 DEBUG : vfs cache: root is "F:\\MYPATH\\data\\rclone_vfs_cache_remote"
2023/05/01 16:58:47 DEBUG : vfs cache: data root is "\\\\?\\F:\\MYPATH\\data\\rclone_vfs_cache_remote\\vfs\\mys3us
w2\\MYBUCKET"
2023/05/01 16:58:47 DEBUG : vfs cache: metadata root is "\\\\?\\F:\\MYPATH\\data\\rclone_vfs_cache_remote\\vfsMeta
\\mys3usw2\\MYBUCKET"
2023/05/01 16:58:47 DEBUG : Creating backend with remote "F:/MYPATH/data/rclone_vfs_cache_remote/vfs/mys3usw2/MYBUCKET"
2023/05/01 16:58:47 DEBUG : fs cache: renaming cache item "F:/MYPATH/data/rclone_vfs_cache_remote/vfs/mys3usw2/MYBUCKET" to be canonical "//?/F:/MYPATH/data/rclone_vfs_cache_remote/vfs/mys3usw2/MYBUCKET"
2023/05/01 16:58:47 DEBUG : Creating backend with remote "F:/MYPATH/data/rclone_vfs_cache_remote/vfsMeta/mys3usw2/MYBUCKET"
2023/05/01 16:58:47 DEBUG : fs cache: renaming cache item "F:/MYPATH/data/rclone_vfs_cache_remote/vfsMeta/mys3usw2/MYBUCKET" to be canonical "//?/F:/MYPATH/data/rclone_vfs_cache_remote/vfsMeta/mys3usw2/MYBUCKET"
2023/05/01 16:58:47 DEBUG : Forcing network mode due to network share (UNC) volume name
2023/05/01 16:58:47 DEBUG : Network mode mounting is enabled
2023/05/01 16:58:47 DEBUG : Mounting on "s:" ("\\mount\\sql_remote")
2023/05/01 16:58:47 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was
0)
2023/05/01 16:58:47 DEBUG : S3 bucket MYBUCKET: Mounting with options: ["-o" "attr_timeout=1" "-o" "uid=-1" "
-o" "gid=-1" "--FileSystemName=rclone" "--VolumePrefix=\\mount\\sql_remote" "-o" "FileSecurity=D:P(A;;FA;;;WD)"]
2023/05/01 16:58:47 DEBUG : S3 bucket MYBUCKET: Init:
2023/05/01 16:58:47 DEBUG : S3 bucket MYBUCKET: >Init:
2023/05/01 16:58:47 DEBUG : /: Statfs:
2023/05/01 16:58:47 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:27487
7906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2023/05/01 16:58:47 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:47 DEBUG : /: >Getattr: errc=0
2023/05/01 16:58:47 DEBUG : /: Readlink:
2023/05/01 16:58:47 DEBUG : /: >Readlink: linkPath="", errc=-40
2023/05/01 16:58:47 DEBUG : /: Getxattr: name="non-existant-a11ec902d22f4ec49003af15282d3b00"
2023/05/01 16:58:47 DEBUG : /: >Getxattr: errc=-40, value=""
The service rclone has been started.
2023/05/01 16:58:47 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:47 DEBUG : /: >Getattr: errc=0
2023/05/01 16:58:47 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:47 DEBUG : /: >Getattr: errc=0
2023/05/01 16:58:47 DEBUG : /: Opendir:
2023/05/01 16:58:47 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2023/05/01 16:58:47 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2023/05/01 16:58:47 DEBUG : /: >Opendir: errc=0, fh=0x0
2023/05/01 16:58:47 DEBUG : /Desktop.ini: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:48 DEBUG : /: >Getattr: errc=0
2023/05/01 16:58:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:48 DEBUG : /: >Getattr: errc=0
2023/05/01 16:58:48 DEBUG : /: Opendir:
2023/05/01 16:58:48 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2023/05/01 16:58:48 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:48 DEBUG : /: >Getattr: errc=0
2023/05/01 16:58:48 DEBUG : /: Opendir:
2023/05/01 16:58:48 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2023/05/01 16:58:54 DEBUG : /desktop.ini: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:54 DEBUG : /: >Getattr: errc=0
2023/05/01 16:58:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2023/05/01 16:58:54 DEBUG : /: >Getattr: errc=0
2023/05/01 16:58:54 DEBUG : /: Opendir:
2023/05/01 16:58:54 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
AFTER CTRL-C

The service rclone has been stopped.

Additional Details/Steps I've tried (apologies for being so verbose)

• is this an instance of 'unkillable processes' Unkillable Processes - Microsoft Community Hub

• When I realized that the process hadn't exited, I tried killing with taskmgr and got "The operation could not be completed: Access is denied" popup.

• next I tried killing the task in powershell

PS C:\Users\MYUSER\src\s3bin\rclone> taskkill /PID 15304
SUCCESS: Sent termination signal to the process with PID 15304.
PS C:\Users\MYUSER\src\s3bin\rclone> taskkill /PID 15304 /F
ERROR: The process with PID 15304 could not be terminated.
Reason: There is no running instance of the task.

• next I tried to look at the process

PS C:\Users\MYUSER\src\s3bin\rclone> get-process -id 15304

Handles  NPM(K)    PM(K)      WS(K)     CPU(s)     Id  SI ProcessName
-------  ------    -----      -----     ------     --  -- -----------
    197      25    36820      43324       0.44  15304   2 rclone

• After a few searches for similar messages, I came across this post: Windows rclone mount refuses pathname mount point; WinFsp issue? - #10 by asdffdsa and tried

PS C:\Users\MYUSER\src\s3bin\rclone> wmic logicaldisk list brief
DeviceID  DriveType  FreeSpace     ProviderName  Size          VolumeName
C:        3          130949373952                214220926976
D:        5
E:        3          25888030720                 107237801984 Installer
F:        3          4559601664                  8554217472    somedrive
S:        4
Z:        3          8490516480                  8554217472    someotherdrive


PS C:\Users\MYUSER\src\s3bin\rclone> net use S:
The network connection could not be found.

• then I tried killing using wmic

wmic:root\cli>process where name="rclone.exe" delete
Delete '\\DAL-ADB-STG-01\ROOT\CIMV2:Win32_Process.Handle="15304"' (Y/N/?)? y
Deleting instance \\DAL-ADB-STG-01\ROOT\CIMV2:Win32_Process.Handle="15304"
ERROR:
Description = Access denied

• checked endpoint, realized it was being blocked

Test-NetConnection -ComputerName s3.us-west-2.amazonaws.com -port 443
(hangs for a long time with)

 Test-NetConnection - 52.92.224.48:443
    Attempting TCP connect

    Waiting for response

• checked from another machine on another subnet with access

Test-NetConnection -ComputerName s3.us-west-2.amazonaws.com -port 443


ComputerName     : s3.us-west-2.amazonaws.com
RemoteAddress    : 3.5.77.157
RemotePort       : 443
InterfaceAlias   : Ethernet0 2
SourceAddress    : INTERNAL.IP.ADDR
TcpTestSucceeded : True

• after trying successfully from the allowed subnet, I tried an ls from the blocked subnet machine, this is what I get...eventually (it doesn't hang forever upon timing out)

PS C:\Users\MYUSER\src\s3bin\rclone> .\rclone.exe -vv --no-check-certificate --config rclone_remote_other.conf ls "mys3usw2://MYBUCKET"
2023/05/01 19:07:34 DEBUG : rclone: Version "v1.62.2" starting with parameters ["C:\\Users\\MYUSER\\src\\s3bin\\rclone\\rclone.exe" "-vv" "--no-check-certificate" "--config" "rclone_remote_other.conf" "ls"
 "mys3usw2://MYBUCKET"]
2023/05/01 19:07:34 DEBUG : Creating backend with remote "mys3usw2://MYBUCKET"
2023/05/01 19:07:34 DEBUG : Using config file from "C:\\Users\\MYUSER\\src\\s3bin\\rclone\\rclone_remote_other.conf"
2023/05/01 19:07:34 DEBUG : Resolving service "s3" region "us-west-2"
2023/05/01 19:07:34 DEBUG : fs cache: renaming cache item "mys3usw2://MYBUCKET" to be canonical "mys3usw2:MYBUCKET"
2023/05/01 19:19:08 DEBUG : pacer: low level retry 1/2 (error RequestError: send request failed
caused by: Get "https://s3.us-west-2.amazonaws.com/MYBUCKET?delimiter=&max-keys=1000&prefix=": dial tcp 52.92.149.120:443: i/o timeout)
2023/05/01 19:19:08 DEBUG : pacer: Rate limited, increasing sleep to 10ms
2023/05/01 19:30:58 DEBUG : pacer: low level retry 2/2 (error RequestError: send request failed
caused by: Get "https://s3.us-west-2.amazonaws.com/MYBUCKET?delimiter=&max-keys=1000&prefix=": dial tcp 52.92.211.136:443: i/o timeout)
2023/05/01 19:30:58 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2023/05/01 19:30:58 DEBUG : 2 go routines active
2023/05/01 19:30:58 Failed to ls: RequestError: send request failed
caused by: Get "https://s3.us-west-2.amazonaws.com/MYBUCKET?delimiter=&max-keys=1000&prefix=": dial tcp 52.92.211.136:443: i/o timeout

• finally, I looked at explorer, the s: was there, but on clicking it, I get this message

S:\ is not accessible.   The I/O operation has been aborted because of either a thread exit or an application request.

[ncw (Nick Craig-Wood)]

@mrlitsta

I discovered later that our border firewall is likely blocking the traffic to the S3 endpoint, but I'm surprised that I can't exit/kill the process.

You probably can't kill the rclone process while it is being used by the kernel. (I'm not a Windows expert - I'm extrapolating from my Linux experience here.)

If that is the case then it is waiting for timeouts most likely before returning errors to the kernel. It should happen eventually I would have thought.

I've not seen this in Windows before, but it happens regularly on my Linux box. Most of the time I can force umount (with fusermount -z -u /mnt/path). There may be an equivalent on Windows.

[mrlitsta]

Thanks for the response. I'm very not a windows expert either

At this point, it's been hung for 43 hours now, so it looks like kernel timeouts aren't working? Is there any other debugging information I can grab using Powershell/Process Explorer, etc. that might be useful?

So far, my searches on the forums indicate that the only thing that will kill an rclone mount in windows is Ctrl-C:

Rclone mount - progrmatic umount under windows

interesting, i had found a .exe named SendSignal.exe and that never worked for me. i will try your links. and yes, i already read that web.archive.org link but thanks for that anyway. thanks,

Safe way to unmount

I think this is answered here by the author of WinFSP The proper way to unmount a file system that uses WinFsp-FUSE is by sending it a Ctrl-C. On Windows this is done by calling GenerateConsoleCtrlEvent . On Cygwin you can also use kill or pkill to send it a SIGTERM , especially if you run it as a Cygwin daemon.

[ncw (Nick Craig-Wood)]

@mrlitsta

So far, my searches on the forums indicate that the only thing that will kill an rclone mount in windows is Ctrl-C:

It's worth a try.

Any advice you read for killing WinFSP should be good.