Poor performance and errors from Dreamhost

What is the problem you are having with rclone?

I've been using rclone to sync from Dreamhost's DreamObjects service for quite some time successfully. Lately though I'm getting poor performance and strange errors. I'm sure this is on the Dreamhost side but maybe there are workarounds I can do on the rclone side.

I was thinking of trying to turn off concurrent downloads, but I don't see an option for that in the S3 flags.

What is your rclone version (output from rclone version)

Which OS you are using and how many bits (eg Windows 7, 64 bit)

C:\Users\tv>rclone --version
rclone v1.55.1
- os/type: windows
- os/arch: amd64
- go/version: go1.16.3
- go/linking: dynamic
- go/tags: cmount

Which cloud storage system are you using? (eg Google Drive)

Dreamhost/DreamObjects, S3 compatible

Locally I'm saving to a network drive.

The command you were trying to run (eg rclone copy /tmp remote:tmp)

rclone sync dreamobjects:laundry/youtube/timeline/downloads m:\youtube --progress

The rclone config contents with secrets removed.

C:\Users\tv>rclone config show
[dreamobjects]
type = s3
provider = Dreamhost
env_auth = false
access_key_id = **
secret_access_key = **
region = us-east-1
endpoint = objects-us-east-1.dream.io

A log from the command with the -vv flag

C:\Source>rclone sync dreamobjects:laundry/youtube/timeline/downloads m:\youtube --progress
2021-06-12 07:48:41 ERROR : 1623168030/youtube.com!watch/media.mp4: Failed to set sparse: DeviceIoControl FSCTL_SET_SPARSE: Incorrect function.
2021-06-12 07:48:44 ERROR : 1622390302/youtube.com!watch/media.mp4: Failed to set sparse: DeviceIoControl FSCTL_SET_SPARSE: Incorrect function.
2021-06-12 07:52:46 ERROR : 1622390302/youtube.com!watch/media.mp4: Failed to set sparse: DeviceIoControl FSCTL_SET_SPARSE: Incorrect function.
2021-06-12 07:52:57 NOTICE: 1623027603/youtube.com!watch/media.mp4: Removing partially written file on error: unexpected EOF
2021-06-12 07:55:17 ERROR : 1623168030/youtube.com!watch/media.mp4: Failed to set sparse: DeviceIoControl FSCTL_SET_SPARSE: Incorrect function.
2021-06-12 07:55:24 ERROR : 1622390302/youtube.com!watch/media.mp4: Failed to copy: multipart copy: failed to open source: SerializationError: failed to unmarshal error message
        status code: 502, request id: , host id:
caused by: UnmarshalError: failed to unmarshal error message
        00000000  3c 68 74 6d 6c 3e 3c 62  6f 64 79 3e 3c 68 31 3e  |<html><body><h1>|
00000010  35 30 32 20 42 61 64 20  47 61 74 65 77 61 79 3c  |502 Bad Gateway<|
00000020  2f 68 31 3e 0a 54 68 65  20 73 65 72 76 65 72 20  |/h1>.The server |
00000030  72 65 74 75 72 6e 65 64  20 61 6e 20 69 6e 76 61  |returned an inva|
00000040  6c 69 64 20 6f 72 20 69  6e 63 6f 6d 70 6c 65 74  |lid or incomplet|
00000050  65 20 72 65 73 70 6f 6e  73 65 2e 0a 3c 2f 62 6f  |e response..</bo|
00000060  64 79 3e 3c 2f 68 74 6d  6c 3e 0a                 |dy></html>.|

caused by: expected element type <Error> but have <html>
2021-06-12 07:57:13 NOTICE: 1623027603/youtube.com!watch/media.mp4: Removing partially written file on error: unexpected EOF
2021-06-12 08:02:32 ERROR : 1623168030/youtube.com!watch/media.mp4: Failed to set sparse: DeviceIoControl FSCTL_SET_SPARSE: Incorrect function.
2021-06-12 08:04:06 NOTICE: 1623027603/youtube.com!watch/media.mp4: Removing partially written file on error: unexpected EOF
2021-06-12 08:05:52 ERROR : 1623168030/youtube.com!watch/media.mp4: Failed to set sparse: DeviceIoControl FSCTL_SET_SPARSE: Incorrect function.
2021-06-12 08:07:43 NOTICE: 1623027603/youtube.com!watch/media.mp4: Removing partially written file on error: unexpected EOF
2021-06-12 08:08:18 ERROR : 1623168030/youtube.com!watch/media.mp4: Failed to set sparse: DeviceIoControl FSCTL_SET_SPARSE: Incorrect function.
2021-06-12 08:11:32 NOTICE: 1623027603/youtube.com!watch/media.mp4: Removing partially written file on error: unexpected EOF
2021-06-12 08:13:52 ERROR : 1623168030/youtube.com!watch/media.mp4: Failed to set sparse: DeviceIoControl FSCTL_SET_SPARSE: Incorrect function.
2021-06-12 08:15:48 NOTICE: 1623027603/youtube.com!watch/media.mp4: Removing partially written file on error: unexpected EOF
2021-06-12 08:15:51 ERROR : 1623168030/youtube.com!watch/media.mp4: Failed to copy: multipart copy: failed to open source: SerializationError: failed to unmarshal error message
        status code: 502, request id: , host id:
caused by: UnmarshalError: failed to unmarshal error message
        00000000  3c 68 74 6d 6c 3e 3c 62  6f 64 79 3e 3c 68 31 3e  |<html><body><h1>|
00000010  35 30 32 20 42 61 64 20  47 61 74 65 77 61 79 3c  |502 Bad Gateway<|
00000020  2f 68 31 3e 0a 54 68 65  20 73 65 72 76 65 72 20  |/h1>.The server |
00000030  72 65 74 75 72 6e 65 64  20 61 6e 20 69 6e 76 61  |returned an inva|
00000040  6c 69 64 20 6f 72 20 69  6e 63 6f 6d 70 6c 65 74  |lid or incomplet|
00000050  65 20 72 65 73 70 6f 6e  73 65 2e 0a 3c 2f 62 6f  |e response..</bo|
00000060  64 79 3e 3c 2f 68 74 6d  6c 3e 0a                 |dy></html>.|

caused by: expected element type <Error> but have <html>
2021-06-12 08:20:10 NOTICE: 1623027603/youtube.com!watch/media.mp4: Removing partially written file on error: unexpected EOF

hello and welcome to the forum,

what is the operating system?

not sure this is a problem with dreamhost, as you are getting errors about spare files?
might try to disable that
--local-no-sparse Disable sparse files for multi-thread downloads

could be an issue with rclone

what is file system type fo the network drive, ntfs or what?

if you sync to local storage, such as the c: drive, do you get errors?

you can set --transfers=1

and https://rclone.org/docs/#multi-thread-streams-n

Thanks! This is on the latest Windows 10 x64. The network drive presents as NTFS. It's a Drobo NAS.

I think the sparse errors have been showing for a while, but I've ignored them and it's been ok. I added --local-no-sparse to my command. Those errors went away.

I was searching the flags for "concurrent" so I missed the --transfers=1 option. I added that too.

I'm still getting errors though. The transfer works for a while and then dies. See attached.

does this error happen every time, if so, then let's do testing by copying a single file, not a folder.

i would run this, either for a single file or a folder

rclone sync dreamobjects:laundry/youtube/timeline/downloads/1623168030/youtube.com!watch/media.mp4 m:\youtube\file --transfers=1 --local-no-sparse --dump=bodies --retries=1 --low-level-retries=1 --log-level=DEBUG --log-file=rclone.log

and post rclone.log

I also tried writing to the C drive, and got an error after a while. Transfer speed has also slowed to a few bytes per second.

Here's the rclone.log from that command.

2021/06/12 09:21:38 DEBUG : Using config file from "C:\\Users\\tv\\.config\\rclone\\rclone.conf"
2021/06/12 09:21:38 DEBUG : rclone: Version "v1.55.1" starting with parameters ["C:\\ProgramData\\chocolatey\\lib\\rclone.portable\\tools\\rclone-v1.55.1-windows-amd64\\rclone.exe" "sync" "dreamobjects:laundry/youtube/timeline/downloads/1623168030/youtube.com!watch/media.mp4" "m:\\youtube\\file" "--transfers=1" "--local-no-sparse" "--dump=bodies" "--retries=1" "--low-level-retries=1" "--log-level=DEBUG" "--log-file=rclone.log"]
2021/06/12 09:21:38 DEBUG : Creating backend with remote "dreamobjects:laundry/youtube/timeline/downloads/1623168030/youtube.com!watch/media.mp4"
2021/06/12 09:21:38 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.
2021/06/12 09:21:38 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2021/06/12 09:21:38 DEBUG : HTTP REQUEST (req 0xc000660a00)
2021/06/12 09:21:38 DEBUG : HEAD /laundry/youtube/timeline/downloads/1623168030/youtube.com%21watch/media.mp4 HTTP/1.1
Host: objects-us-east-1.dream.io
User-Agent: rclone/v1.55.1
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20210612T162138Z

2021/06/12 09:21:38 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2021/06/12 09:21:38 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2021/06/12 09:21:38 DEBUG : HTTP RESPONSE (req 0xc000660a00)
2021/06/12 09:21:38 DEBUG : HTTP/1.1 200 OK
Content-Length: 406147336
Accept-Ranges: bytes
Content-Type: video/mp4
Date: Sat, 12 Jun 2021 16:21:37 GMT
Etag: "38814606627f4339dbf754b62e2c462e-78"
Last-Modified: Tue, 08 Jun 2021 19:25:09 GMT
X-Amz-Request-Id: tx00000000000000000127e-0060c4df11-937015e0-us-east-1-iad1
X-Rgw-Object-Type: Normal

2021/06/12 09:21:38 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2021/06/12 09:21:38 DEBUG : fs cache: adding new entry for parent of "dreamobjects:laundry/youtube/timeline/downloads/1623168030/youtube.com!watch/media.mp4", "dreamobjects:laundry/youtube/timeline/downloads/1623168030/youtube.com!watch"
2021/06/12 09:21:38 DEBUG : Creating backend with remote "m:\\youtube\\file"
2021/06/12 09:21:38 DEBUG : local: detected overridden config - adding "{tKRgO}" suffix to name
2021/06/12 09:21:38 DEBUG : fs cache: renaming cache item "m:\\youtube\\file" to be canonical "local{tKRgO}://?/m:/youtube/file"
2021/06/12 09:21:38 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2021/06/12 09:21:38 DEBUG : HTTP REQUEST (req 0xc0001c8300)
2021/06/12 09:21:38 DEBUG : HEAD /laundry/youtube/timeline/downloads/1623168030/youtube.com%21watch/media.mp4 HTTP/1.1
Host: objects-us-east-1.dream.io
User-Agent: rclone/v1.55.1
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20210612T162138Z

2021/06/12 09:21:38 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2021/06/12 09:21:38 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2021/06/12 09:21:38 DEBUG : HTTP RESPONSE (req 0xc0001c8300)
2021/06/12 09:21:38 DEBUG : HTTP/1.1 200 OK
Content-Length: 406147336
Accept-Ranges: bytes
Content-Type: video/mp4
Date: Sat, 12 Jun 2021 16:21:38 GMT
Etag: "38814606627f4339dbf754b62e2c462e-78"
Last-Modified: Tue, 08 Jun 2021 19:25:09 GMT
X-Amz-Request-Id: tx000000000000000001895-0060c4df12-9370c6ea-us-east-1-iad1
X-Rgw-Object-Type: Normal

2021/06/12 09:21:38 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2021/06/12 09:21:38 DEBUG : media.mp4: Need to transfer - File not found at Destination
2021/06/12 09:21:38 DEBUG : media.mp4: Starting multi-thread copy with 2 parts of size 193.688M
2021/06/12 09:21:38 DEBUG : media.mp4: multi-thread copy: stream 1/2 (0-203096064) size 193.688M starting
2021/06/12 09:21:38 DEBUG : media.mp4: multi-thread copy: stream 2/2 (203096064-406147336) size 193.645M starting
2021/06/12 09:21:38 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2021/06/12 09:21:38 DEBUG : HTTP REQUEST (req 0xc0001c9500)
2021/06/12 09:21:38 DEBUG : GET /laundry/youtube/timeline/downloads/1623168030/youtube.com%21watch/media.mp4 HTTP/1.1
Host: objects-us-east-1.dream.io
User-Agent: rclone/v1.55.1
Authorization: XXXX
Range: bytes=0-203096063
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20210612T162138Z

2021/06/12 09:21:38 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2021/06/12 09:21:38 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2021/06/12 09:21:38 DEBUG : HTTP REQUEST (req 0xc0006c6300)
2021/06/12 09:21:38 DEBUG : GET /laundry/youtube/timeline/downloads/1623168030/youtube.com%21watch/media.mp4 HTTP/1.1
Host: objects-us-east-1.dream.io
User-Agent: rclone/v1.55.1
Authorization: XXXX
Range: bytes=203096064-406147335
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20210612T162138Z

2021/06/12 09:21:38 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2021/06/12 09:21:38 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2021/06/12 09:21:38 DEBUG : HTTP RESPONSE (req 0xc0001c9500)
2021/06/12 09:22:21 DEBUG : 
2021/06/12 09:22:21 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2021/06/12 09:22:21 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2021/06/12 09:22:21 DEBUG : HTTP RESPONSE (req 0xc0006c6300)
2021/06/12 09:22:21 DEBUG : media.mp4: Reopening on read failure after 0 bytes: retry 1/1: unexpected EOF
2021/06/12 09:22:21 DEBUG : media.mp4: Reopen failed after 0 bytes read: failed to reopen: too many retries
2021/06/12 09:22:21 DEBUG : media.mp4: multi-thread copy: stream 1/2 failed: multipart copy: read failed: unexpected EOF
2021/06/12 09:22:21 DEBUG : 
2021/06/12 09:22:21 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2021/06/12 09:22:21 DEBUG : media.mp4: multi-thread copy: stream 2/2 failed: multipart copy: failed to open source: context canceled
2021/06/12 09:22:21 ERROR : media.mp4: Failed to copy: multipart copy: read failed: unexpected EOF
2021/06/12 09:22:21 ERROR : Attempt 1/1 failed with 1 errors and: multipart copy: read failed: unexpected EOF
2021/06/12 09:22:21 INFO  : 
Transferred:   	         0 / 0 Bytes, -, 0 Bytes/s, ETA -
Errors:                 1 (retrying may help)
Elapsed time:        43.6s

2021/06/12 09:22:21 DEBUG : 2 go routines active
2021/06/12 09:22:21 Failed to sync: multipart copy: read failed: unexpected EOF

I received a response from Dreamhost, as this seemed to start after an incident the other day.

Our engineers have diagnosed and resolved this issue, however the long term fix is still in the process of being applied. As such, the effects of the outage may take a few days to fully return back to normal, however uptime should improve over time.

So maybe I just need to wait a while and try again.

well, if the start of the problem coincided with the time of the dreamhost issue, then i guess best to wait.

1 Like

I have written to DreamHost support about the same issue several days ago. Since then I'm receiving daily email updates similar to what endquote wrote. In last email on Friday, they said they have resolved the issue and are preparing post-mortem analysis article.

I've now different issue with DreamObjects though and I'm not sure what is the cause. Rclone complains that it can't read metadata of data/0/504 object, but when I list the bucket, the object seems to be there:

$ rclone ls dreamobjects:my-backup/localhost/data/0/|grep 504
       17 504
525185047 690
$ rclone ls dreamobjects:my-backup/localhost/data/0/504 
$ rclone ls dreamobjects:my-backup/localhost/data/0/690
525185047 690

I have same exact backup on Backblaze B2 and there it seems I can read the metadata:

$ rclone ls b2:my-backup/localhost/data/0/|grep 504
       17 504
525185047 690
$ rclone ls b2:my-backup/localhost/data/0/504 
       17 504
$ rclone ls b2:my-backup/localhost/data/0/690
525185047 690

Here's the error I'm getting when I try to sync my backup to Dreamobjects:

$ rclone sync -v /backup dreamobjects:my-backup/localhost
2021/06/28 11:06:32 NOTICE: data/0/504: Failed to read metadata: object not found
2021/06/28 11:06:32 ERROR : data/0/504: Failed to set modification time: object not found
2021/06/28 11:06:35 ERROR : S3 bucket my-backup path localhost: not deleting files as there were IO errors
2021/06/28 11:06:35 ERROR : S3 bucket my-backup path localhost: not deleting directories as there were IO errors
2021/06/28 11:06:35 ERROR : Attempt 1/3 failed with 2 errors and: not deleting files as there were IO errors
2021/06/28 11:06:41 NOTICE: data/0/504: Failed to read metadata: object not found
2021/06/28 11:06:41 ERROR : data/0/504: Failed to set modification time: object not found
2021/06/28 11:06:44 ERROR : S3 bucket my-backup path localhost: not deleting files as there were IO errors
2021/06/28 11:06:44 ERROR : S3 bucket my-backup path localhost: not deleting directories as there were IO errors
2021/06/28 11:06:44 ERROR : Attempt 2/3 failed with 2 errors and: not deleting files as there were IO errors
2021/06/28 11:06:49 NOTICE: data/0/504: Failed to read metadata: object not found
2021/06/28 11:06:50 ERROR : data/0/504: Failed to set modification time: object not found
2021/06/28 11:06:53 ERROR : S3 bucket my-backup path localhost: not deleting files as there were IO errors
2021/06/28 11:06:53 ERROR : S3 bucket my-backup path localhost: not deleting directories as there were IO errors
2021/06/28 11:06:53 ERROR : Attempt 3/3 failed with 2 errors and: not deleting files as there were IO errors
2021/06/28 11:06:53 INFO  : 
Transferred:   	         0 / 0 Bytes, -, 0 Bytes/s, ETA -
Errors:                 2 (retrying may help)
Checks:              1620 / 1620, 100%
Elapsed time:        29.2s

2021/06/28 11:06:53 Failed to sync with 2 errors: last error was: not deleting files as there were IO errors

Where could possibly be the problem?

hello and welcome to the forum,

if you had started a new post, there would have been a template of questions for you to answer such as

  • operating system
  • rclone version
  • config file, redact id/secrets
  • debug log

run rclone ls b2:my-backup/localhost/data/0/504 --dump=bodies --retries=1 --low-level-retries=1 --log-level=DEBUG --log-file rclone.log

post the rclone.log.
if the log is large in size, post to pastebin.com or other such website.

Hello, glad to join. Good to know, thank you for the info. I run the command, but unfortunately, I cannot include links in my post, so I spoofed it a little below to workaround the restriction.
Here's the output of the command you wrote

  • from B2
    gist githubusercontent com /woky/4d861124235967055c55315a720a4396/raw/e70df36340d48782cb4294dcc7dff5b24a1ff514/rclone-b2.log
  • from Dreamobjects
    gist githubusercontent com /woky/4d861124235967055c55315a720a4396/raw/e70df36340d48782cb4294dcc7dff5b24a1ff514/rclone-dreamobjects.log

i had asked for information, but you provided only some of it.
let's not waste posts going back and forth, with me trying to pull information from you, ok?


rclone checks for the existance of
HEAD /woky-backup/bor/data/0/504
and dreamhost returns
404 Not Found

with dh, how did you copy the files into there, rclone, website or what?

also, no point in posting logs about b2, not going to help us.

I'm sorry, I forgot about that. Also, you wrote the command with b2 remote, so I included both because I was not sure what do you need.

Operating system: Arch Linux (updated recently)

Rclone version:

$ rclone --version
rclone v1.55.1
- os/type: linux
- os/arch: amd64
- go/version: go1.16.4
- go/linking: dynamic
- go/tags: none

Rclone config:

[b2]
type = b2
account = ...
key = ...
hard_delete = true

[dreamobjects]
type = s3
provider = Dreamhost
env_auth = false
access_key_id = ...
secret_access_key = ...
endpoint = objects-us-east-1.dream.io
acl = private

Debug log I believe I already attached.

with dh, how did you copy the files into there, rclone, website or what?

With rclone sync as in my first post today, but I run rclone sync several times during the time when DH had issues and was returning 503 (the topic of this thread). It's possible that some data were copied at this time. I have never used anything except rclone sync to push my data there.

if the cloud provider has a known bug in their system, nothing rclone can do that about that.

if you got errors in the initial sync and now you have a problems with the corrupted data, nothing rclone can do about that.

if the bug was fixed then
i would delete the damaged folders in dh and try to sync again.

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.