"./vfs.test -test.v -test.timeout 1h0m0s -remote TestSugarSync:Test -verbose" - Starting (try 4/5)
2025/09/13 08:34:15 DEBUG : Creating backend with remote "TestSugarSync:Test/rclone-test-zusosig3hazi"
2025/09/13 08:34:15 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/09/13 08:34:19 DEBUG : Creating backend with remote "/tmp/rclone1713112533"
=== RUN   TestDirHandleMethods
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:34:19 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:34:26 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:34:26 DEBUG : dir: Looking for writers
2025/09/13 08:34:26 DEBUG : Looking for writers
2025/09/13 08:34:26 DEBUG : dir: reading active writers
2025/09/13 08:34:26 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleMethods (11.02s)
=== RUN   TestDirHandleReaddir
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:34:30 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:34:44 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:34:44 DEBUG : dir/subdir: Looking for writers
2025/09/13 08:34:44 DEBUG : dir: Looking for writers
2025/09/13 08:34:44 DEBUG : file1: reading active writers
2025/09/13 08:34:44 DEBUG : file2: reading active writers
2025/09/13 08:34:44 DEBUG : subdir: reading active writers
2025/09/13 08:34:44 DEBUG : Looking for writers
2025/09/13 08:34:44 DEBUG : dir: reading active writers
2025/09/13 08:34:44 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleReaddir (20.90s)
=== RUN   TestDirHandleReaddirnames
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:34:51 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:34:57 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:34:57 DEBUG : dir: Looking for writers
2025/09/13 08:34:57 DEBUG : file1: reading active writers
2025/09/13 08:34:57 DEBUG : Looking for writers
2025/09/13 08:34:57 DEBUG : dir: reading active writers
2025/09/13 08:34:57 DEBUG : >WaitForWriters: 
--- PASS: TestDirHandleReaddirnames (10.56s)
=== RUN   TestDirMethods
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:35:01 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:35:07 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:35:07 DEBUG : dir: Looking for writers
2025/09/13 08:35:07 DEBUG : Looking for writers
2025/09/13 08:35:07 DEBUG : dir: reading active writers
2025/09/13 08:35:07 DEBUG : >WaitForWriters: 
--- PASS: TestDirMethods (9.67s)
=== RUN   TestDirForgetAll
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:35:11 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:35:17 DEBUG : dir: forgetting directory cache
2025/09/13 08:35:17 DEBUG : forgetting directory cache
2025/09/13 08:35:17 DEBUG : dir: forgetting directory cache
2025/09/13 08:35:17 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:35:17 DEBUG : Looking for writers
2025/09/13 08:35:17 DEBUG : >WaitForWriters: 
--- PASS: TestDirForgetAll (10.43s)
=== RUN   TestDirForgetPath
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:35:22 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:35:28 DEBUG : ForgetPath: relativePath="dir/notfound", type=1
2025/09/13 08:35:28 DEBUG : dir: invalidating directory cache
2025/09/13 08:35:28 DEBUG : >ForgetPath: 
2025/09/13 08:35:28 DEBUG : ForgetPath: relativePath="dir", type=0
2025/09/13 08:35:28 DEBUG : invalidating directory cache
2025/09/13 08:35:28 DEBUG : dir: forgetting directory cache
2025/09/13 08:35:28 DEBUG : >ForgetPath: 
2025/09/13 08:35:28 DEBUG : ForgetPath: relativePath="not/in/cache", type=0
2025/09/13 08:35:28 DEBUG : >ForgetPath: 
2025/09/13 08:35:28 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:35:28 DEBUG : dir: Looking for writers
2025/09/13 08:35:28 DEBUG : Looking for writers
2025/09/13 08:35:28 DEBUG : dir: reading active writers
2025/09/13 08:35:28 DEBUG : >WaitForWriters: 
--- PASS: TestDirForgetPath (10.52s)
=== RUN   TestDirWalk
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:35:32 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:35:46 DEBUG : forgetting directory cache
2025/09/13 08:35:46 DEBUG : dir: forgetting directory cache
2025/09/13 08:35:48 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:35:48 DEBUG : dir: Looking for writers
2025/09/13 08:35:48 DEBUG : fil/a/b: Looking for writers
2025/09/13 08:35:48 DEBUG : fil/a: Looking for writers
2025/09/13 08:35:48 DEBUG : b: reading active writers
2025/09/13 08:35:48 DEBUG : fil: Looking for writers
2025/09/13 08:35:48 DEBUG : a: reading active writers
2025/09/13 08:35:48 DEBUG : Looking for writers
2025/09/13 08:35:48 DEBUG : dir: reading active writers
2025/09/13 08:35:48 DEBUG : fil: reading active writers
2025/09/13 08:35:48 DEBUG : >WaitForWriters: 
--- PASS: TestDirWalk (24.93s)
=== RUN   TestDirSetModTime
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:35:57 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:36:03 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:36:03 DEBUG : dir: Looking for writers
2025/09/13 08:36:03 DEBUG : Looking for writers
2025/09/13 08:36:03 DEBUG : dir: reading active writers
2025/09/13 08:36:03 DEBUG : >WaitForWriters: 
--- PASS: TestDirSetModTime (9.84s)
=== RUN   TestDirStat
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:36:07 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:41:11 DEBUG : pacer: low level retry 1/10 (error Get "https://api.sugarsync.com/folder/:sc:9068489:215_6563808897/contents?max=500&start=0": read tcp 65.108.87.141:33112->208.94.4.81:443: i/o timeout)
2025/09/13 08:41:11 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 08:41:12 DEBUG : pacer: Reducing sleep to 15ms
2025/09/13 08:41:12 DEBUG : pacer: Reducing sleep to 11.25ms
2025/09/13 08:41:13 DEBUG : pacer: Reducing sleep to 10ms
2025/09/13 08:41:14 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:41:14 DEBUG : dir: Looking for writers
2025/09/13 08:41:14 DEBUG : file1: reading active writers
2025/09/13 08:41:14 DEBUG : Looking for writers
2025/09/13 08:41:14 DEBUG : dir: reading active writers
2025/09/13 08:41:14 DEBUG : >WaitForWriters: 
--- PASS: TestDirStat (311.11s)
=== RUN   TestDirReadDirAll
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:41:18 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
=== RUN   TestDirReadDirAll/Virtual
2025/09/13 08:41:32 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile"
2025/09/13 08:41:32 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir"
2025/09/13 08:41:32 DEBUG : dir: Added virtual directory entry vDel: "file2"
2025/09/13 08:41:32 DEBUG : dir: Added virtual directory entry vDel: "subdir"
2025/09/13 08:44:26 DEBUG : forgetting directory cache
2025/09/13 08:44:26 DEBUG : dir: forgetting directory cache
2025/09/13 08:44:26 DEBUG : dir: forgetting directory cache
2025/09/13 08:44:43 DEBUG : forgetting directory cache
2025/09/13 08:44:43 DEBUG : dir: forgetting directory cache
2025/09/13 08:44:43 DEBUG : dir/subdir: forgetting directory cache
2025/09/13 08:44:57 DEBUG : forgetting directory cache
2025/09/13 08:44:57 DEBUG : dir: forgetting directory cache
2025/09/13 08:45:07 DEBUG : forgetting directory cache
2025/09/13 08:45:07 DEBUG : dir: forgetting directory cache
2025/09/13 08:45:07 DEBUG : dir: forgetting directory cache
2025/09/13 08:45:27 DEBUG : forgetting directory cache
2025/09/13 08:45:27 DEBUG : dir: forgetting directory cache
2025/09/13 08:45:47 DEBUG : forgetting directory cache
2025/09/13 08:45:47 DEBUG : dir: forgetting directory cache
2025/09/13 08:45:47 DEBUG : dir: forgetting directory cache
2025/09/13 08:45:47 DEBUG : fil: forgetting directory cache
2025/09/13 08:45:47 DEBUG : fil/a: forgetting directory cache
2025/09/13 08:45:47 DEBUG : fil/a/b: forgetting directory cache
2025/09/13 08:46:03 DEBUG : forgetting directory cache
2025/09/13 08:46:03 DEBUG : dir: forgetting directory cache
2025/09/13 08:46:03 DEBUG : dir: forgetting directory cache
2025/09/13 08:46:37 DEBUG : pacer: low level retry 1/1 (error Put "https://api.sugarsync.com/file/:sc:9068489:215_6563812857/data": net/http: timeout awaiting response headers)
2025/09/13 08:46:37 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 08:46:38 DEBUG : pacer: Reducing sleep to 15ms
=== NAME  TestDirReadDirAll
    run.go:281: Retry Put of "dir/virtualDir/testFile" to sugarsync root 'Test/rclone-test-zusosig3hazi': 1/10 (failed to upload file: Put "https://api.sugarsync.com/file/:sc:9068489:215_6563812857/data": net/http: timeout awaiting response headers)
2025/09/13 08:46:41 DEBUG : pacer: Reducing sleep to 11.25ms
2025/09/13 08:46:41 DEBUG : pacer: Reducing sleep to 10ms
2025/09/13 08:46:45 DEBUG : dir: invalidating directory cache
2025/09/13 08:46:45 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir"
2025/09/13 08:46:45 DEBUG : dir: Removed virtual directory entry vDel: "file2"
2025/09/13 08:46:45 DEBUG : dir: Removed virtual directory entry vDel: "subdir"
2025/09/13 08:46:45 DEBUG : dir/file1: Reset virtual modtime
2025/09/13 08:46:45 DEBUG : dir: Removed virtual directory entry vAddFile: "virtualFile"
2025/09/13 08:46:45 DEBUG : dir/virtualFile: Reset virtual modtime
2025/09/13 08:46:45 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile2"
2025/09/13 08:46:45 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir2"
2025/09/13 08:46:45 DEBUG : dir: Added virtual directory entry vDel: "file1"
2025/09/13 08:46:45 DEBUG : dir: invalidating directory cache
2025/09/13 08:46:46 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir2"
2025/09/13 08:46:46 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2025/09/13 08:46:46 DEBUG : dir/virtualFile: Reset virtual modtime
2025/09/13 08:46:46 DEBUG : forgetting directory cache
2025/09/13 08:46:46 DEBUG : dir: forgetting directory cache
2025/09/13 08:46:46 DEBUG : dir/virtualDir: forgetting directory cache
2025/09/13 08:46:46 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:46:46 DEBUG : dir/virtualDir: Looking for writers
2025/09/13 08:46:46 DEBUG : dir: Looking for writers
2025/09/13 08:46:46 DEBUG : virtualDir: reading active writers
2025/09/13 08:46:46 DEBUG : file1: reading active writers
2025/09/13 08:46:46 DEBUG : virtualFile2: reading active writers
2025/09/13 08:46:46 DEBUG : virtualFile: reading active writers
2025/09/13 08:46:46 DEBUG : Looking for writers
2025/09/13 08:46:46 DEBUG : dir: reading active writers
2025/09/13 08:46:46 DEBUG : >WaitForWriters: 
--- PASS: TestDirReadDirAll (335.29s)
    --- PASS: TestDirReadDirAll/Virtual (313.87s)
=== RUN   TestDirOpen
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:46:53 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:46:59 ERROR : dir/: Can only open directories read only
2025/09/13 08:46:59 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:46:59 DEBUG : dir: Looking for writers
2025/09/13 08:46:59 DEBUG : Looking for writers
2025/09/13 08:46:59 DEBUG : dir: reading active writers
2025/09/13 08:46:59 DEBUG : >WaitForWriters: 
--- PASS: TestDirOpen (9.87s)
=== RUN   TestDirCreate
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:47:03 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:51:13 DEBUG : forgetting directory cache
2025/09/13 08:51:13 DEBUG : dir: forgetting directory cache
2025/09/13 08:51:32 DEBUG : dir/subdir: forgetting directory cache
2025/09/13 08:52:10 DEBUG : pacer: low level retry 1/10 (error Get "https://api.sugarsync.com/folder/:sc:9068489:215_6563815922/contents?max=500&start=0": net/http: timeout awaiting response headers)
2025/09/13 08:52:10 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 08:52:10 DEBUG : pacer: Reducing sleep to 15ms
2025/09/13 08:52:10 DEBUG : dir/potato: Open: flags=O_WRONLY|O_CREATE
2025/09/13 08:52:10 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2025/09/13 08:52:10 DEBUG : dir/potato: >Open: fd=dir/potato (w), err=<nil>
2025/09/13 08:52:10 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2025/09/13 08:52:10 DEBUG : sugarsync root 'Test/rclone-test-zusosig3hazi': File to upload is small (5 bytes), uploading instead of streaming
2025/09/13 08:52:11 DEBUG : pacer: Reducing sleep to 11.25ms
2025/09/13 08:52:12 DEBUG : pacer: Reducing sleep to 10ms
2025/09/13 08:52:13 NOTICE: sugarsync root 'Test/rclone-test-zusosig3hazi': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/09/13 08:52:13 DEBUG : dir/potato: Size of src and dst objects identical
2025/09/13 08:52:13 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2025/09/13 08:52:13 DEBUG : Re-reading directory (5m3.825422921s old)
2025/09/13 08:52:13 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:52:13 DEBUG : dir: Looking for writers
2025/09/13 08:52:13 DEBUG : file1: reading active writers
2025/09/13 08:52:13 DEBUG : potato: reading active writers
2025/09/13 08:52:13 DEBUG : Looking for writers
2025/09/13 08:52:13 DEBUG : dir: reading active writers
2025/09/13 08:52:13 DEBUG : >WaitForWriters: 
--- PASS: TestDirCreate (315.20s)
=== RUN   TestDirMkdir
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:52:18 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:52:27 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2025/09/13 08:52:29 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:52:29 DEBUG : dir/sub: Looking for writers
2025/09/13 08:52:29 DEBUG : dir: Looking for writers
2025/09/13 08:52:29 DEBUG : file1: reading active writers
2025/09/13 08:52:29 DEBUG : sub: reading active writers
2025/09/13 08:52:29 DEBUG : Looking for writers
2025/09/13 08:52:29 DEBUG : dir: reading active writers
2025/09/13 08:52:29 DEBUG : >WaitForWriters: 
2025/09/13 08:56:45 DEBUG : dir/virtualDir2: forgetting directory cache
2025/09/13 08:56:46 DEBUG : forgetting directory cache
2025/09/13 08:56:46 DEBUG : dir: forgetting directory cache
2025/09/13 08:56:46 DEBUG : dir/virtualDir: forgetting directory cache
2025/09/13 08:56:46 DEBUG : dir: forgetting directory cache
2025/09/13 08:56:46 DEBUG : dir/virtualDir: forgetting directory cache
2025/09/13 08:56:59 DEBUG : dir: forgetting directory cache
2025/09/13 08:56:59 DEBUG : forgetting directory cache
2025/09/13 08:56:59 DEBUG : dir: forgetting directory cache
2025/09/13 08:57:35 DEBUG : pacer: low level retry 1/10 (error Get "https://api.sugarsync.com/folder/:sc:9068489:215_6563808897/contents?max=500&start=0": net/http: timeout awaiting response headers)
2025/09/13 08:57:35 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 08:57:36 DEBUG : pacer: Reducing sleep to 15ms
--- PASS: TestDirMkdir (317.28s)
=== RUN   TestDirMkdirSub
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 08:57:36 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 08:57:36 DEBUG : pacer: Reducing sleep to 11.25ms
2025/09/13 08:57:37 DEBUG : pacer: Reducing sleep to 10ms
2025/09/13 08:57:44 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2025/09/13 08:57:45 DEBUG : dir/sub: Added virtual directory entry vAddDir: "subsub"
2025/09/13 08:57:49 DEBUG : WaitForWriters: timeout=30s
2025/09/13 08:57:49 DEBUG : dir/sub/subsub: Looking for writers
2025/09/13 08:57:49 DEBUG : dir/sub: Looking for writers
2025/09/13 08:57:49 DEBUG : subsub: reading active writers
2025/09/13 08:57:49 DEBUG : dir: Looking for writers
2025/09/13 08:57:49 DEBUG : file1: reading active writers
2025/09/13 08:57:49 DEBUG : sub: reading active writers
2025/09/13 08:57:49 DEBUG : Looking for writers
2025/09/13 08:57:49 DEBUG : dir: reading active writers
2025/09/13 08:57:49 DEBUG : >WaitForWriters: 
2025/09/13 09:02:10 DEBUG : dir: forgetting directory cache
2025/09/13 09:02:10 DEBUG : dir: Removed virtual directory entry vAddFile: "potato"
2025/09/13 09:02:13 DEBUG : forgetting directory cache
2025/09/13 09:02:13 DEBUG : dir: forgetting directory cache
2025/09/13 09:02:24 DEBUG : forgetting directory cache
2025/09/13 09:02:24 DEBUG : dir: forgetting directory cache
2025/09/13 09:02:24 DEBUG : dir/sub: forgetting directory cache
2025/09/13 09:02:24 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2025/09/13 09:02:50 DEBUG : pacer: low level retry 1/10 (error Get "https://api.sugarsync.com/folder/:sc:9068489:215_6563845488/contents?max=500&start=0": read tcp 65.108.87.141:48010->208.94.4.81:443: i/o timeout)
2025/09/13 09:02:50 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 09:02:51 DEBUG : pacer: Reducing sleep to 15ms
2025/09/13 09:02:51 DEBUG : pacer: Reducing sleep to 11.25ms
2025/09/13 09:02:52 DEBUG : pacer: Reducing sleep to 10ms
--- PASS: TestDirMkdirSub (321.22s)
=== RUN   TestDirRemove
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 09:02:57 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 09:03:03 ERROR : dir/: Dir.Remove not empty
2025/09/13 09:03:03 DEBUG : dir/file1: Remove: 
2025/09/13 09:03:04 DEBUG : dir: Added virtual directory entry vDel: "file1"
2025/09/13 09:03:04 DEBUG : dir/file1: >Remove: err=<nil>
2025/09/13 09:03:06 DEBUG : Added virtual directory entry vDel: "dir"
2025/09/13 09:03:06 DEBUG : WaitForWriters: timeout=30s
2025/09/13 09:03:06 DEBUG : Looking for writers
2025/09/13 09:03:06 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemove (10.43s)
=== RUN   TestDirRemoveAll
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 09:03:07 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 09:03:14 DEBUG : dir/file1: Remove: 
2025/09/13 09:03:15 DEBUG : dir: Added virtual directory entry vDel: "file1"
2025/09/13 09:03:15 DEBUG : dir/file1: >Remove: err=<nil>
2025/09/13 09:03:16 DEBUG : Added virtual directory entry vDel: "dir"
2025/09/13 09:03:16 DEBUG : WaitForWriters: timeout=30s
2025/09/13 09:03:16 DEBUG : Looking for writers
2025/09/13 09:03:16 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemoveAll (10.72s)
=== RUN   TestDirRemoveName
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 09:03:18 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 09:03:24 DEBUG : dir/file1: Remove: 
2025/09/13 09:03:25 DEBUG : dir: Added virtual directory entry vDel: "file1"
2025/09/13 09:03:25 DEBUG : dir/file1: >Remove: err=<nil>
2025/09/13 09:03:27 DEBUG : WaitForWriters: timeout=30s
2025/09/13 09:03:27 DEBUG : dir: Looking for writers
2025/09/13 09:03:27 DEBUG : Looking for writers
2025/09/13 09:03:27 DEBUG : dir: reading active writers
2025/09/13 09:03:27 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemoveName (12.01s)
=== RUN   TestDirRename
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 09:03:30 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 09:06:46 DEBUG : dir: forgetting directory cache
2025/09/13 09:06:46 DEBUG : dir/virtualDir: forgetting directory cache
2025/09/13 09:06:46 DEBUG : forgetting directory cache
2025/09/13 09:06:46 DEBUG : dir: forgetting directory cache
2025/09/13 09:06:46 DEBUG : dir/virtualDir: forgetting directory cache
2025/09/13 09:07:41 DEBUG : forgetting directory cache
2025/09/13 09:07:41 DEBUG : dir: forgetting directory cache
2025/09/13 09:07:41 DEBUG : dir/sub: forgetting directory cache
2025/09/13 09:07:41 DEBUG : dir/sub/subsub: forgetting directory cache
2025/09/13 09:07:41 DEBUG : dir/sub: Removed virtual directory entry vAddDir: "subsub"
2025/09/13 09:07:41 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2025/09/13 09:08:34 DEBUG : pacer: low level retry 1/10 (error Get "https://api.sugarsync.com/folder/:sc:9068489:215_6563808897/contents?max=500&start=0": read tcp 65.108.87.141:53404->208.94.4.81:443: i/o timeout)
2025/09/13 09:08:34 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 09:08:35 DEBUG : pacer: Reducing sleep to 15ms
2025/09/13 09:08:35 DEBUG : pacer: Reducing sleep to 11.25ms
2025/09/13 09:08:36 DEBUG : pacer: Reducing sleep to 10ms
2025/09/13 09:08:41 ERROR : dir/not found: Dir.Rename error: file does not exist
2025/09/13 09:13:02 DEBUG : forgetting directory cache
2025/09/13 09:13:02 DEBUG : Removed virtual directory entry vDel: "dir"
2025/09/13 09:13:03 DEBUG : dir: forgetting directory cache
2025/09/13 09:13:03 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2025/09/13 09:13:13 DEBUG : forgetting directory cache
2025/09/13 09:13:13 DEBUG : Removed virtual directory entry vDel: "dir"
2025/09/13 09:13:14 DEBUG : dir: forgetting directory cache
2025/09/13 09:13:14 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2025/09/13 09:13:24 DEBUG : forgetting directory cache
2025/09/13 09:13:24 DEBUG : dir: forgetting directory cache
2025/09/13 09:13:24 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2025/09/13 09:13:42 DEBUG : pacer: low level retry 1/10 (error Put "https://api.sugarsync.com/folder/:sc:9068489:215_6563858648": net/http: timeout awaiting response headers)
2025/09/13 09:13:42 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 09:13:43 DEBUG : pacer: Reducing sleep to 15ms
2025/09/13 09:13:43 DEBUG : dir: Updating dir with dir2 0xc000514000
2025/09/13 09:13:43 DEBUG : dir: forgetting directory cache
2025/09/13 09:13:43 DEBUG : Added virtual directory entry vDel: "dir"
2025/09/13 09:13:43 DEBUG : Added virtual directory entry vAddDir: "dir2"
2025/09/13 09:13:43 DEBUG : Re-reading directory (5m6.951263708s old)
2025/09/13 09:13:43 DEBUG : pacer: Reducing sleep to 11.25ms
2025/09/13 09:13:43 DEBUG : Removed virtual directory entry vDel: "dir"
2025/09/13 09:13:43 DEBUG : Removed virtual directory entry vAddDir: "dir2"
2025/09/13 09:13:44 DEBUG : pacer: Reducing sleep to 10ms
2025/09/13 09:13:47 INFO  : dir2/file1: Moved (server-side) to: file2
2025/09/13 09:13:47 DEBUG : file2: Updating file with file2 0xc00021b2c0
2025/09/13 09:13:47 DEBUG : dir2: Added virtual directory entry vDel: "file1"
2025/09/13 09:13:47 DEBUG : Added virtual directory entry vAddFile: "file2"
2025/09/13 09:13:50 INFO  : dir2/file3: Deleted
2025/09/13 09:13:51 INFO  : file2: Moved (server-side) to: dir2/file3
2025/09/13 09:13:51 DEBUG : dir2/file3: Updating file with dir2/file3 0xc00021b2c0
2025/09/13 09:13:51 DEBUG : Added virtual directory entry vDel: "file2"
2025/09/13 09:13:51 DEBUG : dir2: Added virtual directory entry vAddFile: "file3"
2025/09/13 09:16:46 DEBUG : forgetting directory cache
2025/09/13 09:16:46 DEBUG : dir: forgetting directory cache
2025/09/13 09:16:46 DEBUG : dir/virtualDir: forgetting directory cache
2025/09/13 09:16:46 DEBUG : dir: forgetting directory cache
2025/09/13 09:16:46 DEBUG : dir/virtualDir: forgetting directory cache
2025/09/13 09:18:52 DEBUG : pacer: low level retry 1/10 (error Get "https://api.sugarsync.com/folder/:sc:9068489:215_6563858648/contents?max=500&start=0": net/http: timeout awaiting response headers)
2025/09/13 09:18:52 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 09:18:52 DEBUG : sugarsync root 'Test/rclone-test-zusosig3hazi': Renewing token
2025/09/13 09:18:53 DEBUG : pacer: Reducing sleep to 15ms
2025/09/13 09:18:53 DEBUG : Saving config "authorization" in section "TestSugarSync" of the config file
2025/09/13 09:18:53 DEBUG : Saving config "authorization_expiry" in section "TestSugarSync" of the config file
2025/09/13 09:18:53 DEBUG : Saving config "user" in section "TestSugarSync" of the config file
2025/09/13 09:18:54 DEBUG : pacer: Reducing sleep to 11.25ms
2025/09/13 09:18:54 DEBUG : Re-reading directory (5m10.881237961s old)
2025/09/13 09:18:55 DEBUG : pacer: Reducing sleep to 10ms
2025/09/13 09:18:55 DEBUG : Removed virtual directory entry vDel: "file2"
2025/09/13 09:18:56 DEBUG : Added virtual directory entry vAddDir: "empty directory"
2025/09/13 09:18:57 DEBUG : empty directory: Updating dir with renamed empty directory 0xc000650f70
2025/09/13 09:18:57 DEBUG : empty directory: forgetting directory cache
2025/09/13 09:18:57 DEBUG : Added virtual directory entry vDel: "empty directory"
2025/09/13 09:18:57 DEBUG : Added virtual directory entry vAddDir: "renamed empty directory"
2025/09/13 09:18:57 DEBUG : dir2: Renaming to "dir3"
2025/09/13 09:18:57 DEBUG : WaitForWriters: timeout=30s
2025/09/13 09:18:57 DEBUG : dir3: Looking for writers
2025/09/13 09:18:57 DEBUG : file3: reading active writers
2025/09/13 09:18:57 DEBUG : renamed empty directory: Looking for writers
2025/09/13 09:18:57 DEBUG : Looking for writers
2025/09/13 09:18:57 DEBUG : dir3: reading active writers
2025/09/13 09:18:57 DEBUG : renamed empty directory: reading active writers
2025/09/13 09:18:57 DEBUG : >WaitForWriters: 
2025/09/13 09:23:02 DEBUG : forgetting directory cache
2025/09/13 09:23:13 DEBUG : forgetting directory cache
2025/09/13 09:23:44 DEBUG : dir3: forgetting directory cache
2025/09/13 09:23:44 DEBUG : dir3: Removed virtual directory entry vDel: "file1"
2025/09/13 09:23:44 DEBUG : dir3: Removed virtual directory entry vAddFile: "file3"
2025/09/13 09:24:01 DEBUG : pacer: low level retry 1/10 (error Delete "https://api.sugarsync.com/folder/:sc:9068489:215_6563858648": net/http: timeout awaiting response headers)
2025/09/13 09:24:01 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 09:24:02 DEBUG : pacer: Reducing sleep to 15ms
2025/09/13 09:24:03 DEBUG : pacer: Reducing sleep to 11.25ms
--- PASS: TestDirRename (1232.59s)
=== RUN   TestDirStructSize
    dir_test.go:611: Dir struct has size 200 bytes
--- PASS: TestDirStructSize (0.00s)
=== RUN   TestDirFileOpen
    run.go:180: Remote "sugarsync root 'Test/rclone-test-zusosig3hazi'", Local "Local file system at /tmp/rclone1713112533", Modify Window "876000h0m0s"
2025/09/13 09:24:03 INFO  : sugarsync root 'Test/rclone-test-zusosig3hazi': poll-interval is not supported by this remote
2025/09/13 09:24:03 DEBUG : pacer: Reducing sleep to 10ms
2025/09/13 09:24:11 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2025/09/13 09:24:11 DEBUG : dir/sub/file0: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw-
2025/09/13 09:24:11 DEBUG : dir/sub/file0: Open: flags=O_RDWR|O_CREATE|O_TRUNC
2025/09/13 09:24:11 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0"
2025/09/13 09:24:11 DEBUG : dir/sub/file0: >Open: fd=dir/sub/file0 (w), err=<nil>
2025/09/13 09:24:11 DEBUG : dir/sub/file0: >OpenFile: fd=dir/sub/file0 (w), err=<nil>
2025/09/13 09:24:11 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0"
2025/09/13 09:24:11 DEBUG : dir/sub/file2: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw-
2025/09/13 09:24:11 DEBUG : dir/sub/file2: Open: flags=O_RDWR|O_CREATE|O_TRUNC
2025/09/13 09:24:11 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2"
2025/09/13 09:24:11 DEBUG : dir/sub/file2: >Open: fd=dir/sub/file2 (w), err=<nil>
2025/09/13 09:24:11 DEBUG : dir/sub/file2: >OpenFile: fd=dir/sub/file2 (w), err=<nil>
2025/09/13 09:24:11 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2"
2025/09/13 09:24:11 DEBUG : sugarsync root 'Test/rclone-test-zusosig3hazi': File to upload is small (12 bytes), uploading instead of streaming
2025/09/13 09:24:14 DEBUG : dir/sub/file2: Size of src and dst objects identical
2025/09/13 09:24:14 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2"
2025/09/13 09:24:14 DEBUG : forgetting directory cache
2025/09/13 09:24:14 DEBUG : dir: forgetting directory cache
2025/09/13 09:24:14 DEBUG : dir/sub: forgetting directory cache
2025/09/13 09:24:14 DEBUG : dir/sub: Removed virtual directory entry vAddFile: "file2"
2025/09/13 09:24:14 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2025/09/13 09:24:14 DEBUG : sugarsync root 'Test/rclone-test-zusosig3hazi': File to upload is small (5 bytes), uploading instead of streaming
2025/09/13 09:24:16 DEBUG : dir/sub/file0: Size of src and dst objects identical
2025/09/13 09:24:16 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0"
2025/09/13 09:24:16 DEBUG : WaitForWriters: timeout=30s
2025/09/13 09:24:16 DEBUG : dir/sub: Looking for writers
2025/09/13 09:24:16 DEBUG : file2: reading active writers
2025/09/13 09:24:16 DEBUG : file0: reading active writers
2025/09/13 09:24:16 DEBUG : dir: Looking for writers
2025/09/13 09:24:16 DEBUG : file1: reading active writers
2025/09/13 09:24:16 DEBUG : sub: reading active writers
2025/09/13 09:24:16 DEBUG : Looking for writers
2025/09/13 09:24:16 DEBUG : dir: reading active writers
2025/09/13 09:24:16 DEBUG : >WaitForWriters: 
2025/09/13 09:26:46 DEBUG : forgetting directory cache
2025/09/13 09:26:46 DEBUG : dir: forgetting directory cache
2025/09/13 09:26:46 DEBUG : dir/virtualDir: forgetting directory cache
2025/09/13 09:26:46 DEBUG : dir: forgetting directory cache
2025/09/13 09:26:46 DEBUG : dir/virtualDir: forgetting directory cache
2025/09/13 09:28:55 DEBUG : forgetting directory cache
2025/09/13 09:28:55 DEBUG : dir3: forgetting directory cache
2025/09/13 09:28:55 DEBUG : renamed empty directory: forgetting directory cache
2025/09/13 09:28:55 DEBUG : Removed virtual directory entry vDel: "empty directory"
2025/09/13 09:28:55 DEBUG : Removed virtual directory entry vAddDir: "renamed empty directory"
2025/09/13 09:29:17 DEBUG : pacer: low level retry 1/10 (error Get "https://api.sugarsync.com/folder/:sc:9068489:215_6563808897/contents?max=500&start=0": net/http: timeout awaiting response headers)
2025/09/13 09:29:17 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/13 09:34:14 DEBUG : forgetting directory cache
2025/09/13 09:34:14 DEBUG : dir: forgetting directory cache
2025/09/13 09:34:14 DEBUG : dir: forgetting directory cache
2025/09/13 09:34:14 DEBUG : dir/sub: forgetting directory cache
2025/09/13 09:34:14 DEBUG : dir/sub: forgetting directory cache
2025/09/13 09:34:14 DEBUG : dir/sub: forgetting directory cache
2025/09/13 09:34:14 DEBUG : dir/sub: Removed virtual directory entry vAddFile: "file0"
2025/09/13 09:34:17 DEBUG : pacer: low level retry 2/10 (error Get "https://api.sugarsync.com/folder/:sc:9068489:215_6563808897/contents?max=500&start=0": net/http: timeout awaiting response headers)
2025/09/13 09:34:17 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/13 09:34:18 DEBUG : pacer: Reducing sleep to 30ms
2025/09/13 09:34:19 DEBUG : pacer: Reducing sleep to 22.5ms
panic: test timed out after 1h0m0s
	running tests:
		TestDirFileOpen (10m16s)

goroutine 4291 [running]:
testing.(*M).startAlarm.func1()
	/usr/local/go/src/testing/testing.go:2484 +0x394
created by time.goFunc
	/usr/local/go/src/time/sleep.go:215 +0x2d

goroutine 1 [chan receive, 11 minutes]:
testing.(*T).Run(0xc000554c40, {0x2802086?, 0xc00006dad8?}, 0x2942760)
	/usr/local/go/src/testing/testing.go:1859 +0x431
testing.runTests.func1(0xc000554c40)
	/usr/local/go/src/testing/testing.go:2279 +0x37
testing.tRunner(0xc000554c40, 0xc00006dc18)
	/usr/local/go/src/testing/testing.go:1792 +0xf4
testing.runTests(0xc00070c480, {0x40e2060, 0x55, 0x55}, {0x847360?, 0x4138d80?, 0x41150a0?})
	/usr/local/go/src/testing/testing.go:2277 +0x4b4
testing.(*M).Run(0xc000146820)
	/usr/local/go/src/testing/testing.go:2142 +0x64a
github.com/rclone/rclone/fstest.TestMain(0xc000146820)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:69 +0xa5
github.com/rclone/rclone/vfs.TestMain(...)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/vfs_test.go:37
main.main()
	_testmain.go:217 +0xa9

goroutine 51 [syscall, 60 minutes]:
os/signal.signal_recv()
	/usr/local/go/src/runtime/sigqueue.go:152 +0x29
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:23 +0x13
created by os/signal.Notify.func1.1 in goroutine 1
	/usr/local/go/src/os/signal/signal.go:152 +0x1f

goroutine 52 [chan receive, 60 minutes]:
github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1()
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:24 +0x27
created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler in goroutine 1
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:21 +0xa7

goroutine 4208 [select]:
net/http.(*Transport).getConn(0xc00036e1a0, 0xc000790c30, {{}, 0x0, {0xc0008a8340, 0x5}, {0xc0001738d8, 0x15}, 0x0})
	/usr/local/go/src/net/http/transport.go:1520 +0x4ae
net/http.(*Transport).roundTrip(0xc00036e1a0, 0xc00045db80)
	/usr/local/go/src/net/http/transport.go:685 +0xb57
net/http.(*Transport).RoundTrip(...)
	/usr/local/go/src/net/http/roundtrip.go:30
github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc0001e4720, 0xc00045db80)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:496 +0x345
net/http.send(0xc00045db80, {0x2c73520, 0xc0001e4720}, {0x6fc001?, 0xc0008a8348?, 0x0?})
	/usr/local/go/src/net/http/client.go:259 +0x5e2
net/http.(*Client).send(0xc00051a1e0, 0xc00045db80, {0x20?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:180 +0x91
net/http.(*Client).do(0xc00051a1e0, 0xc00045db80)
	/usr/local/go/src/net/http/client.go:728 +0x989
net/http.(*Client).Do(...)
	/usr/local/go/src/net/http/client.go:587
github.com/rclone/rclone/lib/rest.(*Client).Call(0xc000230730, {0x2c9ae08, 0x41387e0}, 0xc00084f648)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:353 +0xd67
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xc000230730, {0x2c9ae08, 0x41387e0}, 0xc00045da40?, {0x219b6c0?, 0xc00078fbc0?}, {0x21ccda0, 0xc0001c0628}, 0x41373d?, 0x29442e0, ...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:550 +0x3f2
github.com/rclone/rclone/lib/rest.(*Client).CallXML(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:510
github.com/rclone/rclone/backend/sugarsync.(*Fs).moveFile.func1()
	/home/rclone/go/src/github.com/rclone/rclone/backend/sugarsync/sugarsync.go:967 +0x8d
github.com/rclone/rclone/fs.pacerInvoker(0x1, 0xa, 0xc00008f808?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:86 +0x32
github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc0001e4780, 0xc000790b90, 0xa)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:199 +0x7c
github.com/rclone/rclone/lib/pacer.(*Pacer).Call(0xc0001e4780, 0xc000790b90)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:218 +0x93
github.com/rclone/rclone/backend/sugarsync.(*Fs).moveFile(0xc0003f30e0, {0x2c9ae08, 0x41387e0}, {0xc0008a8340, 0x39}, {0xc00088aa34, 0x5}, {0xc00030464d, 0x2e})
	/home/rclone/go/src/github.com/rclone/rclone/backend/sugarsync/sugarsync.go:966 +0x29d
github.com/rclone/rclone/backend/sugarsync.(*Fs).delete(0xc0003f30e0, {0x2c9ae08, 0x41387e0}, 0x1, {0xc0008a8340, 0x39}, {0xc00088aa30?, 0x0?}, 0xd8?)
	/home/rclone/go/src/github.com/rclone/rclone/backend/sugarsync/sugarsync.go:807 +0x215
github.com/rclone/rclone/backend/sugarsync.(*Object).Remove(0x20?, {0x2c9ae08?, 0x41387e0?})
	/home/rclone/go/src/github.com/rclone/rclone/backend/sugarsync/sugarsync.go:1307 +0x3d
github.com/rclone/rclone/fstest.newRunIndividual.func1.1.1()
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:154 +0x24
github.com/rclone/rclone/fstest.retry(0xc000757340, {0xc0005fea00, 0x19}, 0xc00084fd28)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:121 +0xde
github.com/rclone/rclone/fstest.newRunIndividual.func1.1({0xc000586ac0?, 0x18?, 0x248a3e0?})
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:154 +0x29a
github.com/rclone/rclone/fs/walk.listRwalk.func1({0xc00088a4f4?, 0x26b45c0?}, {0xc000586ac0, 0x2, 0x2}, {0x0?, 0x0?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:179 +0x162
github.com/rclone/rclone/fs/walk.walk.func2()
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:415 +0x2e4
created by github.com/rclone/rclone/fs/walk.walk in goroutine 4032
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:395 +0x1df

goroutine 4032 [sync.WaitGroup.Wait, 10 minutes]:
sync.runtime_SemacquireWaitGroup(0xc0005abb68?)
	/usr/local/go/src/runtime/sema.go:110 +0x25
sync.(*WaitGroup).Wait(0x2c9ae08?)
	/usr/local/go/src/sync/waitgroup.go:118 +0x48
github.com/rclone/rclone/fs/walk.walk({0x2c9ae08, 0x41387e0}, {0x2cb3b00, 0xc0003f30e0}, {0x0, 0x0}, 0x1, 0xffffffffffffffff, 0xc000780ae0, 0x2943618)
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:453 +0x355
github.com/rclone/rclone/fs/walk.walkListDirSorted(...)
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:349
github.com/rclone/rclone/fs/walk.Walk({0x2c9ae08, 0x41387e0}, {0x2cb3b00, 0xc0003f30e0}, {0x0, 0x0}, 0x1, 0xffffffffffffffff, 0xc000780ae0)
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:76 +0x2a5
github.com/rclone/rclone/fs/walk.listRwalk({0x2c9ae08, 0x41387e0}, {0x2cb3b00, 0xc0003f30e0}, {0x0, 0x0}, 0x1, 0xffffffffffffffff, 0x3, 0xc000780ab0)
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:170 +0x10d
github.com/rclone/rclone/fs/walk.ListR({0x2c9ae08, 0x41387e0}, {0x2cb3b00, 0xc0003f30e0}, {0x0, 0x0}, 0x1, 0xffffffffffffffff, 0x3, 0xc000780ab0)
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:160 +0x236
github.com/rclone/rclone/fstest.newRunIndividual.func1()
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:150 +0x107
github.com/rclone/rclone/fstest.(*Run).Finalise(0xc0003a4460)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:388 +0x1c
testing.(*common).Cleanup.func1()
	/usr/local/go/src/testing/testing.go:1211 +0x106
testing.(*common).runCleanup(0xc000757340, 0xc0005abf38?)
	/usr/local/go/src/testing/testing.go:1445 +0xea
testing.tRunner.func2()
	/usr/local/go/src/testing/testing.go:1786 +0x25
testing.tRunner(0xc000757340, 0x2942760)
	/usr/local/go/src/testing/testing.go:1798 +0x11e
created by testing.(*T).Run in goroutine 1
	/usr/local/go/src/testing/testing.go:1851 +0x413

goroutine 4209 [select, 10 minutes]:
github.com/rclone/rclone/fs/walk.walk.func2()
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:398 +0x16c
created by github.com/rclone/rclone/fs/walk.walk in goroutine 4032
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:395 +0x1df

goroutine 4245 [select]:
github.com/rclone/rclone/fs/walk.walk.func2()
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:398 +0x16c
created by github.com/rclone/rclone/fs/walk.walk in goroutine 4032
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:395 +0x1df

goroutine 4287 [IO wait]:
internal/poll.runtime_pollWait(0x7fe1842284c0, 0x77)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0xc000150280?, 0x0?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitWrite(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:93
internal/poll.(*FD).WaitWrite(...)
	/usr/local/go/src/internal/poll/fd_unix.go:692
net.(*netFD).connect(0xc000150280, {0x2c9af90, 0xc0003a4e00}, {0x41b074?, 0x4a31b3?}, {0x2c71c80?, 0xc00078a280?})
	/usr/local/go/src/net/fd_unix.go:141 +0x6cb
net.(*netFD).dial(0xc000150280, {0x2c9af90, 0xc0003a4e00}, {0x2ca2c30?, 0x0?}, {0x2ca2c30, 0xc000576cc0}, 0xc00083d210?)
	/usr/local/go/src/net/sock_posix.go:124 +0x3bc
net.socket({0x2c9af90, 0xc0003a4e00}, {0x27e0160, 0x3}, 0x2, 0x1, 0x2?, 0x0, {0x2ca2c30, 0x0}, ...)
	/usr/local/go/src/net/sock_posix.go:70 +0x29b
net.internetSocket({0x2c9af90, 0xc0003a4e00}, {0x27e0160, 0x3}, {0x2ca2c30, 0x0}, {0x2ca2c30, 0xc000576cc0}, 0x1, 0x0, ...)
	/usr/local/go/src/net/ipsock_posix.go:167 +0xf8
net.(*sysDialer).doDialTCPProto(0xc0006a6a80, {0x2c9af90, 0xc0003a4e00}, 0x0, 0xc000576cc0, 0x0)
	/usr/local/go/src/net/tcpsock_posix.go:85 +0xe7
net.(*sysDialer).doDialTCP(...)
	/usr/local/go/src/net/tcpsock_posix.go:75
net.(*sysDialer).dialTCP(0x0?, {0x2c9af90?, 0xc0003a4e00?}, 0xc00083d528?, 0xc00083d420?)
	/usr/local/go/src/net/tcpsock_posix.go:71 +0x69
net.(*sysDialer).dialSingle(0xc0006a6a80, {0x2c9af90, 0xc0003a4e00}, {0x2c85f18, 0xc000576cc0})
	/usr/local/go/src/net/dial.go:721 +0x3ce
net.(*sysDialer).dialSerial(0xc0006a6a80, {0x2c9af90, 0xc0003a4e00}, {0xc00095e110?, 0x1, 0xc000576c90?})
	/usr/local/go/src/net/dial.go:686 +0x24e
net.(*sysDialer).dialParallel(0x0?, {0x2c9af90?, 0xc0003a4e00?}, {0xc00095e110?, 0x23b2da0?, 0x27e1241?}, {0x0?, 0x27e0160?, 0xc00009f7e0?})
	/usr/local/go/src/net/dial.go:587 +0x3a7
net.(*Dialer).DialContext(0xc00093e460, {0x2c9af20, 0xc000790c80}, {0x27e0160, 0x3}, {0xc0001738d8, 0x15})
	/usr/local/go/src/net/dial.go:578 +0x6ac
github.com/rclone/rclone/fs/fshttp.(*Dialer).DialContext(0xc00093e460, {0x2c9af20, 0xc000790c80}, {0x27e0160?, 0x7fe1843e0998?}, {0xc0001738d8, 0x15})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:62 +0x125
github.com/rclone/rclone/fs/fshttp.NewTransportCustom.func2({0x2c9af20, 0xc000790c80}, {0x27e0160, 0x3}, {0xc0001738d8, 0x15})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:269 +0x5c
net/http.(*Transport).dial(0xc000652c80?, {0x2c9af20?, 0xc000790c80?}, {0x27e0160?, 0x1?}, {0xc0001738d8?, 0x458449?})
	/usr/local/go/src/net/http/transport.go:1278 +0xd2
net/http.(*Transport).dialConn(0xc00036e1a0, {0x2c9af20, 0xc000790c80}, {{}, 0x0, {0xc0008a8340, 0x5}, {0xc0001738d8, 0x15}, 0x0})
	/usr/local/go/src/net/http/transport.go:1780 +0x7e5
net/http.(*Transport).dialConnFor(0xc00036e1a0, 0xc0000e48f0)
	/usr/local/go/src/net/http/transport.go:1615 +0xb8
net/http.(*Transport).startDialConnForLocked.func1()
	/usr/local/go/src/net/http/transport.go:1597 +0x35
created by net/http.(*Transport).startDialConnForLocked in goroutine 4208
	/usr/local/go/src/net/http/transport.go:1596 +0x112

goroutine 4243 [select, 10 minutes]:
github.com/rclone/rclone/fs/walk.walk.func2()
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:398 +0x16c
created by github.com/rclone/rclone/fs/walk.walk in goroutine 4032
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:395 +0x1df

goroutine 4207 [select, 10 minutes]:
github.com/rclone/rclone/fs/walk.walk.func2()
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:398 +0x16c
created by github.com/rclone/rclone/fs/walk.walk in goroutine 4032
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:395 +0x1df

goroutine 4185 [select]:
net.(*netFD).connect.func2()
	/usr/local/go/src/net/fd_unix.go:118 +0x7a
created by net.(*netFD).connect in goroutine 4287
	/usr/local/go/src/net/fd_unix.go:117 +0x349

goroutine 4242 [select, 10 minutes]:
github.com/rclone/rclone/fs/walk.walk.func2()
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:398 +0x16c
created by github.com/rclone/rclone/fs/walk.walk in goroutine 4032
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:395 +0x1df

goroutine 4206 [select, 10 minutes]:
github.com/rclone/rclone/fs/walk.walk.func2()
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:398 +0x16c
created by github.com/rclone/rclone/fs/walk.walk in goroutine 4032
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:395 +0x1df

goroutine 4244 [select, 10 minutes]:
github.com/rclone/rclone/fs/walk.walk.func2()
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:398 +0x16c
created by github.com/rclone/rclone/fs/walk.walk in goroutine 4032
	/home/rclone/go/src/github.com/rclone/rclone/fs/walk/walk.go:395 +0x1df
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestSugarSync:Test -verbose" - Finished ERROR in 1h0m3.547727501s (try 4/5): exit status 2: Failed []