ResumableUploadAbortException on gsutil

Question

I keep seeing the following error when using gsutil

ResumableUploadAbortException: Upload complete with 6275 additional bytes left in stream

The command is very simple, something like

gsutil cp -r <source_path> gs://<target-bucket>/<target_path>

with about 80 files inside <source_path>. There are nested folders inside <source_path>, as well. Changing gsutil cp to gsutil -m cp doesn't make a difference. And this error is reproducible when I run it inside a python script together with lots of a other code. However, when I run the command separately in bash, it doesn't seem to have any problem. So I wonder what could possibly be the reason to ResumableUploadAbortException, please?

Tail of debug output with gsutil -D -m cp

total_bytes_transferred: 794750002
Total bytes copied=794750002, total elapsed time=7.932 secs (95.55 MiBps)
DEBUG: Exception stack trace:
    Traceback (most recent call last):
      File "/usr/lib/google-cloud-sdk/platform/gsutil/gslib/__main__.py", line 565, in _RunNamedCommandAndHandleExceptions
        parallel_operations, perf_trace_token=perf_trace_token)
      File "/usr/lib/google-cloud-sdk/platform/gsutil/gslib/command_runner.py", line 280, in RunNamedCommand
        return_code = command_inst.RunCommand()
      File "/usr/lib/google-cloud-sdk/platform/gsutil/gslib/commands/cp.py", line 998, in RunCommand
        self.op_failure_count, plural_str, plural_str))
    CommandException: CommandException: 1 file/object could not be transferred.

Woodwaxen

What version of gsutil are you using? – Wappes

@TravisHobrla, gsutil version: 4.19 – Woodwaxen

That you can't reproduce this in bash makes it seem most likely that something in your python script may still be writing to one of the files or that the file may have not been flushed before you call gsutil. How are you calling gsutil from Python? You can collect a gsutil -D cp log to see if the byte ranges that gsutil is attempting to send initially match your expected file size(s). – Wappes

The debug output is rather verbose, what should I be looking at? I have updated my question with the last tail of the debug log. I also trimmed my code down to only the part of gsutil and the problem is still reproducible. Though I think it unlikely, if it's a flushing problem, does it mean I need to use something like sys.stdout.flush? – Woodwaxen

Is your Python code producing the files that will be transferred? If it is, you need make sure they're all fully flushed/closed before gsutil or any other utility can safely copy them. As for the debug log, generally what you're looking for is the HTTP header like content-range: bytes 0-999/1000 after a PUT /resumable/upload/storage request. The size in that header should match your expected size in the source file. – Wappes

I see. I will debug further. By the way, is there an easy way to find out which file is not successfully uploaded since the Exception message doesn't tell? – Woodwaxen

Let us continue this discussion in chat. – Woodwaxen

Answer 1

Make sure you are transferring a file that gets changed during the transfer process. In my case, the problem is that I redirect the output to a log file, while the log file is also being transferred to the cloud, which causes the above problem.

Woodwaxen

Answer 2

Using WSL2?

WSL has a well known issue that causes the time to go out of sync.

In my case, it looks like having the time out of sync caused the ResumableUploadAbortException.

To fix it, just sync the time from WSL 2: sudo nohup watch -n 10 ntpdate time.windows.com > /dev/null 2>&1 &

Candlestand

Answer 3

The gsutil command suggests to "delete tracker files" to fix the problem. That did indeed fix the issue for me:

rm -rf ~/.gsutil/tracker-files

Lukash