"./vfs.test -test.v -test.timeout 1h0m0s -remote TestCompressDrive: -verbose" - Starting (try 1/5)
2021/12/13 05:45:03 DEBUG : Creating backend with remote "TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2"
2021/12/13 05:45:03 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2021/12/13 05:45:04 DEBUG : Creating backend with remote "/tmp/rclone1570099853"
=== RUN   TestDirHandleMethods
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:45:12 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:45:12 DEBUG : dir: Looking for writers
2021/12/13 05:45:12 DEBUG : : Looking for writers
2021/12/13 05:45:12 DEBUG : dir: reading active writers
2021/12/13 05:45:12 DEBUG : >WaitForWriters: 
2021/12/13 05:45:14 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:45:14 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
--- PASS: TestDirHandleMethods (10.87s)
=== RUN   TestDirHandleReaddir
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:45:32 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:45:32 DEBUG : dir/subdir: Looking for writers
2021/12/13 05:45:32 DEBUG : dir: Looking for writers
2021/12/13 05:45:32 DEBUG : file1: reading active writers
2021/12/13 05:45:32 DEBUG : file2: reading active writers
2021/12/13 05:45:32 DEBUG : subdir: reading active writers
2021/12/13 05:45:32 DEBUG : : Looking for writers
2021/12/13 05:45:32 DEBUG : dir: reading active writers
2021/12/13 05:45:32 DEBUG : >WaitForWriters: 
2021/12/13 05:45:38 DEBUG : dir/subdir: Rmdir: contains trashed file: "file3.json"
2021/12/13 05:45:38 DEBUG : dir/subdir: Rmdir: contains trashed file: "file3.EAAAAAAAAAA.gz"
2021/12/13 05:45:39 DEBUG : dir: Rmdir: contains trashed file: "subdir"
2021/12/13 05:45:39 DEBUG : dir: Rmdir: contains trashed file: "file2.DwAAAAAAAAA.gz"
2021/12/13 05:45:39 DEBUG : dir: Rmdir: contains trashed file: "file2.json"
2021/12/13 05:45:39 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:45:39 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
--- PASS: TestDirHandleReaddir (24.90s)
=== RUN   TestDirHandleReaddirnames
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:45:46 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:45:46 DEBUG : dir: Looking for writers
2021/12/13 05:45:46 DEBUG : file1: reading active writers
2021/12/13 05:45:46 DEBUG : : Looking for writers
2021/12/13 05:45:46 DEBUG : dir: reading active writers
2021/12/13 05:45:46 DEBUG : >WaitForWriters: 
2021/12/13 05:45:49 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:45:49 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
--- PASS: TestDirHandleReaddirnames (10.34s)
=== RUN   TestDirMethods
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:45:57 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:45:57 DEBUG : dir: Looking for writers
2021/12/13 05:45:57 DEBUG : : Looking for writers
2021/12/13 05:45:57 DEBUG : dir: reading active writers
2021/12/13 05:45:57 DEBUG : >WaitForWriters: 
2021/12/13 05:45:59 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:45:59 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
--- PASS: TestDirMethods (9.90s)
=== RUN   TestDirForgetAll
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:46:04 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:46:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "" entryType 0
2021/12/13 05:46:05 DEBUG : : changeNotify: relativePath="", type=0
2021/12/13 05:46:05 DEBUG : : invalidating directory cache
2021/12/13 05:46:05 DEBUG : : >changeNotify: 
2021/12/13 05:46:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:46:05 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:46:05 DEBUG : : >changeNotify: 
2021/12/13 05:46:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:46:05 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:46:05 DEBUG : : >changeNotify: 
2021/12/13 05:46:07 DEBUG : dir: forgetting directory cache
2021/12/13 05:46:07 DEBUG : : forgetting directory cache
2021/12/13 05:46:07 DEBUG : dir: forgetting directory cache
2021/12/13 05:46:07 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:46:07 DEBUG : : Looking for writers
2021/12/13 05:46:07 DEBUG : >WaitForWriters: 
2021/12/13 05:46:08 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:46:08 DEBUG : pacer: Rate limited, increasing sleep to 1.290850246s
2021/12/13 05:46:08 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:46:10 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:46:10 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
--- PASS: TestDirForgetAll (10.60s)
=== RUN   TestDirForgetPath
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:46:11 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:46:11 DEBUG : pacer: Rate limited, increasing sleep to 1.165393986s
2021/12/13 05:46:12 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:46:12 DEBUG : pacer: Rate limited, increasing sleep to 2.76921914s
2021/12/13 05:46:13 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:46:15 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:46:16 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:46:16 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:46:16 DEBUG : : invalidating directory cache
2021/12/13 05:46:16 DEBUG : dir: invalidating directory cache
2021/12/13 05:46:16 DEBUG : : >changeNotify: 
2021/12/13 05:46:21 DEBUG : : ForgetPath: relativePath="dir/notfound", type=1
2021/12/13 05:46:21 DEBUG : dir: invalidating directory cache
2021/12/13 05:46:21 DEBUG : : >ForgetPath: 
2021/12/13 05:46:21 DEBUG : : ForgetPath: relativePath="dir", type=0
2021/12/13 05:46:21 DEBUG : : invalidating directory cache
2021/12/13 05:46:21 DEBUG : dir: forgetting directory cache
2021/12/13 05:46:21 DEBUG : : >ForgetPath: 
2021/12/13 05:46:21 DEBUG : : ForgetPath: relativePath="not/in/cache", type=0
2021/12/13 05:46:21 DEBUG : : >ForgetPath: 
2021/12/13 05:46:21 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:46:21 DEBUG : dir: Looking for writers
2021/12/13 05:46:21 DEBUG : : Looking for writers
2021/12/13 05:46:21 DEBUG : dir: reading active writers
2021/12/13 05:46:21 DEBUG : >WaitForWriters: 
2021/12/13 05:46:23 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:46:23 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
--- PASS: TestDirForgetPath (13.84s)
=== RUN   TestDirWalk
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:46:30 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:46:30 DEBUG : pacer: Rate limited, increasing sleep to 1.208404246s
2021/12/13 05:46:31 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:46:34 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:46:34 DEBUG : pacer: Rate limited, increasing sleep to 1.351366274s
2021/12/13 05:46:34 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:46:37 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:46:37 DEBUG : pacer: Rate limited, increasing sleep to 1.869410844s
2021/12/13 05:46:38 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:46:40 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:46:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:46:40 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:46:40 DEBUG : : invalidating directory cache
2021/12/13 05:46:40 DEBUG : dir: invalidating directory cache
2021/12/13 05:46:40 DEBUG : : >changeNotify: 
2021/12/13 05:46:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:46:40 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:46:40 DEBUG : : >changeNotify: 
2021/12/13 05:46:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:46:40 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:46:40 DEBUG : : >changeNotify: 
2021/12/13 05:46:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil" entryType 0
2021/12/13 05:46:40 DEBUG : : changeNotify: relativePath="fil", type=0
2021/12/13 05:46:40 DEBUG : : >changeNotify: 
2021/12/13 05:46:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil/a" entryType 0
2021/12/13 05:46:40 DEBUG : : changeNotify: relativePath="fil/a", type=0
2021/12/13 05:46:40 DEBUG : : >changeNotify: 
2021/12/13 05:46:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil/a/b" entryType 0
2021/12/13 05:46:40 DEBUG : : changeNotify: relativePath="fil/a/b", type=0
2021/12/13 05:46:40 DEBUG : : >changeNotify: 
2021/12/13 05:46:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil/a/b/c.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:46:40 DEBUG : : changeNotify: relativePath="fil/a/b/c.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:46:40 DEBUG : : >changeNotify: 
2021/12/13 05:46:42 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:46:42 DEBUG : pacer: Rate limited, increasing sleep to 1.0552721s
2021/12/13 05:46:42 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:46:44 DEBUG : : forgetting directory cache
2021/12/13 05:46:44 DEBUG : dir: forgetting directory cache
2021/12/13 05:46:45 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:46:45 DEBUG : fil/a/b: Looking for writers
2021/12/13 05:46:45 DEBUG : fil/a: Looking for writers
2021/12/13 05:46:45 DEBUG : b: reading active writers
2021/12/13 05:46:45 DEBUG : fil: Looking for writers
2021/12/13 05:46:45 DEBUG : a: reading active writers
2021/12/13 05:46:45 DEBUG : dir: Looking for writers
2021/12/13 05:46:45 DEBUG : : Looking for writers
2021/12/13 05:46:45 DEBUG : dir: reading active writers
2021/12/13 05:46:45 DEBUG : fil: reading active writers
2021/12/13 05:46:45 DEBUG : >WaitForWriters: 
2021/12/13 05:46:50 DEBUG : fil/a/b: Rmdir: contains trashed file: "c.DwAAAAAAAAA.gz"
2021/12/13 05:46:50 DEBUG : fil/a/b: Rmdir: contains trashed file: "c.json"
2021/12/13 05:46:50 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:46:51 DEBUG : fil/a: Rmdir: contains trashed file: "b"
2021/12/13 05:46:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:46:51 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:46:51 DEBUG : : invalidating directory cache
2021/12/13 05:46:51 DEBUG : : >changeNotify: 
2021/12/13 05:46:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil" entryType 0
2021/12/13 05:46:51 DEBUG : : changeNotify: relativePath="fil", type=0
2021/12/13 05:46:51 DEBUG : : >changeNotify: 
2021/12/13 05:46:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil/a" entryType 0
2021/12/13 05:46:51 DEBUG : : changeNotify: relativePath="fil/a", type=0
2021/12/13 05:46:51 DEBUG : : >changeNotify: 
2021/12/13 05:46:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil/a/b" entryType 0
2021/12/13 05:46:51 DEBUG : : changeNotify: relativePath="fil/a/b", type=0
2021/12/13 05:46:51 DEBUG : : >changeNotify: 
2021/12/13 05:46:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:46:51 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:46:51 DEBUG : : >changeNotify: 
2021/12/13 05:46:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:46:51 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:46:51 DEBUG : : >changeNotify: 
2021/12/13 05:46:51 DEBUG : fil: Rmdir: contains trashed file: "a"
2021/12/13 05:46:52 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:46:52 DEBUG : pacer: Rate limited, increasing sleep to 1.976347085s
2021/12/13 05:46:52 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:46:54 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:46:54 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
--- PASS: TestDirWalk (30.47s)
=== RUN   TestDirSetModTime
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:47:00 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:47:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:47:01 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:47:01 DEBUG : : >changeNotify: 
2021/12/13 05:47:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil" entryType 0
2021/12/13 05:47:01 DEBUG : : changeNotify: relativePath="fil", type=0
2021/12/13 05:47:01 DEBUG : : >changeNotify: 
2021/12/13 05:47:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:01 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:01 DEBUG : : >changeNotify: 
2021/12/13 05:47:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:47:01 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:47:01 DEBUG : : >changeNotify: 
2021/12/13 05:47:01 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:47:01 DEBUG : dir: Looking for writers
2021/12/13 05:47:01 DEBUG : : Looking for writers
2021/12/13 05:47:01 DEBUG : dir: reading active writers
2021/12/13 05:47:01 DEBUG : >WaitForWriters: 
2021/12/13 05:47:04 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:47:04 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:47:04 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
--- PASS: TestDirSetModTime (9.71s)
=== RUN   TestDirStat
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:47:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:47:05 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:47:05 DEBUG : : >changeNotify: 
2021/12/13 05:47:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil" entryType 0
2021/12/13 05:47:05 DEBUG : : changeNotify: relativePath="fil", type=0
2021/12/13 05:47:05 DEBUG : : >changeNotify: 
2021/12/13 05:47:11 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:47:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:47:11 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:47:11 DEBUG : : >changeNotify: 
2021/12/13 05:47:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil" entryType 0
2021/12/13 05:47:11 DEBUG : : changeNotify: relativePath="fil", type=0
2021/12/13 05:47:11 DEBUG : : >changeNotify: 
2021/12/13 05:47:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:11 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:11 DEBUG : : >changeNotify: 
2021/12/13 05:47:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:47:11 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:47:11 DEBUG : : >changeNotify: 
2021/12/13 05:47:11 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:47:11 DEBUG : dir: Looking for writers
2021/12/13 05:47:11 DEBUG : file1: reading active writers
2021/12/13 05:47:11 DEBUG : : Looking for writers
2021/12/13 05:47:11 DEBUG : dir: reading active writers
2021/12/13 05:47:11 DEBUG : >WaitForWriters: 
2021/12/13 05:47:14 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:47:14 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
--- PASS: TestDirStat (10.06s)
=== RUN   TestDirReadDirAll
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:47:15 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:47:15 DEBUG : pacer: Rate limited, increasing sleep to 1.40680319s
2021/12/13 05:47:15 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:47:15 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:47:15 DEBUG : pacer: Rate limited, increasing sleep to 2.19485925s
2021/12/13 05:47:17 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:47:17 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:47:17 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:47:17 DEBUG : : >changeNotify: 
2021/12/13 05:47:17 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil" entryType 0
2021/12/13 05:47:17 DEBUG : : changeNotify: relativePath="fil", type=0
2021/12/13 05:47:17 DEBUG : : >changeNotify: 
2021/12/13 05:47:25 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:47:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil" entryType 0
2021/12/13 05:47:25 DEBUG : : changeNotify: relativePath="fil", type=0
2021/12/13 05:47:25 DEBUG : : invalidating directory cache
2021/12/13 05:47:25 DEBUG : fil: invalidating directory cache
2021/12/13 05:47:25 DEBUG : : >changeNotify: 
2021/12/13 05:47:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:47:25 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:47:25 DEBUG : : >changeNotify: 
2021/12/13 05:47:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:25 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:25 DEBUG : : >changeNotify: 
2021/12/13 05:47:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:47:25 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:47:25 DEBUG : : >changeNotify: 
2021/12/13 05:47:32 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:47:32 DEBUG : pacer: Rate limited, increasing sleep to 1.852265037s
2021/12/13 05:47:32 DEBUG : pacer: Reducing sleep to 0s
=== RUN   TestDirReadDirAll/Virtual
2021/12/13 05:47:37 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile"
2021/12/13 05:47:37 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir"
2021/12/13 05:47:37 DEBUG : dir: Added virtual directory entry vDel: "file2"
2021/12/13 05:47:37 DEBUG : dir: Added virtual directory entry vDel: "subdir"
2021/12/13 05:47:37 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:47:37 DEBUG : pacer: Rate limited, increasing sleep to 1.226810526s
2021/12/13 05:47:38 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:47:40 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:47:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil" entryType 0
2021/12/13 05:47:40 DEBUG : : changeNotify: relativePath="fil", type=0
2021/12/13 05:47:40 DEBUG : : >changeNotify: 
2021/12/13 05:47:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:47:40 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:47:40 DEBUG : : >changeNotify: 
2021/12/13 05:47:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:40 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:40 DEBUG : : >changeNotify: 
2021/12/13 05:47:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:47:40 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:47:40 DEBUG : : >changeNotify: 
2021/12/13 05:47:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file2.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:40 DEBUG : : changeNotify: relativePath="dir/file2.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:40 DEBUG : : >changeNotify: 
2021/12/13 05:47:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file2.json" entryType 1
2021/12/13 05:47:40 DEBUG : : changeNotify: relativePath="dir/file2.json.json", type=1
2021/12/13 05:47:40 DEBUG : : >changeNotify: 
2021/12/13 05:47:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/subdir" entryType 0
2021/12/13 05:47:40 DEBUG : : changeNotify: relativePath="dir/subdir", type=0
2021/12/13 05:47:40 DEBUG : : >changeNotify: 
2021/12/13 05:47:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/subdir/file3.EAAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:40 DEBUG : : changeNotify: relativePath="dir/subdir/file3.EAAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:40 DEBUG : : >changeNotify: 
2021/12/13 05:47:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/subdir/file3.json" entryType 1
2021/12/13 05:47:40 DEBUG : : changeNotify: relativePath="dir/subdir/file3.json.json", type=1
2021/12/13 05:47:40 DEBUG : : >changeNotify: 
2021/12/13 05:47:44 DEBUG : pacer: low level retry 1/1 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:47:44 DEBUG : pacer: Rate limited, increasing sleep to 1.51010641s
=== CONT  TestDirReadDirAll
    run.go:283: Retry Put of "dir/virtualDir/testFile" to Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: 1/10 (googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:47:46 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:47:50 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "fil" entryType 0
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="fil", type=0
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file2.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/file2.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file2.json" entryType 1
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/file2.json.json", type=1
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/subdir" entryType 0
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/subdir", type=0
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/subdir/file3.EAAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/subdir/file3.EAAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/subdir/file3.json" entryType 1
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/subdir/file3.json.json", type=1
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualFile.FAAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/virtualFile.FAAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualFile.json" entryType 1
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/virtualFile.json.json", type=1
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualDir" entryType 0
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/virtualDir", type=0
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualDir/testFile.EQAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:51 DEBUG : : changeNotify: relativePath="dir/virtualDir/testFile.EQAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:51 DEBUG : : >changeNotify: 
2021/12/13 05:47:53 DEBUG : dir: invalidating directory cache
2021/12/13 05:47:53 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir"
2021/12/13 05:47:53 DEBUG : dir: Removed virtual directory entry vDel: "file2"
2021/12/13 05:47:53 DEBUG : dir: Removed virtual directory entry vDel: "subdir"
2021/12/13 05:47:53 DEBUG : dir: Removed virtual directory entry vAddFile: "virtualFile"
2021/12/13 05:47:53 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile2"
2021/12/13 05:47:53 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir2"
2021/12/13 05:47:53 DEBUG : dir: Added virtual directory entry vDel: "file1"
2021/12/13 05:47:53 DEBUG : dir: invalidating directory cache
2021/12/13 05:47:54 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir2"
2021/12/13 05:47:54 DEBUG : dir: Removed virtual directory entry vDel: "file1"
2021/12/13 05:47:54 DEBUG : : forgetting directory cache
2021/12/13 05:47:54 DEBUG : dir: forgetting directory cache
2021/12/13 05:47:54 DEBUG : dir/virtualDir: forgetting directory cache
2021/12/13 05:47:54 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:47:54 DEBUG : dir/virtualDir: Looking for writers
2021/12/13 05:47:54 DEBUG : dir: Looking for writers
2021/12/13 05:47:54 DEBUG : file1: reading active writers
2021/12/13 05:47:54 DEBUG : virtualFile2: reading active writers
2021/12/13 05:47:54 DEBUG : virtualFile: reading active writers
2021/12/13 05:47:54 DEBUG : virtualDir: reading active writers
2021/12/13 05:47:54 DEBUG : : Looking for writers
2021/12/13 05:47:54 DEBUG : dir: reading active writers
2021/12/13 05:47:54 DEBUG : >WaitForWriters: 
2021/12/13 05:47:54 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:47:54 DEBUG : pacer: Rate limited, increasing sleep to 1.41136595s
2021/12/13 05:47:55 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:47:55 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:47:56 DEBUG : : invalidating directory cache
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualFile.FAAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/virtualFile.FAAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualFile.json" entryType 1
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/virtualFile.json.json", type=1
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualDir" entryType 0
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/virtualDir", type=0
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualDir/testFile.EQAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/virtualDir/testFile.EQAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualDir/testFile.json" entryType 1
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/virtualDir/testFile.json.json", type=1
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file2.json" entryType 1
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/file2.json.json", type=1
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file2.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/file2.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:47:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/subdir" entryType 0
2021/12/13 05:47:56 DEBUG : : changeNotify: relativePath="dir/subdir", type=0
2021/12/13 05:47:56 DEBUG : : >changeNotify: 
2021/12/13 05:48:00 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:01 DEBUG : dir/virtualDir: Rmdir: contains trashed file: "testFile.EQAAAAAAAAA.gz"
2021/12/13 05:48:01 DEBUG : dir/virtualDir: Rmdir: contains trashed file: "testFile.json"
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualDir" entryType 0
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/virtualDir", type=0
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualDir/testFile.EQAAAAAAAAA.gz" entryType 1
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/virtualDir/testFile.EQAAAAAAAAA.gz.json", type=1
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file2.json" entryType 1
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/file2.json.json", type=1
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file2.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/file2.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/subdir" entryType 0
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/subdir", type=0
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualFile.json" entryType 1
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/virtualFile.json.json", type=1
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualFile.FAAAAAAAAAA.gz" entryType 1
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/virtualFile.FAAAAAAAAAA.gz.json", type=1
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/virtualDir/testFile.json" entryType 1
2021/12/13 05:48:01 DEBUG : : changeNotify: relativePath="dir/virtualDir/testFile.json.json", type=1
2021/12/13 05:48:01 DEBUG : : >changeNotify: 
2021/12/13 05:48:02 DEBUG : dir: Rmdir: contains trashed file: "virtualDir"
2021/12/13 05:48:02 DEBUG : dir: Rmdir: contains trashed file: "subdir"
2021/12/13 05:48:02 DEBUG : dir: Rmdir: contains trashed file: "file2.json"
2021/12/13 05:48:02 DEBUG : dir: Rmdir: contains trashed file: "file2.DwAAAAAAAAA.gz"
2021/12/13 05:48:02 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:48:02 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:48:02 DEBUG : dir: Rmdir: contains trashed file: "virtualFile.json"
2021/12/13 05:48:02 DEBUG : dir: Rmdir: contains trashed file: "virtualFile.FAAAAAAAAAA.gz"
--- PASS: TestDirReadDirAll (47.97s)
    --- PASS: TestDirReadDirAll/Virtual (16.46s)
=== RUN   TestDirOpen
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:48:04 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:05 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:05 DEBUG : : >changeNotify: 
2021/12/13 05:48:05 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:05 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:05 DEBUG : : invalidating directory cache
2021/12/13 05:48:05 DEBUG : dir: invalidating directory cache
2021/12/13 05:48:05 DEBUG : : >changeNotify: 
2021/12/13 05:48:09 ERROR : dir/: Can only open directories read only
2021/12/13 05:48:09 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:48:09 DEBUG : dir: Looking for writers
2021/12/13 05:48:09 DEBUG : : Looking for writers
2021/12/13 05:48:09 DEBUG : dir: reading active writers
2021/12/13 05:48:09 DEBUG : >WaitForWriters: 
2021/12/13 05:48:11 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:11 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:11 DEBUG : : >changeNotify: 
2021/12/13 05:48:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:48:11 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:48:11 DEBUG : : >changeNotify: 
2021/12/13 05:48:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:48:11 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:48:11 DEBUG : : >changeNotify: 
2021/12/13 05:48:11 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:48:11 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
--- PASS: TestDirOpen (9.79s)
=== RUN   TestDirCreate
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:48:15 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:15 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:15 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:15 DEBUG : dir: invalidating directory cache
2021/12/13 05:48:15 DEBUG : : >changeNotify: 
2021/12/13 05:48:16 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:16 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:16 DEBUG : : >changeNotify: 
2021/12/13 05:48:19 DEBUG : dir/potato: Open: flags=O_WRONLY|O_CREATE
2021/12/13 05:48:19 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2021/12/13 05:48:19 DEBUG : dir/potato: >Open: fd=dir/potato (w), err=<nil>
2021/12/13 05:48:19 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2021/12/13 05:48:19 DEBUG : Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: File to upload is small (5 bytes), uploading instead of streaming
2021/12/13 05:48:22 DEBUG : dir/potato: md5 = 5d41402abc4b2a76b9719d911017c592 OK
2021/12/13 05:48:22 INFO  : dir/potato: Copied (new)
2021/12/13 05:48:22 DEBUG : dir: Added virtual directory entry vAddFile: "potato"
2021/12/13 05:48:22 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:48:22 DEBUG : dir: Looking for writers
2021/12/13 05:48:22 DEBUG : file1: reading active writers
2021/12/13 05:48:22 DEBUG : potato: reading active writers
2021/12/13 05:48:22 DEBUG : : Looking for writers
2021/12/13 05:48:22 DEBUG : dir: reading active writers
2021/12/13 05:48:22 DEBUG : >WaitForWriters: 
2021/12/13 05:48:25 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:25 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:25 DEBUG : : >changeNotify: 
2021/12/13 05:48:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:48:25 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:48:25 DEBUG : : >changeNotify: 
2021/12/13 05:48:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:48:25 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:48:25 DEBUG : : >changeNotify: 
2021/12/13 05:48:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/potato.json" entryType 1
2021/12/13 05:48:25 DEBUG : : changeNotify: relativePath="dir/potato.json.json", type=1
2021/12/13 05:48:25 DEBUG : : >changeNotify: 
2021/12/13 05:48:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/potato.bin" entryType 1
2021/12/13 05:48:25 DEBUG : : changeNotify: relativePath="dir/potato.bin.json", type=1
2021/12/13 05:48:25 DEBUG : : >changeNotify: 
2021/12/13 05:48:26 DEBUG : dir: Rmdir: contains trashed file: "potato.bin"
2021/12/13 05:48:26 DEBUG : dir: Rmdir: contains trashed file: "potato.json"
2021/12/13 05:48:26 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:48:26 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
--- PASS: TestDirCreate (14.69s)
=== RUN   TestDirMkdir
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:48:35 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2021/12/13 05:48:37 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:48:37 DEBUG : dir/sub: Looking for writers
2021/12/13 05:48:37 DEBUG : dir: Looking for writers
2021/12/13 05:48:37 DEBUG : file1: reading active writers
2021/12/13 05:48:37 DEBUG : sub: reading active writers
2021/12/13 05:48:37 DEBUG : : Looking for writers
2021/12/13 05:48:37 DEBUG : dir: reading active writers
2021/12/13 05:48:37 DEBUG : >WaitForWriters: 
2021/12/13 05:48:40 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:40 DEBUG : dir: Rmdir: contains trashed file: "sub"
2021/12/13 05:48:40 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:48:40 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:48:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:40 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:40 DEBUG : : >changeNotify: 
2021/12/13 05:48:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:48:40 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:48:40 DEBUG : : >changeNotify: 
2021/12/13 05:48:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:48:40 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:48:40 DEBUG : : >changeNotify: 
2021/12/13 05:48:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/sub" entryType 0
2021/12/13 05:48:40 DEBUG : : changeNotify: relativePath="dir/sub", type=0
2021/12/13 05:48:40 DEBUG : : >changeNotify: 
--- PASS: TestDirMkdir (14.01s)
=== RUN   TestDirMkdirSub
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:48:49 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2021/12/13 05:48:50 DEBUG : dir/sub: Added virtual directory entry vAddDir: "subsub"
2021/12/13 05:48:50 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:51 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:51 DEBUG : : >changeNotify: 
2021/12/13 05:48:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:48:51 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:48:51 DEBUG : : >changeNotify: 
2021/12/13 05:48:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:48:51 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:48:51 DEBUG : : >changeNotify: 
2021/12/13 05:48:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/sub" entryType 0
2021/12/13 05:48:51 DEBUG : : changeNotify: relativePath="dir/sub", type=0
2021/12/13 05:48:51 DEBUG : : >changeNotify: 
2021/12/13 05:48:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/sub/subsub" entryType 0
2021/12/13 05:48:51 DEBUG : : changeNotify: relativePath="dir/sub/subsub", type=0
2021/12/13 05:48:51 DEBUG : : >changeNotify: 
2021/12/13 05:48:52 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:48:52 DEBUG : dir/sub/subsub: Looking for writers
2021/12/13 05:48:52 DEBUG : dir/sub: Looking for writers
2021/12/13 05:48:52 DEBUG : subsub: reading active writers
2021/12/13 05:48:52 DEBUG : dir: Looking for writers
2021/12/13 05:48:52 DEBUG : file1: reading active writers
2021/12/13 05:48:52 DEBUG : sub: reading active writers
2021/12/13 05:48:52 DEBUG : : Looking for writers
2021/12/13 05:48:52 DEBUG : dir: reading active writers
2021/12/13 05:48:52 DEBUG : >WaitForWriters: 
2021/12/13 05:48:55 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:48:55 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:48:55 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:48:55 DEBUG : : >changeNotify: 
2021/12/13 05:48:55 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/sub" entryType 0
2021/12/13 05:48:55 DEBUG : : changeNotify: relativePath="dir/sub", type=0
2021/12/13 05:48:55 DEBUG : : >changeNotify: 
2021/12/13 05:48:55 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/sub/subsub" entryType 0
2021/12/13 05:48:55 DEBUG : : changeNotify: relativePath="dir/sub/subsub", type=0
2021/12/13 05:48:55 DEBUG : : >changeNotify: 
2021/12/13 05:48:55 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:48:55 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:48:55 DEBUG : : >changeNotify: 
2021/12/13 05:48:55 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:48:55 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:48:55 DEBUG : : >changeNotify: 
2021/12/13 05:48:56 DEBUG : dir/sub: Rmdir: contains trashed file: "subsub"
2021/12/13 05:48:56 DEBUG : dir: Rmdir: contains trashed file: "sub"
2021/12/13 05:48:56 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:48:56 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
--- PASS: TestDirMkdirSub (16.34s)
=== RUN   TestDirRemove
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:49:00 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:01 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:01 DEBUG : : >changeNotify: 
2021/12/13 05:49:03 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:03 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:03 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:03 DEBUG : : invalidating directory cache
2021/12/13 05:49:03 DEBUG : : >changeNotify: 
2021/12/13 05:49:03 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:03 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:03 DEBUG : : >changeNotify: 
2021/12/13 05:49:03 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:49:03 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:49:03 DEBUG : : >changeNotify: 
2021/12/13 05:49:04 ERROR : dir/: Dir.Remove not empty
2021/12/13 05:49:04 DEBUG : dir/file1: Remove: 
2021/12/13 05:49:04 DEBUG : dir: Added virtual directory entry vDel: "file1"
2021/12/13 05:49:04 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:05 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:05 DEBUG : : >changeNotify: 
2021/12/13 05:49:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:05 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:05 DEBUG : : >changeNotify: 
2021/12/13 05:49:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:49:05 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:49:05 DEBUG : : >changeNotify: 
2021/12/13 05:49:05 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:05 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:05 DEBUG : : >changeNotify: 
2021/12/13 05:49:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:05 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:05 DEBUG : : >changeNotify: 
2021/12/13 05:49:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:49:05 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:49:05 DEBUG : : >changeNotify: 
2021/12/13 05:49:05 DEBUG : dir/file1: >Remove: err=<nil>
2021/12/13 05:49:06 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:49:06 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:49:06 DEBUG : : Added virtual directory entry vDel: "dir"
2021/12/13 05:49:07 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:49:07 DEBUG : : Looking for writers
2021/12/13 05:49:07 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemove (9.67s)
=== RUN   TestDirRemoveAll
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:49:11 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:11 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:11 DEBUG : : >changeNotify: 
2021/12/13 05:49:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:11 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:11 DEBUG : : >changeNotify: 
2021/12/13 05:49:13 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:13 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:13 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:13 DEBUG : : invalidating directory cache
2021/12/13 05:49:13 DEBUG : dir: invalidating directory cache
2021/12/13 05:49:13 DEBUG : : >changeNotify: 
2021/12/13 05:49:13 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:13 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:13 DEBUG : : >changeNotify: 
2021/12/13 05:49:13 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:49:13 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:49:13 DEBUG : : >changeNotify: 
2021/12/13 05:49:13 DEBUG : dir/file1: Remove: 
2021/12/13 05:49:13 DEBUG : dir: Added virtual directory entry vDel: "file1"
2021/12/13 05:49:15 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:15 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:15 DEBUG : dir/file1: >Remove: err=<nil>
2021/12/13 05:49:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:15 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:15 DEBUG : : >changeNotify: 
2021/12/13 05:49:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:15 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:15 DEBUG : : >changeNotify: 
2021/12/13 05:49:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:49:15 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:49:15 DEBUG : : >changeNotify: 
2021/12/13 05:49:15 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:49:15 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:49:16 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:16 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:16 DEBUG : : >changeNotify: 
2021/12/13 05:49:16 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:49:16 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:49:16 DEBUG : : >changeNotify: 
2021/12/13 05:49:16 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:16 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:16 DEBUG : : >changeNotify: 
2021/12/13 05:49:16 DEBUG : : Added virtual directory entry vDel: "dir"
2021/12/13 05:49:16 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:49:16 DEBUG : : Looking for writers
2021/12/13 05:49:16 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemoveAll (9.68s)
=== RUN   TestDirRemoveName
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:49:23 DEBUG : dir/file1: Remove: 
2021/12/13 05:49:23 DEBUG : dir: Added virtual directory entry vDel: "file1"
2021/12/13 05:49:25 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:25 DEBUG : dir/file1: >Remove: err=<nil>
2021/12/13 05:49:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:25 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:25 DEBUG : : >changeNotify: 
2021/12/13 05:49:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:49:25 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:49:25 DEBUG : : >changeNotify: 
2021/12/13 05:49:25 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:25 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:25 DEBUG : : >changeNotify: 
2021/12/13 05:49:25 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:49:25 DEBUG : dir: Looking for writers
2021/12/13 05:49:25 DEBUG : : Looking for writers
2021/12/13 05:49:25 DEBUG : dir: reading active writers
2021/12/13 05:49:25 DEBUG : >WaitForWriters: 
2021/12/13 05:49:26 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:49:26 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
--- PASS: TestDirRemoveName (10.30s)
=== RUN   TestDirRename
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:49:27 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:28 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:28 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:28 DEBUG : : invalidating directory cache
2021/12/13 05:49:28 DEBUG : dir: invalidating directory cache
2021/12/13 05:49:28 DEBUG : : >changeNotify: 
2021/12/13 05:49:40 ERROR : dir/not found: Dir.Rename error: file does not exist
2021/12/13 05:49:40 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:40 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:40 DEBUG : : >changeNotify: 
2021/12/13 05:49:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:40 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:40 DEBUG : : >changeNotify: 
2021/12/13 05:49:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:49:40 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:49:40 DEBUG : : >changeNotify: 
2021/12/13 05:49:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file3.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:40 DEBUG : : changeNotify: relativePath="dir/file3.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:40 DEBUG : : >changeNotify: 
2021/12/13 05:49:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file3.json" entryType 1
2021/12/13 05:49:40 DEBUG : : changeNotify: relativePath="dir/file3.json.json", type=1
2021/12/13 05:49:40 DEBUG : : >changeNotify: 
2021/12/13 05:49:40 DEBUG : dir: Updating dir with dir2 0xc000959d40
2021/12/13 05:49:40 DEBUG : dir: forgetting directory cache
2021/12/13 05:49:40 DEBUG : : Added virtual directory entry vDel: "dir"
2021/12/13 05:49:40 DEBUG : : Added virtual directory entry vAddDir: "dir2"
2021/12/13 05:49:41 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:42 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:42 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:42 DEBUG : : invalidating directory cache
2021/12/13 05:49:42 DEBUG : dir: invalidating directory cache
2021/12/13 05:49:42 DEBUG : : >changeNotify: 
2021/12/13 05:49:42 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:42 DEBUG : : changeNotify: relativePath="dir2/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:42 DEBUG : : >changeNotify: 
2021/12/13 05:49:42 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file1.json" entryType 1
2021/12/13 05:49:42 DEBUG : : changeNotify: relativePath="dir2/file1.json.json", type=1
2021/12/13 05:49:42 DEBUG : : >changeNotify: 
2021/12/13 05:49:42 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:42 DEBUG : : changeNotify: relativePath="dir2/file3.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:42 DEBUG : : >changeNotify: 
2021/12/13 05:49:42 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.json" entryType 1
2021/12/13 05:49:42 DEBUG : : changeNotify: relativePath="dir2/file3.json.json", type=1
2021/12/13 05:49:42 DEBUG : : >changeNotify: 
2021/12/13 05:49:42 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:49:42 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:49:42 DEBUG : : >changeNotify: 
2021/12/13 05:49:47 INFO  : dir2/file1: Moved (server-side) to: file2
2021/12/13 05:49:47 DEBUG : file2: Updating file with file2 0xc0017f06c0
2021/12/13 05:49:47 DEBUG : dir2: Added virtual directory entry vDel: "file1"
2021/12/13 05:49:47 DEBUG : : Added virtual directory entry vAddFile: "file2"
2021/12/13 05:49:50 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:51 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:51 DEBUG : : >changeNotify: 
2021/12/13 05:49:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:51 DEBUG : : changeNotify: relativePath="dir2/file3.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:51 DEBUG : : >changeNotify: 
2021/12/13 05:49:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:49:51 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:49:51 DEBUG : : >changeNotify: 
2021/12/13 05:49:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "file2.json" entryType 1
2021/12/13 05:49:51 DEBUG : : changeNotify: relativePath="file2.json.json", type=1
2021/12/13 05:49:51 DEBUG : : >changeNotify: 
2021/12/13 05:49:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "file2.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:51 DEBUG : : changeNotify: relativePath="file2.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:51 DEBUG : : >changeNotify: 
2021/12/13 05:49:51 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.json" entryType 1
2021/12/13 05:49:51 DEBUG : : changeNotify: relativePath="dir2/file3.json.json", type=1
2021/12/13 05:49:51 DEBUG : : >changeNotify: 
2021/12/13 05:49:51 INFO  : dir2/file3: Deleted
2021/12/13 05:49:53 INFO  : file2: Moved (server-side) to: dir2/file3
2021/12/13 05:49:53 DEBUG : dir2/file3: Updating file with dir2/file3 0xc0017f06c0
2021/12/13 05:49:53 DEBUG : : Added virtual directory entry vDel: "file2"
2021/12/13 05:49:53 DEBUG : dir2: Added virtual directory entry vAddFile: "file3"
2021/12/13 05:49:55 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:55 DEBUG : : Added virtual directory entry vAddDir: "empty directory"
2021/12/13 05:49:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:56 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:56 DEBUG : : >changeNotify: 
2021/12/13 05:49:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:49:56 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:49:56 DEBUG : : >changeNotify: 
2021/12/13 05:49:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.json" entryType 1
2021/12/13 05:49:56 DEBUG : : changeNotify: relativePath="dir2/file3.json.json", type=1
2021/12/13 05:49:56 DEBUG : : >changeNotify: 
2021/12/13 05:49:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:56 DEBUG : : changeNotify: relativePath="dir2/file3.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:56 DEBUG : : >changeNotify: 
2021/12/13 05:49:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:56 DEBUG : : changeNotify: relativePath="dir2/file3.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:56 DEBUG : : >changeNotify: 
2021/12/13 05:49:56 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "empty directory" entryType 0
2021/12/13 05:49:56 DEBUG : : changeNotify: relativePath="empty directory", type=0
2021/12/13 05:49:56 DEBUG : : >changeNotify: 
2021/12/13 05:49:56 DEBUG : empty directory: Updating dir with renamed empty directory 0xc000a4a6c0
2021/12/13 05:49:56 DEBUG : empty directory: forgetting directory cache
2021/12/13 05:49:56 DEBUG : : Added virtual directory entry vDel: "empty directory"
2021/12/13 05:49:56 DEBUG : : Added virtual directory entry vAddDir: "renamed empty directory"
2021/12/13 05:49:56 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:49:56 DEBUG : dir2: Looking for writers
2021/12/13 05:49:56 DEBUG : file3: reading active writers
2021/12/13 05:49:56 DEBUG : renamed empty directory: Looking for writers
2021/12/13 05:49:56 DEBUG : : Looking for writers
2021/12/13 05:49:56 DEBUG : dir2: reading active writers
2021/12/13 05:49:56 DEBUG : renamed empty directory: reading active writers
2021/12/13 05:49:56 DEBUG : >WaitForWriters: 
2021/12/13 05:49:58 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:49:58 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:49:58 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:49:58 DEBUG : : invalidating directory cache
2021/12/13 05:49:58 DEBUG : : >changeNotify: 
2021/12/13 05:49:58 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:49:58 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:49:58 DEBUG : : >changeNotify: 
2021/12/13 05:49:58 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.json" entryType 1
2021/12/13 05:49:58 DEBUG : : changeNotify: relativePath="dir2/file3.json.json", type=1
2021/12/13 05:49:58 DEBUG : : >changeNotify: 
2021/12/13 05:49:58 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.DwAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:58 DEBUG : : changeNotify: relativePath="dir2/file3.DwAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:58 DEBUG : : >changeNotify: 
2021/12/13 05:49:58 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2/file3.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:49:58 DEBUG : : changeNotify: relativePath="dir2/file3.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:49:58 DEBUG : : >changeNotify: 
2021/12/13 05:49:58 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:49:58 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:49:58 DEBUG : : >changeNotify: 
2021/12/13 05:49:59 DEBUG : dir2: Rmdir: contains trashed file: "file3.DwAAAAAAAAA.gz"
2021/12/13 05:49:59 DEBUG : dir2: Rmdir: contains trashed file: "file3.json"
2021/12/13 05:49:59 DEBUG : dir2: Rmdir: contains trashed file: "file3.json"
2021/12/13 05:49:59 DEBUG : dir2: Rmdir: contains trashed file: "file3.DgAAAAAAAAA.gz"
2021/12/13 05:50:00 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
--- PASS: TestDirRename (33.17s)
=== RUN   TestErrorError
--- PASS: TestErrorError (0.00s)
=== RUN   TestFileMethods
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:50:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:01 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:01 DEBUG : : >changeNotify: 
2021/12/13 05:50:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:01 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:01 DEBUG : : >changeNotify: 
2021/12/13 05:50:01 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:01 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:01 DEBUG : : >changeNotify: 
2021/12/13 05:50:03 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:03 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:03 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:03 DEBUG : : >changeNotify: 
2021/12/13 05:50:03 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:03 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:03 DEBUG : : >changeNotify: 
2021/12/13 05:50:03 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:03 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:03 DEBUG : : >changeNotify: 
2021/12/13 05:50:04 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:05 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:05 DEBUG : : >changeNotify: 
2021/12/13 05:50:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:05 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:05 DEBUG : : >changeNotify: 
2021/12/13 05:50:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:05 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:05 DEBUG : : >changeNotify: 
2021/12/13 05:50:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:50:05 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:50:05 DEBUG : : >changeNotify: 
2021/12/13 05:50:05 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:05 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:05 DEBUG : : >changeNotify: 
2021/12/13 05:50:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:05 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:05 DEBUG : : >changeNotify: 
2021/12/13 05:50:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:05 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:05 DEBUG : : >changeNotify: 
2021/12/13 05:50:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:50:05 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:50:05 DEBUG : : >changeNotify: 
2021/12/13 05:50:05 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:50:05 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:50:05 DEBUG : : >changeNotify: 
2021/12/13 05:50:07 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:50:07 DEBUG : dir: Looking for writers
2021/12/13 05:50:07 DEBUG : file1: reading active writers
2021/12/13 05:50:07 DEBUG : : Looking for writers
2021/12/13 05:50:07 DEBUG : dir: reading active writers
2021/12/13 05:50:07 DEBUG : >WaitForWriters: 
2021/12/13 05:50:07 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:08 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:08 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:08 DEBUG : : invalidating directory cache
2021/12/13 05:50:08 DEBUG : : >changeNotify: 
2021/12/13 05:50:08 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:08 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:08 DEBUG : : >changeNotify: 
2021/12/13 05:50:08 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:08 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:08 DEBUG : : >changeNotify: 
2021/12/13 05:50:08 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:50:08 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:50:08 DEBUG : : >changeNotify: 
2021/12/13 05:50:08 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:50:08 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:50:08 DEBUG : : >changeNotify: 
2021/12/13 05:50:09 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:50:09 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
--- PASS: TestFileMethods (10.25s)
=== RUN   TestFileSetModTime
=== RUN   TestFileSetModTime/cache=off,open=false,write=false
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:50:11 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:11 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:11 DEBUG : : >changeNotify: 
2021/12/13 05:50:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:11 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:11 DEBUG : : >changeNotify: 
2021/12/13 05:50:11 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:11 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:11 DEBUG : : >changeNotify: 
2021/12/13 05:50:13 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:13 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:13 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:13 DEBUG : : >changeNotify: 
2021/12/13 05:50:13 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:13 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:13 DEBUG : : >changeNotify: 
2021/12/13 05:50:13 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:13 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:13 DEBUG : : >changeNotify: 
2021/12/13 05:50:15 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:15 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:15 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:15 DEBUG : : >changeNotify: 
2021/12/13 05:50:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:15 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:15 DEBUG : : >changeNotify: 
2021/12/13 05:50:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:15 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:15 DEBUG : : >changeNotify: 
2021/12/13 05:50:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:50:15 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:50:15 DEBUG : : >changeNotify: 
2021/12/13 05:50:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:15 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:15 DEBUG : : >changeNotify: 
2021/12/13 05:50:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:15 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:15 DEBUG : : >changeNotify: 
2021/12/13 05:50:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:15 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:15 DEBUG : : >changeNotify: 
2021/12/13 05:50:15 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:50:15 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:50:15 DEBUG : : >changeNotify: 
2021/12/13 05:50:17 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:17 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:17 DEBUG : pacer: Rate limited, increasing sleep to 1.584449368s
2021/12/13 05:50:17 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:17 DEBUG : pacer: Rate limited, increasing sleep to 2.30167901s
2021/12/13 05:50:17 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:50:17 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:17 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:17 DEBUG : : invalidating directory cache
2021/12/13 05:50:17 DEBUG : dir: invalidating directory cache
2021/12/13 05:50:17 DEBUG : : >changeNotify: 
2021/12/13 05:50:17 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:17 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:17 DEBUG : : >changeNotify: 
2021/12/13 05:50:17 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:17 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:17 DEBUG : : >changeNotify: 
2021/12/13 05:50:17 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:50:17 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:50:17 DEBUG : : >changeNotify: 
2021/12/13 05:50:17 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:50:17 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:50:17 DEBUG : : >changeNotify: 
2021/12/13 05:50:24 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:24 DEBUG : pacer: Rate limited, increasing sleep to 1.238837676s
2021/12/13 05:50:25 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:25 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:50:26 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:26 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:26 DEBUG : : >changeNotify: 
2021/12/13 05:50:26 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:26 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:26 DEBUG : : >changeNotify: 
2021/12/13 05:50:26 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:26 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:26 DEBUG : : >changeNotify: 
2021/12/13 05:50:26 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:50:26 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:50:26 DEBUG : : >changeNotify: 
2021/12/13 05:50:26 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:50:26 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:50:26 DEBUG : : >changeNotify: 
2021/12/13 05:50:26 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.bin" entryType 1
2021/12/13 05:50:26 DEBUG : : changeNotify: relativePath="time_test.bin.json", type=1
2021/12/13 05:50:26 DEBUG : : >changeNotify: 
2021/12/13 05:50:26 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.json" entryType 1
2021/12/13 05:50:26 DEBUG : : changeNotify: relativePath="time_test.json.json", type=1
2021/12/13 05:50:26 DEBUG : : >changeNotify: 
2021/12/13 05:50:26 DEBUG : Can set mod time: true
2021/12/13 05:50:26 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:26 DEBUG : pacer: Rate limited, increasing sleep to 1.371030974s
2021/12/13 05:50:27 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:27 DEBUG : pacer: Rate limited, increasing sleep to 2.532990154s
2021/12/13 05:50:27 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:27 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:28 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:50:28 DEBUG : dir/file1: Applied pending mod time 2011-12-25 12:59:59.123456789 +0000 UTC OK
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:31 DEBUG : : invalidating directory cache
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:31 DEBUG : dir2: invalidating directory cache
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.json" entryType 1
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="time_test.json.json", type=1
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.bin" entryType 1
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="time_test.bin.json", type=1
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.json" entryType 1
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="dir/file1.json.json", type=1
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.json" entryType 1
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="time_test.json.json", type=1
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.bin" entryType 1
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="time_test.bin.json", type=1
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:31 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir/file1.DgAAAAAAAAA.gz" entryType 1
2021/12/13 05:50:31 DEBUG : : changeNotify: relativePath="dir/file1.DgAAAAAAAAA.gz.json", type=1
2021/12/13 05:50:31 DEBUG : : >changeNotify: 
2021/12/13 05:50:32 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:32 DEBUG : pacer: Rate limited, increasing sleep to 1.71275463s
2021/12/13 05:50:32 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:50:32 DEBUG : WaitForWriters: timeout=30s
2021/12/13 05:50:32 DEBUG : dir: Looking for writers
2021/12/13 05:50:32 DEBUG : file1: reading active writers
2021/12/13 05:50:32 DEBUG : : Looking for writers
2021/12/13 05:50:32 DEBUG : dir: reading active writers
2021/12/13 05:50:32 DEBUG : >WaitForWriters: 
2021/12/13 05:50:34 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:34 DEBUG : pacer: Rate limited, increasing sleep to 1.533930038s
2021/12/13 05:50:34 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:34 DEBUG : pacer: Rate limited, increasing sleep to 2.747371939s
2021/12/13 05:50:36 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:50:39 DEBUG : dir: Rmdir: contains trashed file: "file1.DgAAAAAAAAA.gz"
2021/12/13 05:50:39 DEBUG : dir: Rmdir: contains trashed file: "file1.json"
2021/12/13 05:50:40 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
=== RUN   TestFileSetModTime/cache=off,open=true,write=false
    run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2", Local "Local file system at /tmp/rclone1570099853", Modify Window "1ms"
2021/12/13 05:50:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:40 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:40 DEBUG : : >changeNotify: 
2021/12/13 05:50:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:40 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:40 DEBUG : : >changeNotify: 
2021/12/13 05:50:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:40 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:40 DEBUG : : >changeNotify: 
2021/12/13 05:50:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.json" entryType 1
2021/12/13 05:50:40 DEBUG : : changeNotify: relativePath="time_test.json.json", type=1
2021/12/13 05:50:40 DEBUG : : >changeNotify: 
2021/12/13 05:50:40 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.bin" entryType 1
2021/12/13 05:50:40 DEBUG : : changeNotify: relativePath="time_test.bin.json", type=1
2021/12/13 05:50:40 DEBUG : : >changeNotify: 
2021/12/13 05:50:40 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:40 DEBUG : pacer: Rate limited, increasing sleep to 1.764314315s
2021/12/13 05:50:41 DEBUG : pacer: Reducing sleep to 0s
2021/12/13 05:50:41 DEBUG : Google drive root 'rclone-test-sacoqot7xumayed8hecabut2': Checking for changes on remote
2021/12/13 05:50:43 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "renamed empty directory" entryType 0
2021/12/13 05:50:43 DEBUG : : changeNotify: relativePath="renamed empty directory", type=0
2021/12/13 05:50:43 DEBUG : : >changeNotify: 
2021/12/13 05:50:43 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir2" entryType 0
2021/12/13 05:50:43 DEBUG : : changeNotify: relativePath="dir2", type=0
2021/12/13 05:50:43 DEBUG : : >changeNotify: 
2021/12/13 05:50:43 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "dir" entryType 0
2021/12/13 05:50:43 DEBUG : : changeNotify: relativePath="dir", type=0
2021/12/13 05:50:43 DEBUG : : >changeNotify: 
2021/12/13 05:50:43 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.json" entryType 1
2021/12/13 05:50:43 DEBUG : : changeNotify: relativePath="time_test.json.json", type=1
2021/12/13 05:50:43 DEBUG : : >changeNotify: 
2021/12/13 05:50:43 NOTICE: Compressed: TestCompressDrive:rclone-test-sacoqot7xumayed8hecabut2: path "time_test.bin" entryType 1
2021/12/13 05:50:43 DEBUG : : changeNotify: relativePath="time_test.bin.json", type=1
2021/12/13 05:50:43 DEBUG : : >changeNotify: 
2021/12/13 05:50:45 DEBUG : pacer: low level retry 1/1 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2021/12/13 05:50:45 DEBUG : pacer: Rate limited, increasing sleep to 1.848321743s
--- FAIL: TestFileSetModTime (35.05s)
    --- PASS: TestFileSetModTime/cache=off,open=false,write=false (29.84s)
    --- FAIL: TestFileSetModTime/cache=off,open=true,write=false (5.21s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x40 pc=0xb9e646]

goroutine 1669 [running]:
testing.tRunner.func1.2({0x16a1fc0, 0x29ddb20})
	/usr/local/go/src/testing/testing.go:1209 +0x24e
testing.tRunner.func1()
	/usr/local/go/src/testing/testing.go:1212 +0x218
panic({0x16a1fc0, 0x29ddb20})
	/usr/local/go/src/runtime/panic.go:1038 +0x215
github.com/rclone/rclone/backend/compress.(*Fs).putMetadata(0xc0000f6880, {0x1d20c28, 0xc000040058}, 0x1d20c28, {0x1d39f60, 0xc0009974f0}, {0x0, 0x0, 0x0}, 0xc0003eb980)
	/home/rclone/go/src/github.com/rclone/rclone/backend/compress/compress.go:629 +0x226
github.com/rclone/rclone/backend/compress.(*Fs).putWithCustomFunctions(0xc0000f6880, {0x1d20c28, 0xc000040058}, {0x1ceb000, 0xc0001b1230}, {0x1d39f60, 0xc0009974f0}, {0x0, 0x0, 0x0}, ...)
	/home/rclone/go/src/github.com/rclone/rclone/backend/compress/compress.go:658 +0x166
github.com/rclone/rclone/backend/compress.(*Fs).Put(0xc0000f6880, {0x1d20c28, 0xc000040058}, {0x1ce63a0, 0xc000991860}, {0x1d39f60, 0xc0009974f0}, {0x0, 0x0, 0x0})
	/home/rclone/go/src/github.com/rclone/rclone/backend/compress/compress.go:687 +0x2bd
github.com/rclone/rclone/fstest.(*Run).WriteObjectTo(0xc0001de7e0, {0x1d20c28, 0xc000040058}, {0x1d51198, 0xc0000f6880}, {0x195a507, 0x9}, {0x196308c, 0xe}, {0x1dcd64ff, ...}, ...)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:277 +0x432
github.com/rclone/rclone/fstest.(*Run).WriteObject(...)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:294
github.com/rclone/rclone/vfs.fileCreate(0x1e2e241, 0xf)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:26 +0x128
github.com/rclone/rclone/vfs.testFileSetModTime(0xc000ffd040, 0x0, 0x1, 0x0)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:95 +0xea
github.com/rclone/rclone/vfs.TestFileSetModTime.func1(0x0)
	/home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:160 +0x2f
testing.tRunner(0xc000ffd040, 0xc0003b17c0)
	/usr/local/go/src/testing/testing.go:1259 +0x102
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:1306 +0x35a
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestCompressDrive: -verbose" - Finished ERROR in 5m42.822901792s (try 1/5): exit status 2: Failed [TestFileSetModTime/cache=off,open=true,write=false]