100+ percents of copying on last release

Still on the subject of retries on opendrive want to report 1.50.1 I installed today don't fix this bug.
Please take a look to the screenshots. As you can see 5 files was uploaded successfully but they are still uploading over 100%. The only way to stop them is to Ctrl'C Rclone. So I have to wait until the last of 16 files will have been uploaded and then stop. It's very sad because all this time I will waste traffic and time to upload already uploaded files. And I don't know how to fix it :frowning:


I think rclone will be retrying failed uploads, hence that is why it has uploaded > 100%

They are not actually failed. They were checked ok. Also I downloaded several and unzipped them. They are absolutely ok. But RCLONE for some strange reason didn’t receive an successful upload message or smth about.

As a follow-up... I’ve been monitoring RCLONE upload to OpenDrive for two months and wanna mention:

  1. this issues raise only with large files over 10G.
  2. on 1.49.2 this issue raises the error File already closed. Stopped the uploading and added the next file to a queue. As I said before the file was ok despite the error.
  3. now this issue (seems like) not stops the uploading but continues it over and over. I’m sure it’s much worse. In previous version the uploading of other new files was not stopped as in the new one.
  4. I stopped using 1.49.2 because of another issue I can’t live with (OpenDrive tries to fix it now). 1.50.1 has no this one but has the overuploading bug. I can live with it but not so good and it’s a bug. Maybe it’s time to fix it?

Delighted to fix a bug if we can work out what is going on!

The first start would be a log with -vv.

Ok. I have to wait until my files have been uploaded and then I will start a new upload with --vv. Where should I send a log?

You can post a link here or email it to me nick@craig-wood.com with a link to this forum post in.

Ok, thanks, I’ll do

1 Like

Here's a result. Uploaded 15 files (16 at all but 1 of them was uploaded before so only checked). Manually stopped on 127%. All the files was successfully uploaded but Rclone knew nothing about it and continued uploading. Then I checked all the files successfully as well. The log of upload and check here: https://www.dropbox.com/s/y64rj2ogtw2421q/RcloneLog.zip?dl=0

It would be great to have it fixed.


I think these are the problem

2019-11-06 12:55:32 DEBUG : pacer: low level retry 2/10 (error This file is already being processed. Please wait until previous upload operation will be finished. (Error 423)) 
2019-11-06 12:55:32 DEBUG : pacer: Rate limited, increasing sleep to 20ms 
2019-11-06 12:55:44 DEBUG : pacer: Reducing sleep to 10ms 

This means that opendrive rejected the chunk and rclone had to send it again. I had a look in the opendrive API docs and I couldn't see that referenced: https://www.opendrive.com/wp-content/uploads/guides/OpenDrive_API_guide.pdf

In fact looking more closely at the log I see lots of different errors

Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: Invalid temp file location (Error 400) - low level retry 1/10 
low level retry 1/10 (error Post https://dev.opendrive.com/api/v1/upload/close_file_upload.json: net/http: timeout awaiting response headers) 
low level retry 1/10 (error Unknown 502 Bad Gateway (Error 502)) 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: This file is already being processed. Please wait until previous upload operation will be finished. (Error 423) - low level retry 1/10 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: This file is already being processed. Please wait until previous upload operation will be finished. (Error 423) - low level retry 1/10 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: This file is already being processed. Please wait until previous upload operation will be finished. (Error 423) - low level retry 1/10 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 
Received error: failed to create file: File update error. Temp file doesn't exist. Please restart task. (Error 400) - low level retry 1/10 

That is why you are seeing uploads > 100%.- rclone is having to retry files.

I think maybe the reason this didn't show for older rclone versions is that it didn't count the retries in the upload traffic.

So you mean the files were not uploaded correctly when I stopped Rclone manually?
But:

  1. when Rclone uploaded 100% opendrive decided they are ok and added them to it's log (as you can see) despite they are still was uploading over 100%;
  2. the same Rclone checks them successfully;
  3. being downloaded they was unzipped with no issues.
    What does it mean? Despite of Rclone messages they was uploaded correctly. So these messages are incorrect (or have no sense). Rclone should stop overuploading and add a next file to a queue.
    Am I correct?

Maybe after 100% uploading but before retrying over and over Rclone should do a check, and if it is ok do not keep on retrying?

That is what the error messages say

I guess what is happening is that opendrive says there is an error but the file is actually OK.

Can you try your transfer with --transfers 1 - maybe opendrive doesn't like multiple uploads at once for some reason.

So the problem is in Opendrive API, isn't it?

I tried, the speed was dramatically low.

I just tried to download some files uploaded yesterday (from a browser just clicking on a link). They was downloaded but couldn't unzip. There was a CRC error.
Could you tell me is Rclone check a guaranty the files are absolutely ok? As I think it calculates some hashes (MD5, CRC?) on source and target, compares them and if they are equal tells ok. Is it correct?
Should I try to download all the files (with Rclone) to check them additionally or it's for nothing?

Updated. Downloaded these files using Rclone and they unzipped ok. So the problem was in simple browser download.
Now I'm downloading another 34G file to test. 10h and 253G at the moment. On target it is 29G now (was 31G 8h ago). Nobody knows when (if) it will be downloaded :frowning:

One question. Why these mad percents? Imagine we're trying to upload (download) a chunk. It's failed with an error. Why you mark it as succeeded and add to total percents? Why just not to ignore it and try to upload next time. In this case there will be no percents more than 100%.

A good question :slight_smile: The accounting in rclone is rather complicated but maybe we could fix it somehow!

Only one issue. Now uploading on 1.50.1 I wait until 100% and despite a file is still uploading over 100% stop it and it's ok. If you fixed these crazy percents how could I realize it's time to stop? Only using a target log.

Rclone should stop when it thinks the file is correctly uploaded.

I realized. But this time might never become but actually the file has been correctly uploaded. In other words Rclone don't know what's going on actually. I's a main issue :frowning:

I tried to download with Rclone the file uploaded 3 days ago 2 times. With no success. 34G file was downloaded on ~10 Mb/s speed about a day each time with many times overdownloading and finally crashed. The file was on target but corrupted. I was tired and thought to stop this monkey business: I uploaded files (with big troubles but did) but couldn't download it.
Finally I installed native OpenDrive app to my Mac and tried to download this file. Downloaded in 1.5 hours on 12 Mb/s speed. And file is ok: md5 is equal to original and uploaded, 7zip found no issues. So the problem is solved. I can download my files. Without Rclone but...
So now I'm tending not to use Rclone anymore with Opendrive. More troubles than help.

This is due to the opendrive API I think - I'm not sure what rclone can do to fix it.

I'm glad your files are OK and sorry for the problems you've been having.

This really needs someone to dig into the Opendrive API a bit more - have you got the time and skills to do that?

I'm having same issue but with Jottacloud.
See the log here https://pastebin.com/JMMsqkF4

I also noticed that the overall transfer size increases as the transfers progress.
I checked the files on Jottacloud and there were 40GB worth of files (log file shows 80GB).
So is rclone really transferring the files twice?