Jottacloud crypt - 3 GB copy runs for a week without completing

Do you have any AV software or something that could be interfering with the writing of the rclone.conf file?

Is the drive it's on just a normal disk/ ntfs ?

I don't have any antivirus apart from windows defender. It's an m.2 SSD formatted as NTFS. I haven't made any changes to my setup since my initial post where I didn't get the not a regular file.

I just searched the source code for where this error could be coming in, and the light dawned :bulb:

The error is coming from the transaction rclone does to renew the token not the config file saving.

This should fix it hopefully!

v1.54.0-beta.5061.cef51d58a.fix-jottacloud-renewer on branch fix-jottacloud-renewer (uploaded in 15-30 mins)

Awesome! Testing it now :slight_smile:

I just noticed it had already done a token refresh and it was successful:

2021/01/12 19:00:38 DEBUG : rclone: Version "v1.54.0-beta.5061.cef51d58a.fix-jottacloud-renewer" starting with parameters ["rclone" "copy" "C:\\Users\\=REDACTED=" "jottacrypt_test:=REDACTED=" "-P" "-vv" "--config" "C:\\Commands\\rclone\\rclone.conf"]
2021/01/12 19:00:38 DEBUG : Creating backend with remote "C:\\Users\\=REDACTED="
2021/01/12 19:00:38 DEBUG : Using config file from "C:\\Commands\\rclone\\rclone.conf"
2021/01/12 19:00:38 DEBUG : fs cache: adding new entry for parent of "C:\\Users\\=REDACTED=", "//?/C:/Users/=REDACTED="
2021/01/12 19:00:38 DEBUG : Creating backend with remote "jottacrypt_test:=REDACTED="
2021/01/12 19:00:38 DEBUG : Creating backend with remote "jotta_test:=REDACTED="
2021-01-12 19:00:40 DEBUG : =REDACTED=: Bad size for decrypt: file is too short to be encrypted
2021-01-12 19:00:40 DEBUG : =REDACTED=: Bad size for decrypt: file is too short to be encrypted
2021-01-12 19:00:40 DEBUG : =REDACTED=: Bad size for decrypt: file is too short to be encrypted
2021-01-12 19:00:40 DEBUG : =REDACTED=: Sizes differ (src 3090499593 vs dst 0)
2021-01-12 19:00:40 DEBUG : =REDACTED=: Computing MD5 hash of encrypted source
2021-01-12 19:09:19 DEBUG : jottacloud root '=REDACTED=': Token expired - 1 uploads in progress - refreshing
2021-01-12 19:09:19 DEBUG : jotta_test: Loaded invalid token from config file - ignoring
2021-01-12 19:09:19 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2021-01-12 19:09:19 DEBUG : jotta_test: Saved new token in config file
2021-01-12 19:09:19 DEBUG : jottacloud root '=REDACTED=': Token refresh successful

The upload ETA is 2 days 17 hours (and slowly climbing). Hopefully, it's able to finish uploading this time :slight_smile:

Cross fingers. Let me know what happens :slightly_smiling_face:

1 Like
2021/01/12 19:00:38 DEBUG : rclone: Version "v1.54.0-beta.5061.cef51d58a.fix-jottacloud-renewer" starting with parameters ["rclone" "copy" "C:\\Users\\=REDACTED=" "jottacrypt_test:=REDACTED=" "-P" "-vv" "--config" "C:\\Commands\\rclone\\rclone.conf"]
2021/01/12 19:00:38 DEBUG : Creating backend with remote "C:\\Users\\=REDACTED="
2021/01/12 19:00:38 DEBUG : Using config file from "C:\\Commands\\rclone\\rclone.conf"
2021/01/12 19:00:38 DEBUG : fs cache: adding new entry for parent of "C:\\Users\\=REDACTED=", "//?/C:/Users/=REDACTED="
2021/01/12 19:00:38 DEBUG : Creating backend with remote "jottacrypt_test:=REDACTED="
2021/01/12 19:00:38 DEBUG : Creating backend with remote "jotta_test:=REDACTED="
2021-01-12 19:00:40 DEBUG : =REDACTED=: Bad size for decrypt: file is too short to be encrypted
2021-01-12 19:00:40 DEBUG : =REDACTED=: Bad size for decrypt: file is too short to be encrypted
2021-01-12 19:00:40 DEBUG : =REDACTED=: Bad size for decrypt: file is too short to be encrypted
2021-01-12 19:00:40 DEBUG : =REDACTED=: Sizes differ (src 3090499593 vs dst 0)
2021-01-12 19:00:40 DEBUG : =REDACTED=: Computing MD5 hash of encrypted source
2021-01-12 19:09:19 DEBUG : jottacloud root '=REDACTED=': Token expired - 1 uploads in progress - refreshing
2021-01-12 19:09:19 DEBUG : jotta_test: Loaded invalid token from config file - ignoring
2021-01-12 19:09:19 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2021-01-12 19:09:19 DEBUG : jotta_test: Saved new token in config file
2021-01-12 19:09:19 DEBUG : jottacloud root '=REDACTED=': Token refresh successful
2021-01-12 20:09:19 DEBUG : jottacloud root '=REDACTED=': Token expired - 1 uploads in progress - refreshing
2021-01-12 20:09:19 DEBUG : jotta_test: Loaded invalid token from config file - ignoring
2021-01-12 20:09:19 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2021-01-12 20:09:19 DEBUG : jotta_test: Saved new token in config file
2021-01-12 20:09:20 DEBUG : jottacloud root '=REDACTED=': Token refresh successful
2021-01-12 20:24:51 DEBUG : =REDACTED=: Received error: Post "https://069-up-e.jotta.cloud/files/v1/upload/=REDACTED=": write tcp =REDACTED=->=REDACTED=: wsasend: An existing connection was forcibly closed by the remote host. - low level retry 1/10
2021-01-12 20:24:51 DEBUG : =REDACTED=: Computing MD5 hash of encrypted source
2021-01-12 21:09:19 DEBUG : jottacloud root '=REDACTED=': Token expired - 1 uploads in progress - refreshing
2021-01-12 21:09:19 DEBUG : jotta_test: Loaded invalid token from config file - ignoring
2021-01-12 21:09:20 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2021-01-12 21:09:20 DEBUG : jotta_test: Saved new token in config file
2021-01-12 21:09:20 DEBUG : jottacloud root '=REDACTED=': Token refresh successful
2021-01-12 22:09:20 DEBUG : jottacloud root '=REDACTED=': Token expired - 1 uploads in progress - refreshing
2021-01-12 22:09:20 DEBUG : jotta_test: Loaded invalid token from config file - ignoring
2021-01-12 22:09:20 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2021-01-12 22:09:20 DEBUG : jotta_test: Saved new token in config file
2021-01-12 22:09:20 DEBUG : jottacloud root '=REDACTED=': Token refresh successful
2021-01-12 23:09:20 DEBUG : jottacloud root '=REDACTED=': Token expired - 1 uploads in progress - refreshing
2021-01-12 23:09:20 DEBUG : jotta_test: Loaded invalid token from config file - ignoring
2021-01-12 23:09:20 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2021-01-12 23:09:20 DEBUG : jotta_test: Saved new token in config file
2021-01-12 23:09:20 DEBUG : jottacloud root '=REDACTED=': Token refresh successful
2021-01-13 00:09:20 DEBUG : jottacloud root '=REDACTED=': Token expired - 1 uploads in progress - refreshing
2021-01-13 00:09:20 DEBUG : jotta_test: Loaded invalid token from config file - ignoring
2021-01-13 00:09:20 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2021-01-13 00:09:20 DEBUG : jotta_test: Saved new token in config file
2021-01-13 00:09:20 DEBUG : jottacloud root '=REDACTED=': Token refresh successful
2021-01-13 01:09:20 DEBUG : jottacloud root '=REDACTED=': Token expired - 1 uploads in progress - refreshing
2021-01-13 01:09:20 DEBUG : jotta_test: Loaded invalid token from config file - ignoring
2021-01-13 01:09:20 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2021-01-13 01:09:20 DEBUG : jotta_test: Saved new token in config file
2021-01-13 01:09:20 DEBUG : jottacloud root '=REDACTED=': Token refresh successful
2021-01-13 02:09:20 DEBUG : jottacloud root '=REDACTED=': Token expired - 1 uploads in progress - refreshing
2021-01-13 02:09:20 DEBUG : jotta_test: Loaded invalid token from config file - ignoring
2021-01-13 02:09:20 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2021-01-13 02:09:20 DEBUG : jotta_test: Saved new token in config file
2021-01-13 02:09:20 DEBUG : jottacloud root '=REDACTED=': Token refresh successful

Something still isn't right. The total file size doesn't match:
rclone

That's odd! How big is the file really (in bytes).

Things look as though they are proceeding OK though if rather slowly.

From the logs above I see the file is 3090499593 bytes.

This is this many GB

>>> 3090499593./1024/1024/1024
2.8782520378008485

So the second figure is correct.

I wonder if there has been some retries which have bumped up the total. I expect that is the problem.

The original file is 3090499593 bytes. Yes, I can see there has been one low-level retry by looking at my logs.

OK that makes sense. Cross fingers that it completes!

1 Like

I've merged the second fix to master now which means it will be in the latest beta in 15-30 mins and released in v1.54 as I can see it is working from your logs.

I'm still interested in whether your upload completes :slight_smile:

Doesn't look so promising... It has gone past the original file size now.
rclone

That’s normally retries so pretty normal and perhaps more normal over such a long period of time.

Are you saying it's not a bug when the remaining file size is greater than the actual file size? I thought it was supposed to be calculating how much of the file's data it had transferred, not how much data it had transferred in total due to failed attempts.

Correct as that’s not a bug as retries can make it transfer more than the actual file size.

This shows that 3G has been transferred but only 33% * 2.87G = 0.9G of the file has been uploaded.

This means that rclone is doing a lot of retries which is unfortunate.

I suspect Jotta is rate limiting rclone and rejecting the uploads.

Is the 33% still going up? if so your file is still being transferred despite the retries.

It has started over from 0%
rclone__
But CMD froze again, so I don't think the transfer is running anymore.

:frowning: What error are you getting from Jottacloud on the retries?

Since the CMD window is frozen, I can't interact with or scroll through the logs, but they look the same as the previous logs I shared, except the low-level retries did 3 and 4 out of 10 attempts instead of just 1.

Hmm, this is working better than it was now the token is being refreshed properly, but those errors wsasend: An existing connection was forcibly closed by the remote host. indicate that Jottacloud is rate limiting you I think.

I think it is worth trying harder with Jottacloud support to see if your account has been limited or something like that.

1 Like