lfs: fix the stall and corruption issue when concurrently uploading blobs
We've avoided the issue up to this point by gating worker usage with an
experimental config. See 10e62d5efa73, and the thread linked there for some of
the initial diagnosis, but essentially some data was being read from the blob
before an error occurred and `keepalive` retried, but didn't rewind the file
pointer. So the leading data was lost from the blob on the server, and the
connection stalled, trying to send more data than available.
In trying to recreate this, I was unable to do so uploading from Windows to
CentOS 7. But it reproduced every time going from CentOS 7 to another CentOS 7
over https.
I found recent fixes in the FaceBook repo to address this[1][2]. The commit
message for the first is:
The KeepAlive HTTP implementation is bugged in it's retry logic, it supports
reading from a file pointer, but doesn't support rewinding of the seek cursor
when it performs a retry. So it can happen that an upload fails for whatever
reason and will then 'hang' on the retry event.
The sequence of events that get triggered are:
- Upload file A, goes OK. Keep-Alive caches connection.
- Upload file B, fails due to (for example) failing Keep-Alive, but LFS file
pointer has been consumed for the upload and fd has been closed.
- Retry for file B starts, sets the Content-Length properly to the expected
file size, but since file pointer has been consumed no data will be uploaded,
causing the server to wait for the uploaded data until either client or
server reaches a timeout, making it seem as our mercurial process hangs.
This is just a stop-gap measure to prevent this behavior from blocking Mercurial
(LFS has retry logic). A proper solutions need to be build on top of this
stop-gap measure: for upload from file pointers, we should support fseek() on
the interface. Since we expect to consume the whole file always anyways, this
should be safe. This way we can seek back to the beginning on a retry.
I ported those two patches, and it works. But I see that `url._sendfile()` does
a rewind on `httpsendfile` objects[3], so maybe it's better to keep this all in
one place and avoid a second seek. We may still want the first FaceBook patch
as extra protection for this problem in general. The other two uses of
`httpsendfile` are in the wire protocol to upload bundles, and to upload
largefiles. Neither of these appear to use a worker, and I'm not sure why
workers seem to trigger this, or if this could have happened without a worker.
Since `httpsendfile` already has a `close()` method, that is dropped. That
class also explicitly says there's no `__len__` attribute, so that is removed
too. The override for `read()` is necessary to avoid the progressbar usage per
file.
[1] https://github.com/facebookexperimental/eden/commit/c350d6536d90c044c837abdd3675185644481469
[2] https://github.com/facebookexperimental/eden/commit/77f0d3fd0415e81b63e317e457af9c55c46103ee
[3] https://www.mercurial-scm.org/repo/hg/file/5.2.2/mercurial/url.py#l176
Differential Revision: https://phab.mercurial-scm.org/D7962
$ mkdir part1
$ cd part1
$ hg init
$ echo a > a
$ hg add a
$ hg commit -m "1"
$ hg status
$ hg copy a b
$ hg --config ui.portablefilenames=abort copy a con.xml
abort: filename contains 'con', which is reserved on Windows: con.xml
[255]
$ hg status
A b
$ hg sum
parent: 0:c19d34741b0a tip
1
branch: default
commit: 1 copied
update: (current)
phases: 1 draft
$ hg --debug commit -m "2"
committing files:
b
b: copy a:b789fdd96dc2f3bd229c1dd8eedf0fc60e2b68e3
committing manifest
committing changelog
updating the branch cache
committed changeset 1:93580a2c28a50a56f63526fb305067e6fbf739c4
we should see two history entries
$ hg history -v
changeset: 1:93580a2c28a5
tag: tip
user: test
date: Thu Jan 01 00:00:00 1970 +0000
files: b
description:
2
changeset: 0:c19d34741b0a
user: test
date: Thu Jan 01 00:00:00 1970 +0000
files: a
description:
1
we should see one log entry for a
$ hg log a
changeset: 0:c19d34741b0a
user: test
date: Thu Jan 01 00:00:00 1970 +0000
summary: 1
this should show a revision linked to changeset 0
$ hg debugindex a
rev linkrev nodeid p1 p2
0 0 b789fdd96dc2 000000000000 000000000000
we should see one log entry for b
$ hg log b
changeset: 1:93580a2c28a5
tag: tip
user: test
date: Thu Jan 01 00:00:00 1970 +0000
summary: 2
this should show a revision linked to changeset 1
$ hg debugindex b
rev linkrev nodeid p1 p2
0 1 37d9b5d994ea 000000000000 000000000000
this should show the rename information in the metadata
$ hg debugdata b 0 | head -3 | tail -2
copy: a
copyrev: b789fdd96dc2f3bd229c1dd8eedf0fc60e2b68e3
#if reporevlogstore
$ md5sum.py .hg/store/data/b.i
44913824c8f5890ae218f9829535922e .hg/store/data/b.i
#endif
$ hg cat b > bsum
$ md5sum.py bsum
60b725f10c9c85c70d97880dfe8191b3 bsum
$ hg cat a > asum
$ md5sum.py asum
60b725f10c9c85c70d97880dfe8191b3 asum
$ hg verify
checking changesets
checking manifests
crosschecking files in changesets and manifests
checking files
checked 2 changesets with 2 changes to 2 files
$ cd ..
$ mkdir part2
$ cd part2
$ hg init
$ echo foo > foo
should fail - foo is not managed
$ hg mv foo bar
foo: not copying - file is not managed
abort: no files to copy
[255]
$ hg st -A
? foo
respects ui.relative-paths
$ mkdir dir
$ cd dir
$ hg mv ../foo ../bar
../foo: not copying - file is not managed
abort: no files to copy
[255]
$ hg mv ../foo ../bar --config ui.relative-paths=yes
../foo: not copying - file is not managed
abort: no files to copy
[255]
$ hg mv ../foo ../bar --config ui.relative-paths=no
foo: not copying - file is not managed
abort: no files to copy
[255]
$ cd ..
$ rmdir dir
$ hg add foo
dry-run; print a warning that this is not a real copy; foo is added
$ hg mv --dry-run foo bar
foo has not been committed yet, so no copy data will be stored for bar.
$ hg st -A
A foo
should print a warning that this is not a real copy; bar is added
$ hg mv foo bar
foo has not been committed yet, so no copy data will be stored for bar.
$ hg st -A
A bar
should print a warning that this is not a real copy; foo is added
$ hg cp bar foo
bar has not been committed yet, so no copy data will be stored for foo.
$ hg rm -f bar
$ rm bar
$ hg st -A
A foo
$ hg commit -m1
moving a missing file
$ rm foo
$ hg mv foo foo3
foo: deleted in working directory
foo3 does not exist!
$ hg up -qC .
copy --after to a nonexistent target filename
$ hg cp -A foo dummy
foo: not recording copy - dummy does not exist
[1]
dry-run; should show that foo is clean
$ hg copy --dry-run foo bar
$ hg st -A
C foo
should show copy
$ hg copy foo bar
$ hg st -C
A bar
foo
shouldn't show copy
$ hg commit -m2
$ hg st -C
should match
$ hg debugindex foo
rev linkrev nodeid p1 p2
0 0 2ed2a3912a0b 000000000000 000000000000
$ hg debugrename bar
bar renamed from foo:2ed2a3912a0b24502043eae84ee4b279c18b90dd
$ echo bleah > foo
$ echo quux > bar
$ hg commit -m3
should not be renamed
$ hg debugrename bar
bar not renamed
$ hg copy -f foo bar
should show copy
$ hg st -C
M bar
foo
XXX: filtering lfilesrepo.status() in 3.3-rc causes the copy source to not be
displayed.
$ hg st -C --config extensions.largefiles=
The fsmonitor extension is incompatible with the largefiles extension and has been disabled. (fsmonitor !)
M bar
foo
$ hg commit -m3
should show no parents for tip
$ hg debugindex bar
rev linkrev nodeid p1 p2
0 1 7711d36246cc 000000000000 000000000000
1 2 bdf70a2b8d03 7711d36246cc 000000000000
2 3 b2558327ea8d 000000000000 000000000000
should match
$ hg debugindex foo
rev linkrev nodeid p1 p2
0 0 2ed2a3912a0b 000000000000 000000000000
1 2 dd12c926cf16 2ed2a3912a0b 000000000000
$ hg debugrename bar
bar renamed from foo:dd12c926cf165e3eb4cf87b084955cb617221c17
should show no copies
$ hg st -C
copy --after on an added file
$ cp bar baz
$ hg add baz
$ hg cp -A bar baz
$ hg st -C
A baz
bar
foo was clean:
$ hg st -AC foo
C foo
Trying to copy on top of an existing file fails,
$ hg copy -A bar foo
foo: not overwriting - file already committed
('hg copy --after --force' to replace the file by recording a copy)
[1]
same error without the --after, so the user doesn't have to go through
two hints:
$ hg copy bar foo
foo: not overwriting - file already committed
('hg copy --force' to replace the file by recording a copy)
[1]
but it's considered modified after a copy --after --force
$ hg copy -Af bar foo
$ hg st -AC foo
M foo
bar
The hint for a file that exists but is not in file history doesn't
mention --force:
$ touch xyzzy
$ hg cp bar xyzzy
xyzzy: not overwriting - file exists
('hg copy --after' to record the copy)
[1]
$ cd ..