2023/09/29 15:20:46 DEBUG : rclone: Version "v1.64.0" starting with parameters ["rclone" "copyto" "file_v2.bin" "data:test/1" "-vv" "--dump=responses" "--retries=1"]
2023/09/29 15:20:46 DEBUG : Creating backend with remote "file_v2.bin"
2023/09/29 15:20:46 DEBUG : Using config file from "/Users/kagami/.config/rclone/rclone.conf"
2023/09/29 15:20:46 DEBUG : fs cache: adding new entry for parent of "file_v2.bin", "/Users/kagami/code/tmp/onedrive_bug"
2023/09/29 15:20:46 DEBUG : Creating backend with remote "data:test/"
2023/09/29 15:20:46 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:46 DEBUG : HTTP REQUEST (req 0x14000c08500)
2023/09/29 15:20:46 DEBUG : GET /v1.0/drives/__REDACTED__/root HTTP/1.1
Host: graph.microsoft.com
User-Agent: rclone/v1.64.0
Authorization: XXXX
Accept-Encoding: gzip

2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:46 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:46 DEBUG : HTTP RESPONSE (req 0x14000c08500)
2023/09/29 15:20:46 DEBUG : HTTP/1.1 200 OK
Transfer-Encoding: chunked
Cache-Control: private
Client-Request-Id: cfcd8799-aecc-48ae-a92f-6bd5dbd97516
Content-Type: application/json;odata.metadata=minimal;odata.streaming=true;IEEE754Compatible=false;charset=utf-8
Date: Fri, 29 Sep 2023 12:20:45 GMT
Odata-Version: 4.0
Request-Id: cfcd8799-aecc-48ae-a92f-6bd5dbd97516
Strict-Transport-Security: max-age=31536000
Vary: Accept-Encoding
X-Ms-Ags-Diagnostic: {"ServerInfo":{"DataCenter":"West Europe","Slice":"E","Ring":"5","ScaleUnit":"002","RoleInstance":"AM2PEPF0000BE2D"}}

3dc
{"@odata.context":"https://graph.microsoft.com/v1.0/$metadata#drives('__REDACTED__')/root/$entity","createdDateTime":"2022-09-02T12:39:09.737Z","cTag":"adDozMzY0NjRCMDZGMjVEMkY2ITEwMS42MzgzMTU4NjgyNDcyMDAwMDA","eTag":"aMzM2NDY0QjA2RjI1RDJGNiExMDEuMQ","id":"__REDACTED__!101","lastModifiedDateTime":"2023-09-29T12:20:24.72Z","name":"root","size":63837660031,"webUrl":"https://onedrive.live.com/?cid=__REDACTED__","createdBy":{"application":{"displayName":"OneDrive","id":"481710a4"},"user":{"displayName":"Backup Data","id":"__REDACTED__"}},"lastModifiedBy":{"application":{"displayName":"OneDrive","id":"481710a4"},"user":{"displayName":"Backup Data","id":"__REDACTED__"}},"parentReference":{"driveId":"__REDACTED__","driveType":"personal"},"fileSystemInfo":{"createdDateTime":"2022-09-02T12:39:09.736Z","lastModifiedDateTime":"2023-05-13T05:22:45.033Z"},"folder":{"childCount":3,"view":{"viewType":"thumbnails","sortBy":"name","sortOrder":"ascending"}},"root":{}}
0

2023/09/29 15:20:46 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:46 DEBUG : HTTP REQUEST (req 0x1400020be00)
2023/09/29 15:20:46 DEBUG : GET /v1.0/drives/__REDACTED__/items/__REDACTED__!101:/test: HTTP/1.1
Host: graph.microsoft.com
User-Agent: rclone/v1.64.0
Authorization: XXXX
Accept-Encoding: gzip

2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:46 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:46 DEBUG : HTTP RESPONSE (req 0x1400020be00)
2023/09/29 15:20:46 DEBUG : HTTP/1.1 200 OK
Transfer-Encoding: chunked
Cache-Control: private
Client-Request-Id: bfbd5e77-ada8-4a83-aef6-c157f26f8ae1
Content-Type: application/json;odata.metadata=minimal;odata.streaming=true;IEEE754Compatible=false;charset=utf-8
Date: Fri, 29 Sep 2023 12:20:45 GMT
Odata-Version: 4.0
Request-Id: bfbd5e77-ada8-4a83-aef6-c157f26f8ae1
Strict-Transport-Security: max-age=31536000
Vary: Accept-Encoding
X-Ms-Ags-Diagnostic: {"ServerInfo":{"DataCenter":"West Europe","Slice":"E","Ring":"5","ScaleUnit":"002","RoleInstance":"AM2PEPF0000BE2D"}}

3f0
{"@odata.context":"https://graph.microsoft.com/v1.0/$metadata#drives('__REDACTED__')/items/$entity","createdDateTime":"2023-09-29T12:20:23.7Z","cTag":"adDozMzY0NjRCMDZGMjVEMkY2ITE5MDA3LjYzODMxNTg2ODI0NzIwMDAwMA","eTag":"aMzM2NDY0QjA2RjI1RDJGNiExOTAwNy4w","id":"__REDACTED__!19007","lastModifiedDateTime":"2023-09-29T12:20:24.72Z","name":"test","size":5600,"webUrl":"https://1drv.ms/f/s!__REDACTED__","createdBy":{"application":{"displayName":"rclone","id":"45123313"},"user":{"displayName":"Backup Data","id":"__REDACTED__"}},"lastModifiedBy":{"application":{"displayName":"rclone","id":"45123313"},"user":{"displayName":"Backup Data","id":"__REDACTED__"}},"parentReference":{"driveId":"__REDACTED__","driveType":"personal","id":"__REDACTED__!101","path":"/drive/root:"},"fileSystemInfo":{"createdDateTime":"2023-09-29T12:20:23.7Z","lastModifiedDateTime":"2023-09-29T12:20:23.7Z"},"folder":{"childCount":1,"view":{"viewType":"thumbnails","sortBy":"name","sortOrder":"ascending"}}}
0

2023/09/29 15:20:46 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:46 DEBUG : fs cache: renaming cache item "data:test/" to be canonical "data:test"
2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:46 DEBUG : HTTP REQUEST (req 0x14000bbe700)
2023/09/29 15:20:46 DEBUG : GET /v1.0/drives/__REDACTED__/items/__REDACTED__!19007:/1: HTTP/1.1
Host: graph.microsoft.com
User-Agent: rclone/v1.64.0
Authorization: XXXX
Accept-Encoding: gzip

2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:46 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:46 DEBUG : HTTP RESPONSE (req 0x14000bbe700)
2023/09/29 15:20:46 DEBUG : HTTP/1.1 200 OK
Transfer-Encoding: chunked
Cache-Control: no-store
Client-Request-Id: 6c212880-1765-4e87-bf39-4bf5c531c900
Content-Type: application/json;odata.metadata=minimal;odata.streaming=true;IEEE754Compatible=false;charset=utf-8
Date: Fri, 29 Sep 2023 12:20:45 GMT
Odata-Version: 4.0
Request-Id: 6c212880-1765-4e87-bf39-4bf5c531c900
Strict-Transport-Security: max-age=31536000
Vary: Accept-Encoding
X-Ms-Ags-Diagnostic: {"ServerInfo":{"DataCenter":"West Europe","Slice":"E","Ring":"5","ScaleUnit":"002","RoleInstance":"AM2PEPF0000BE2D"}}

606
{"@odata.context":"https://graph.microsoft.com/v1.0/$metadata#drives('__REDACTED__')/items/$entity","@microsoft.graph.downloadUrl":"https://public.db.files.1drv.com/__REDACTED__","createdDateTime":"2023-09-29T12:20:24.37Z","cTag":"aYzozMzY0NjRCMDZGMjVEMkY2ITE5MDA4LjI1Nw","eTag":"aMzM2NDY0QjA2RjI1RDJGNiExOTAwOC4x","id":"__REDACTED__!19008","lastModifiedDateTime":"2023-09-29T12:20:24.72Z","name":"1","size":5600,"webUrl":"https://1drv.ms/u/s!__REDACTED__","reactions":{"commentCount":0},"createdBy":{"application":{"displayName":"rclone","id":"45123313"},"user":{"displayName":"Backup Data","id":"__REDACTED__"}},"lastModifiedBy":{"application":{"displayName":"rclone","id":"45123313"},"user":{"displayName":"Backup Data","id":"__REDACTED__"}},"parentReference":{"driveId":"__REDACTED__","driveType":"personal","id":"__REDACTED__!19007","name":"test","path":"/drive/root:/test"},"file":{"mimeType":"application/octet-stream","hashes":{"quickXorHash":"AAAAAAAAAAAAAAAg4BUAAAAAAAA=","sha1Hash":"29E5F5D3A82C13F6749BCC2143F1FAE14EDC7A1D","sha256Hash":"CF5946E5BD45445AD34A778066CF49442456F16A198229F592C2EBB6B416CD85"}},"fileSystemInfo":{"createdDateTime":"2023-09-28T21:00:00Z","lastModifiedDateTime":"2023-09-28T21:00:00Z"}}
0

2023/09/29 15:20:46 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:46 DEBUG : file_v2.bin: Modification times differ by -1m0s: 2023-09-29 00:01:00 +0300 MSK, 2023-09-28 21:00:00 +0000 UTC
2023/09/29 15:20:46 DEBUG : file_v2.bin: quickxor = 000000000000000000000000e015000000000000 (Local file system at /Users/kagami/code/tmp/onedrive_bug)
2023/09/29 15:20:46 DEBUG : 1: quickxor = 000000000000000000000020e015000000000000 (OneDrive root 'test')
2023/09/29 15:20:46 DEBUG : file_v2.bin: quickxor differ
2023/09/29 15:20:46 DEBUG : 1: Starting multipart upload
2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:46 DEBUG : HTTP REQUEST (req 0x14000bbeb00)
2023/09/29 15:20:46 DEBUG : POST /v1.0/drives/__REDACTED__/items/__REDACTED__!19007:/1:/createUploadSession HTTP/1.1
Host: graph.microsoft.com
User-Agent: rclone/v1.64.0
Content-Length: 116
Authorization: XXXX
Content-Type: application/json
Accept-Encoding: gzip

2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:46 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:46 DEBUG : HTTP RESPONSE (req 0x14000bbeb00)
2023/09/29 15:20:46 DEBUG : HTTP/1.1 200 OK
Transfer-Encoding: chunked
Cache-Control: no-store
Client-Request-Id: f12d319b-c6d4-4681-88d6-a22a7750895a
Content-Type: application/json;odata.metadata=minimal;odata.streaming=true;IEEE754Compatible=false;charset=utf-8
Date: Fri, 29 Sep 2023 12:20:46 GMT
Location: https://graph.microsoft.com
Odata-Version: 4.0
Request-Id: f12d319b-c6d4-4681-88d6-a22a7750895a
Strict-Transport-Security: max-age=31536000
Vary: Accept-Encoding
X-Ms-Ags-Diagnostic: {"ServerInfo":{"DataCenter":"West Europe","Slice":"E","Ring":"5","ScaleUnit":"002","RoleInstance":"AM2PEPF0000BE2D"}}

505
{"@odata.context":"https://graph.microsoft.com/v1.0/$metadata#microsoft.graph.uploadSession","expirationDateTime":"2023-10-04T12:20:46.869Z","nextExpectedRanges":["0-"],"uploadUrl":"https://api.onedrive.com/rup/__REDACTED__/__REDACTED__"}
0

2023/09/29 15:20:46 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:46 DEBUG : 1: Uploading segment 0/5600 size 5600
2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:46 DEBUG : HTTP REQUEST (req 0x14000b18300)
2023/09/29 15:20:46 DEBUG : PUT /rup/__REDACTED__/__REDACTED__ HTTP/1.1
Host: api.onedrive.com
User-Agent: rclone/v1.64.0
Content-Length: 5600
Authorization: XXXX
Content-Range: bytes 0-5599/5600
Accept-Encoding: gzip

2023/09/29 15:20:46 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:47 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:47 DEBUG : HTTP RESPONSE (req 0x14000b18300)
2023/09/29 15:20:47 DEBUG : HTTP/2.0 400 Bad Request
Content-Type: application/json; charset=utf-8
Date: Fri, 29 Sep 2023 12:20:46 GMT
Ms-Cv: zpdCc0ItmkGDk9JSzOnjVg.0
P3p: CP="BUS CUR CONo FIN IVDo ONL OUR PHY SAMo TELo"
Strict-Transport-Security: max-age=31536000; includeSubDomains
Www-Authenticate: Bearer realm="OneDriveAPI", error="invalid_token", error_description="Invalid auth token"
X-Asmversion: UNKNOWN; 19.1248.908.2006
X-Cache: CONFIG_NOCACHE
X-Msedge-Ref: Ref A: 6B2DA31CBA1C48E09D66C71B16E231C7 Ref B: STOEDGE0911 Ref C: 2023-09-29T12:20:47Z
X-Msnserver: DB5PPF8DE765941
X-Qosstats: {"ApiId":0,"ResultType":2,"SourcePropertyId":0,"TargetPropertyId":42}
X-Throwsite: 7cfe.d208

{"error":{"code":"invalidRequest","message":"Bad Argument"}}
2023/09/29 15:20:47 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:47 DEBUG : 1: Cancelling multipart upload: invalidRequest: Bad Argument
2023/09/29 15:20:47 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:47 DEBUG : HTTP REQUEST (req 0x14000b18900)
2023/09/29 15:20:47 DEBUG : DELETE /rup/__REDACTED__/__REDACTED__ HTTP/1.1
Host: api.onedrive.com
User-Agent: rclone/v1.64.0
Authorization: XXXX
Accept-Encoding: gzip

2023/09/29 15:20:47 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023/09/29 15:20:47 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:47 DEBUG : HTTP RESPONSE (req 0x14000b18900)
2023/09/29 15:20:47 DEBUG : HTTP/2.0 204 No Content
Connection: close
Date: Fri, 29 Sep 2023 12:20:47 GMT
Ms-Cv: j7QiZAyVXEGg3jPkynkafg.0
P3p: CP="BUS CUR CONo FIN IVDo ONL OUR PHY SAMo TELo"
Strict-Transport-Security: max-age=31536000; includeSubDomains
Www-Authenticate: Bearer realm="OneDriveAPI", error="invalid_token", error_description="Invalid auth token"
X-Asmversion: UNKNOWN; 19.1248.908.2006
X-Cache: CONFIG_NOCACHE
X-Msedge-Ref: Ref A: A20A1E3313A34C08B71F222CCC9C110E Ref B: STOEDGE0911 Ref C: 2023-09-29T12:20:47Z
X-Msnserver: DB5PPF82E7B4F6D

2023/09/29 15:20:47 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023/09/29 15:20:47 ERROR : file_v2.bin: Failed to copy: invalidRequest: Bad Argument
2023/09/29 15:20:47 ERROR : Attempt 1/1 failed with 1 errors and: invalidRequest: Bad Argument
2023/09/29 15:20:47 INFO  : 
Transferred:   	    5.469 KiB / 5.469 KiB, 100%, 0 B/s, ETA -
Errors:                 1 (retrying may help)
Elapsed time:         1.1s

2023/09/29 15:20:47 DEBUG : 11 go routines active
2023/09/29 15:20:47 Failed to copyto: invalidRequest: Bad Argument