dvc icon indicating copy to clipboard operation
dvc copied to clipboard

Large files get truncated on dvc push to HTTP remote

Open zhansliu opened this issue 2 years ago • 1 comments

Bug Report

Description

When using an HTTP or HTTPS remote (e.g. Artifactory), and dvc push-ing a large file (which takes more than 1 minute to upload).

Reproduce

I believe this affects all HTTP remotes, but I experienced this using an Artifactory server, so I'll describe that.

Create a dvc-tracked repository, with the following .dvc/config:

[core]
    remote = artifactory
    analytics = false
    check_update = false
['remote "artifactory"']
    url = https://<artifactory host>/artifactory/datasets/
    method = PUT
    ask_password = true
    auth = basic

Create a large file large_file (large enough that it will take more than 1 minute to upload to the remote). Then do

dvc add large_file
dvc push large_file.dvc

What happens: dvc push does not report an error, but the uploaded version of the file is truncated. When somebody else tries to download it with dvc pull, they get a truncated version of the file.

Expected

The expected behavior is either the file gets uploaded correctly, or at the very least that dvc reports an error when pushing.

Environment information

Output of dvc doctor:

Supports:
        webhdfs (fsspec = 2022.5.0),
        http (aiohttp = 3.8.1, aiohttp-retry = 2.4.8),
        https (aiohttp = 3.8.1, aiohttp-retry = 2.4.8)
Cache types: hardlink
Cache directory: NTFS on D:\
Caches: local
Remotes: https
Workspace directory: NTFS on D:\
Repo: dvc, git

More details:

After seeing this error, I modified my dvc install a little to use aiohttp's tracing functionality, to trace the calls to aiohttp. I then logged everything that happened when I did the dvc push large_file.dvc command, on a 2.2 GB large_file. Here is the log (slightly anonymized):

aiohttp_log_anonymized.txt

What happens is:

  • The file is broken down into chunks of 5 MiB, and uploaded using Transfer-Encoding: chunked.
  • This all goes well, until one minute in, when you get a ServerTimeoutError('Timeout on reading data from socket')
  • After this happens, a retry is triggered, and the transfer is restarted.
  • BUT: the already-transferred chunks are not included in the retry -- instead it just continues with the chunks that it hasn't transferred yet.
  • The result is that the first batch of chunks are lost, and the uploaded file is truncated.

I believe the timeout behavior comes from this line in dvc_objects. If I change that to sock_read=None, then the ServerTimeoutError doesn't happen, and everything works.

That line was changed to the current behavior in this pull request.

I think the problem is that aiohttp's sock_read timeout timer starts ticking at the beginning of the request, which means that it will trigger when you try to upload large files.

zhansliu avatar Aug 05 '22 15:08 zhansliu

Seems related to iterative/dvc-http#27, although for me with GitLab's generic packages repository as the storage backend the upload fails after ~5 minutes without truncation.

It would be interesting to understand why the behavior differs for Artifactory and GitLab.

sisp avatar Aug 06 '22 11:08 sisp

Hey, I created a consistent reproduction of this issue in this repo: https://github.com/guysmoilov/golang-throttled-fileserver

The root cause is that the HTTP retries don't send from the start of the pushed file - they push from the middle of the file after the first try.

To be clear, it means that any users with HTTP remotes might have a large amount of corrupted files stored in their HTTP remotes, without knowing anything is wrong.

It doesn't even require sketchy network connections to reproduce reliably, any failed push request will cause corrupted data if a retry succeeds.

You can contact me on Discord if you want help faster: Tolstoyevsky#7927

guysmoilov avatar Aug 11 '22 17:08 guysmoilov

I'm working on debugging the client in DVC to find the root cause and fix it ASAP but no luck so far

guysmoilov avatar Aug 11 '22 17:08 guysmoilov

I narrowed it down further: The problem is the aiohttp_retry RetryClient, which gets passed a data chunk generator in DVC's implementation of HTTPFileSystem. The generator doesn't seek to the start of the file on request retry, and retries should be totally unsupported when the data isn't seekable.

I think we have to seek in the file on retries using TraceConfig: https://docs.aiohttp.org/en/stable/tracing_reference.html

But it still feels dangerous since this doesn't seem like something that was well thought out in the retry client, just a workaround.

guysmoilov avatar Aug 11 '22 20:08 guysmoilov

For reference, @guysmoilov the dagshub repo in your example doesn't work for me, when I clone it there is no default remote configured so you can't dvc pull any data

Clone the following repo and dvc pull its data: https://dagshub.com/nirbarazida/hello-world

But I am able to reproduce the issue using my own test DVC repo and the POC go server.

pmrowla avatar Aug 12 '22 04:08 pmrowla

So the issue is that RetryClient defaults to retrying on all 5xx server errors. @skshetry has identified that this can be disabled by setting retry_all_server_errors=False.

However, what we probably want to do is just disable retries for write operations (PUT and POST).

pmrowla avatar Aug 12 '22 04:08 pmrowla

This is fixed in the latest dvc-data/dvc-objects releases and will be available in the next DVC release. In the meantime, you can manually install the latest dvc-data to get the fix.

pip install dvc-data==0.1.15

pmrowla avatar Aug 12 '22 09:08 pmrowla

This is fixed in the latest dvc-data/dvc-objects releases and will be available in the next DVC release. In the meantime, you can manually install the latest dvc-data to get the fix.

pip install dvc-data==0.1.14

I think you mean to say:

pip install dvc-data==0.1.15

? From looking at the changelogs

guysmoilov avatar Aug 14 '22 08:08 guysmoilov

@guysmoilov you are correct, it should be 0.1.15

pmrowla avatar Aug 15 '22 03:08 pmrowla