[PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Johannes Schindelin via GitGitGadget]

I reported a couple of times that t5552 is not passing reliably. It has now
reached next, and will no doubt infect master soon.

Turns out that it is not a Windows-specific issue, even if it occurs a lot 
more often on Windows than elsewhere.

The culprit is that two processes try simultaneously to write to the same
file specified via GIT_TRACE_PACKET, and it is not well defined how that
should work, even on Linux.

This patch series addresses that by locking the trace fd. I chose to use 
flock() instead of fcntl() because the Win32 API LockFileEx()
[https://docs.microsoft.com/en-us/windows/desktop/api/fileapi/nf-fileapi-lockfileex] 
(which does exactly what I want in this context) has much more similar
semantics to the former than the latter.

Of course, I have to admit that I am not super solid on flock() semantics,
and I also do not know which conditional blocks in config.mak.uname should
grow a HAVE_FLOCK = YesWeDo line, still. Reviewers knowledgeable in flock() 
semantics: I would be much indebted if you helped me there. Also: is it safe
to call flock() on file descriptors referring not to files, but, say, pipes
or an interactive terminal?

Johannes Schindelin (4):
  Introduce a function to lock/unlock file descriptors when appending
  mingw: implement lock_or_unlock_fd_for_appending()
  trace: lock the trace file to avoid racy trace_write() calls
  trace: verify that locking works

 Makefile               |   1 +
 compat/mingw.c         |  19 ++++++
 compat/mingw.h         |   3 +
 config.mak.uname       |   3 +
 git-compat-util.h      |   2 +
 t/helper/test-tool.c   |   1 +
 t/helper/test-tool.h   |   1 +
 t/helper/test-trace.c  | 130 +++++++++++++++++++++++++++++++++++++++++
 t/t0070-fundamental.sh |   6 ++
 trace.c                |  11 +++-
 wrapper.c              |  14 +++++
 11 files changed, 190 insertions(+), 1 deletion(-)
 create mode 100644 t/helper/test-trace.c


base-commit: 42cc7485a2ec49ecc440c921d2eb0cae4da80549
Published-As: https://github.com/gitgitgadget/git/releases/tags/pr-17%2Fdscho%2Ffetch-negotiator-skipping-v1
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-17/dscho/fetch-negotiator-skipping-v1
Pull-Request: https://github.com/gitgitgadget/git/pull/17
-- 
gitgitgadget

[PATCH 1/4] Introduce a function to lock/unlock file descriptors when appending

[Johannes Schindelin via GitGitGadget]

From: Johannes Schindelin <johannes.schindelin@gmx.de>

This function will be used to make write accesses in trace_write() a bit
safer.

Note: this patch takes a very different approach for cross-platform
support than Git is historically taking: the original approach is to
first implement everything on Linux, using the functions available on
Linux, and then trying to emulate these functions on platforms that do
not have those functions such as Windows.

This leads to all kinds of undesirable quirks in Git's source code (and
performance characteristics) because of the lack of a proper abstraction
layer: instead of declaring functions for the functionality we
*actually* need, we abuse POSIX functions to say what we need, even if
those functions serve much broader purposes (and do not make at all
clear what the caller wants of them).

For example, when Git wants to determine whether a path refers to a
symbolic link, it calls lstat(). That POSIX function has to be emulated
on Windows, painstakingly filling all the information lstat() would,
only for the caller to throw away everything except that one bit of
information, and all of the time figuring out the mtime/atime/ctime and
file size and whatnot was spent in vain.

If we were to follow that approach, we would extend the fcntl()
emulation in compat/mingw.c after this commit, to support the function
added in this commit.

But fcntl() allows a lot more versatile file region locking that we
actually need, to by necessity the fcntl() emulation would be quite
complex: To support the `l_whence = SEEK_CUR` (which we would use, if it
did not require so much book-keeping due to our writing between locking
and unlocking the file), we would have to call `SetFilePointerEx()`
(after obtaining the `HANDLE` on which all Win32 API functions work
instead of the integer file descriptors used by all POSIX functions).
Multiplying the number of Win32 API round-trips. Of course, we could
implement an incomplete emulation of fcntl()'s F_WRLCK, but that would
be unsatisfying.

An alternative approach would be to use the `flock()` function, whose
semantics are much closer to existing Win32 API. But `flock()` is not
even a POSIX standard, so we would have to implement emulation of
`flock()` for *other* platforms. And it would again be the wrong thing
to do, as we would once again fail to have an abstraction that clearly
says what *exact*functionality we want to use.

To set a precedent for a better approach, let's introduce a proper
abstraction: a function that says in its name precisely what Git
wants it to do (as opposed to *how* it does it on Linux):
lock_or_unlock_fd_for_appending().

The next commit will provide a Windows-specific implementation of this
function/functionality.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>

squash! Introduce a function to lock/unlock file descriptors when appending
---
 git-compat-util.h |  2 ++
 wrapper.c         | 14 ++++++++++++++
 2 files changed, 16 insertions(+)

diff --git a/git-compat-util.h b/git-compat-util.h
index 9a64998b2..13b83bade 100644
--- a/git-compat-util.h
+++ b/git-compat-util.h
@@ -1202,6 +1202,8 @@ struct tm *git_gmtime_r(const time_t *, struct tm *);
 #define getc_unlocked(fh) getc(fh)
 #endif
 
+extern int lock_or_unlock_fd_for_appending(int fd, int lock_it);
+
 /*
  * Our code often opens a path to an optional file, to work on its
  * contents when we can successfully open it.  We can ignore a failure
diff --git a/wrapper.c b/wrapper.c
index e4fa9d84c..6c2116272 100644
--- a/wrapper.c
+++ b/wrapper.c
@@ -690,3 +690,17 @@ int xgethostname(char *buf, size_t len)
 		buf[len - 1] = 0;
 	return ret;
 }
+
+#ifndef GIT_WINDOWS_NATIVE
+int lock_or_unlock_fd_for_appending(int fd, int lock_it)
+{
+	struct flock flock;
+
+	flock.l_type = lock_it ? F_WRLCK : F_UNLCK;
+	flock.l_whence = SEEK_SET;
+	flock.l_start = 0;
+	flock.l_len = 0xffffffff; /* arbitrary number of bytes */
+
+	return fcntl(fd, F_SETLKW, &flock);
+}
+#endif
-- 
gitgitgadget

Re: [PATCH 1/4] Introduce a function to lock/unlock file descriptors when appending

[Junio C Hamano]

"Johannes Schindelin via GitGitGadget" <gitgitgadget@gmail.com>
writes:

> From: Johannes Schindelin <johannes.schindelin@gmx.de>
>
> This function will be used to make write accesses in trace_write() a bit
> safer.
> ...
> To set a precedent for a better approach, let's introduce a proper
> abstraction: a function that says in its name precisely what Git
> wants it to do (as opposed to *how* it does it on Linux):
> lock_or_unlock_fd_for_appending().
>
> The next commit will provide a Windows-specific implementation of this
> function/functionality.
>
> Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
>
> squash! Introduce a function to lock/unlock file descriptors when appending

If we can keep the custom, narrow and easy-to-port API (like this
patch introduces) focused and resist feature creep over time, then
it would be worth spending effort to come up with such a custom
helper that is easy to port.  So I agree with the approach in
general but I tend to think "set a precedent for a better approach"
is a way-too-early and wishful verdict.  We do not know if we can
really keep that custom API easy-to-port-and-maintain yet.

In short, even though I agree with the approach, most of the
verbiage above is unnecessary and mere distraction.

> ---
>  git-compat-util.h |  2 ++
>  wrapper.c         | 14 ++++++++++++++
>  2 files changed, 16 insertions(+)
>
> diff --git a/git-compat-util.h b/git-compat-util.h
> index 9a64998b2..13b83bade 100644
> --- a/git-compat-util.h
> +++ b/git-compat-util.h
> @@ -1202,6 +1202,8 @@ struct tm *git_gmtime_r(const time_t *, struct tm *);
>  #define getc_unlocked(fh) getc(fh)
>  #endif
>  
> +extern int lock_or_unlock_fd_for_appending(int fd, int lock_it);
> +
>  /*
>   * Our code often opens a path to an optional file, to work on its
>   * contents when we can successfully open it.  We can ignore a failure
> diff --git a/wrapper.c b/wrapper.c
> index e4fa9d84c..6c2116272 100644
> --- a/wrapper.c
> +++ b/wrapper.c
> @@ -690,3 +690,17 @@ int xgethostname(char *buf, size_t len)
>  		buf[len - 1] = 0;
>  	return ret;
>  }
> +
> +#ifndef GIT_WINDOWS_NATIVE
> +int lock_or_unlock_fd_for_appending(int fd, int lock_it)
> +{
> +	struct flock flock;
> +
> +	flock.l_type = lock_it ? F_WRLCK : F_UNLCK;
> +	flock.l_whence = SEEK_SET;
> +	flock.l_start = 0;
> +	flock.l_len = 0xffffffff; /* arbitrary number of bytes */

If this can be an arbitrary range, do we need to cover this many (or
only this few, depending on your point of view) bytes?

Would it be sufficient to cover just the first one byte instead?  Or
perhaps give l_len==0 to cover all no matter how large the file
grows, which sounds like a better range specification.

> +	return fcntl(fd, F_SETLKW, &flock);
> +}
> +#endif

Re: [PATCH 1/4] Introduce a function to lock/unlock file descriptors when appending

[Johannes Schindelin]

Hi Junio,

On Thu, 9 Aug 2018, Junio C Hamano wrote:

> "Johannes Schindelin via GitGitGadget" <gitgitgadget@gmail.com>
> writes:
> 
> > From: Johannes Schindelin <johannes.schindelin@gmx.de>
> >
> > This function will be used to make write accesses in trace_write() a bit
> > safer.
> > ...
> > To set a precedent for a better approach, let's introduce a proper
> > abstraction: a function that says in its name precisely what Git
> > wants it to do (as opposed to *how* it does it on Linux):
> > lock_or_unlock_fd_for_appending().
> >
> > The next commit will provide a Windows-specific implementation of this
> > function/functionality.
> >
> > Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
> >
> > squash! Introduce a function to lock/unlock file descriptors when appending
> 
> If we can keep the custom, narrow and easy-to-port API (like this
> patch introduces) focused and resist feature creep over time, then
> it would be worth spending effort to come up with such a custom
> helper that is easy to port.  So I agree with the approach in
> general but I tend to think "set a precedent for a better approach"
> is a way-too-early and wishful verdict.  We do not know if we can
> really keep that custom API easy-to-port-and-maintain yet.
> 
> In short, even though I agree with the approach, most of the
> verbiage above is unnecessary and mere distraction.

I disagree that it is a distraction, because the commit messages are the
very location where I am supposed to detail my rationale, motivation, and
considerations that are not obvious from the diff alone.

Of course, I cannot force you to take this commit message, you can
overrule me and edit it. But you would do this against my express wish.

> > ---
> >  git-compat-util.h |  2 ++
> >  wrapper.c         | 14 ++++++++++++++
> >  2 files changed, 16 insertions(+)
> >
> > diff --git a/git-compat-util.h b/git-compat-util.h
> > index 9a64998b2..13b83bade 100644
> > --- a/git-compat-util.h
> > +++ b/git-compat-util.h
> > @@ -1202,6 +1202,8 @@ struct tm *git_gmtime_r(const time_t *, struct tm *);
> >  #define getc_unlocked(fh) getc(fh)
> >  #endif
> >  
> > +extern int lock_or_unlock_fd_for_appending(int fd, int lock_it);
> > +
> >  /*
> >   * Our code often opens a path to an optional file, to work on its
> >   * contents when we can successfully open it.  We can ignore a failure
> > diff --git a/wrapper.c b/wrapper.c
> > index e4fa9d84c..6c2116272 100644
> > --- a/wrapper.c
> > +++ b/wrapper.c
> > @@ -690,3 +690,17 @@ int xgethostname(char *buf, size_t len)
> >  		buf[len - 1] = 0;
> >  	return ret;
> >  }
> > +
> > +#ifndef GIT_WINDOWS_NATIVE
> > +int lock_or_unlock_fd_for_appending(int fd, int lock_it)
> > +{
> > +	struct flock flock;
> > +
> > +	flock.l_type = lock_it ? F_WRLCK : F_UNLCK;
> > +	flock.l_whence = SEEK_SET;
> > +	flock.l_start = 0;
> > +	flock.l_len = 0xffffffff; /* arbitrary number of bytes */
> 
> If this can be an arbitrary range, do we need to cover this many (or
> only this few, depending on your point of view) bytes?

It can be an arbitrary range, but it does not matter at this point because
we expect only appending callers. Therefore any range will do, as long as
it covers the range of bytes to be written by the trace functions. And
with 0-0xffffffff, I am fairly certain we got it.

Technically, we could even lock the range 0-1, as all of our callers would
agree on that, and block each other. Other Git implementations might not,
though. So 0-0xffffffff is my best bet and cheap.

> Would it be sufficient to cover just the first one byte instead?

As I said, this would depend on no other software trying to append to the
trace file, including alternative Git implementations.

In other words: it would be "too clever". Clever, but asking for problems.

> Or perhaps give l_len==0 to cover all no matter how large the file
> grows, which sounds like a better range specification.

I must have overlooked that option in the documentation.

*clicketyclick*

Indeed,
http://pubs.opengroup.org/onlinepubs/9699919799/functions/fcntl.html
spells it out pretty clearly:

> A lock shall be set to extend to the largest possible value of the file
> offset for that file by setting l_len to 0. If such a lock also has
> l_start set to 0 and l_whence is set to SEEK_SET, the whole file shall
> be locked.

Sorry about missing this. I will change the implementation to this.

> > +	return fcntl(fd, F_SETLKW, &flock);
> > +}
> > +#endif

Thanks for helping me improve the patch,
Dscho

[PATCH 2/4] mingw: implement lock_or_unlock_fd_for_appending()

[Johannes Schindelin via GitGitGadget]

From: Johannes Schindelin <johannes.schindelin@gmx.de>

For some reason, t/t5552-skipping-fetch-negotiator.sh fails particularly
often on Windows due to racy tracing where the `git upload-pack` and the
`git fetch` processes compete for the same file.

We just introduced a remedy that uses fcntl(), but Windows does not have
fcntl(). So let's implement an alternative.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 compat/mingw.c   | 19 +++++++++++++++++++
 compat/mingw.h   |  3 +++
 config.mak.uname |  3 +++
 3 files changed, 25 insertions(+)

diff --git a/compat/mingw.c b/compat/mingw.c
index 6ded1c859..6da9ce861 100644
--- a/compat/mingw.c
+++ b/compat/mingw.c
@@ -514,6 +514,25 @@ int mingw_chmod(const char *filename, int mode)
 	return _wchmod(wfilename, mode);
 }
 
+int mingw_lock_or_unlock_fd_for_appending(int fd, int lock_it)
+{
+	HANDLE handle = (HANDLE)_get_osfhandle(fd);
+	OVERLAPPED overlapped = { 0 };
+	DWORD err;
+
+	if (!lock_it && UnlockFileEx(handle, 0, -1, 0, &overlapped))
+		return 0;
+	if (lock_it &&
+	    LockFileEx(handle, LOCKFILE_EXCLUSIVE_LOCK, 0, -1, 0, &overlapped))
+		return 0;
+
+	err = GetLastError();
+	/* LockFileEx() cannot lock pipes */
+	errno = err == ERROR_INVALID_FUNCTION ?
+		EBADF : err_win_to_posix(GetLastError());
+	return -1;
+}
+
 /*
  * The unit of FILETIME is 100-nanoseconds since January 1, 1601, UTC.
  * Returns the 100-nanoseconds ("hekto nanoseconds") since the epoch.
diff --git a/compat/mingw.h b/compat/mingw.h
index 571019d0b..0f76d89a9 100644
--- a/compat/mingw.h
+++ b/compat/mingw.h
@@ -397,6 +397,9 @@ HANDLE winansi_get_osfhandle(int fd);
  * git specific compatibility
  */
 
+int mingw_lock_or_unlock_fd_for_appending(int fd, int lock_it);
+#define lock_or_unlock_fd_for_appending mingw_lock_or_unlock_fd_for_appending
+
 #define has_dos_drive_prefix(path) \
 	(isalpha(*(path)) && (path)[1] == ':' ? 2 : 0)
 int mingw_skip_dos_drive_prefix(char **path);
diff --git a/config.mak.uname b/config.mak.uname
index 684fc5bf0..159b7da81 100644
--- a/config.mak.uname
+++ b/config.mak.uname
@@ -376,6 +376,7 @@ ifeq ($(uname_S),Windows)
 	NO_POSIX_GOODIES = UnfortunatelyYes
 	NATIVE_CRLF = YesPlease
 	DEFAULT_HELP_FORMAT = html
+	HAVE_FLOCK = YesWeEmulate
 
 	CC = compat/vcbuild/scripts/clink.pl
 	AR = compat/vcbuild/scripts/lib.pl
@@ -523,6 +524,8 @@ ifneq (,$(findstring MINGW,$(uname_S)))
 	NO_INET_NTOP = YesPlease
 	NO_POSIX_GOODIES = UnfortunatelyYes
 	DEFAULT_HELP_FORMAT = html
+	HAVE_FLOCK = YesWeEmulate
+
 	COMPAT_CFLAGS += -DNOGDI -Icompat -Icompat/win32
 	COMPAT_CFLAGS += -DSTRIP_EXTENSION=\".exe\"
 	COMPAT_OBJS += compat/mingw.o compat/winansi.o \
-- 
gitgitgadget

[PATCH 3/4] trace: lock the trace file to avoid racy trace_write() calls

[Johannes Schindelin via GitGitGadget]

From: Johannes Schindelin <johannes.schindelin@gmx.de>

When multiple processes try to write to the same file, it is not
guaranteed that everything works as expected: those writes can overlap,
and in the worst case even lose messages.

This happens in t/t5552-skipping-fetch-negotiator.sh, where we abuse the
`GIT_TRACE` facility to write traces of two concurrent processes (`git
fetch` and `git upload-pack`) to the same file, and then verify that the
trace contains certain expected breadcrumbs.

To remedy this, let's lock the file descriptors for exclusive writing,
using the function we just introduced in the previous commit.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 trace.c | 11 ++++++++++-
 1 file changed, 10 insertions(+), 1 deletion(-)

diff --git a/trace.c b/trace.c
index fc623e91f..6f97dde27 100644
--- a/trace.c
+++ b/trace.c
@@ -114,11 +114,20 @@ static int prepare_trace_line(const char *file, int line,
 
 static void trace_write(struct trace_key *key, const void *buf, unsigned len)
 {
-	if (write_in_full(get_trace_fd(key), buf, len) < 0) {
+	int fd = get_trace_fd(key), locked;
+
+	locked = !lock_or_unlock_fd_for_appending(fd, 1);
+	if (!locked && errno != EBADF)
+		warning("unable to lock file descriptor for %s: %s",
+			key->key, strerror(errno));
+	if (write_in_full(fd, buf, len) < 0) {
 		warning("unable to write trace for %s: %s",
 			key->key, strerror(errno));
 		trace_disable(key);
 	}
+	if (locked && lock_or_unlock_fd_for_appending(fd, 0) < 0)
+		warning("failed to remove lock on fd for %s: %s",
+			key->key, strerror(errno));
 }
 
 void trace_verbatim(struct trace_key *key, const void *buf, unsigned len)
-- 
gitgitgadget

[PATCH 4/4] trace: verify that locking works

[Johannes Schindelin via GitGitGadget]

From: Johannes Schindelin <johannes.schindelin@gmx.de>

Recently, t5552 introduced a pattern where two processes try to write to
the same GIT_TRACE file in parallel. This is not safe, as the two
processes fighting over who gets to append to the file can cause garbled
lines and may even result in data loss on Windows (where buffers are
written to before they are flushed).

To remedy this, we introduced the lock_or_unlock_fd_for_appending()
function. And to make sure that this works, this commit introduces a
regression test.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 Makefile               |   1 +
 t/helper/test-tool.c   |   1 +
 t/helper/test-tool.h   |   1 +
 t/helper/test-trace.c  | 130 +++++++++++++++++++++++++++++++++++++++++
 t/t0070-fundamental.sh |   6 ++
 5 files changed, 139 insertions(+)
 create mode 100644 t/helper/test-trace.c

diff --git a/Makefile b/Makefile
index 617475622..2e3fb5b8d 100644
--- a/Makefile
+++ b/Makefile
@@ -729,6 +729,7 @@ TEST_BUILTINS_OBJS += test-strcmp-offset.o
 TEST_BUILTINS_OBJS += test-string-list.o
 TEST_BUILTINS_OBJS += test-submodule-config.o
 TEST_BUILTINS_OBJS += test-subprocess.o
+TEST_BUILTINS_OBJS += test-trace.o
 TEST_BUILTINS_OBJS += test-urlmatch-normalization.o
 TEST_BUILTINS_OBJS += test-wildmatch.o
 TEST_BUILTINS_OBJS += test-write-cache.o
diff --git a/t/helper/test-tool.c b/t/helper/test-tool.c
index 805a45de9..7adce872b 100644
--- a/t/helper/test-tool.c
+++ b/t/helper/test-tool.c
@@ -39,6 +39,7 @@ static struct test_cmd cmds[] = {
 	{ "string-list", cmd__string_list },
 	{ "submodule-config", cmd__submodule_config },
 	{ "subprocess", cmd__subprocess },
+	{ "trace", cmd__trace },
 	{ "urlmatch-normalization", cmd__urlmatch_normalization },
 	{ "wildmatch", cmd__wildmatch },
 	{ "write-cache", cmd__write_cache },
diff --git a/t/helper/test-tool.h b/t/helper/test-tool.h
index 7116ddfb9..c462ac924 100644
--- a/t/helper/test-tool.h
+++ b/t/helper/test-tool.h
@@ -33,6 +33,7 @@ int cmd__strcmp_offset(int argc, const char **argv);
 int cmd__string_list(int argc, const char **argv);
 int cmd__submodule_config(int argc, const char **argv);
 int cmd__subprocess(int argc, const char **argv);
+int cmd__trace(int argc, const char **argv);
 int cmd__urlmatch_normalization(int argc, const char **argv);
 int cmd__wildmatch(int argc, const char **argv);
 int cmd__write_cache(int argc, const char **argv);
diff --git a/t/helper/test-trace.c b/t/helper/test-trace.c
new file mode 100644
index 000000000..1cc88b030
--- /dev/null
+++ b/t/helper/test-trace.c
@@ -0,0 +1,130 @@
+#include "test-tool.h"
+#include "cache.h"
+#include "run-command.h"
+
+static struct child_process children[2] = {
+	CHILD_PROCESS_INIT,
+	CHILD_PROCESS_INIT,
+};
+
+#define SAY(child, what) \
+	if (write_in_full(children[child].in, \
+			  what "\n", strlen(what) + 1) < 0) \
+		die("Failed to tell child process #%d to %s", child, what)
+
+#define LISTEN(child, what) \
+	if (strbuf_getwholeline_fd(&buf, children[child].out, '\n') < 0) \
+		die("Child process #%d failed to acknowledge %s", child, what)
+
+#define ACK(what) \
+	if (write_in_full(1, what ": ACK\n", strlen(what) + 6) < 0) \
+		die_errno("'%s': %s ACK", child_name, what)
+
+static void contention_orchestrator(const char *argv0)
+{
+	struct strbuf buf = STRBUF_INIT;
+	int i;
+
+	/* Spawn two children and simulate write contention */
+	trace_printf("start");
+
+	for (i = 0; i < 2; i++) {
+		strbuf_reset(&buf);
+		strbuf_addf(&buf, "child #%d", i);
+		argv_array_pushl(&children[i].args,
+					argv0, "trace", "lock", buf.buf, NULL);
+		children[i].in = children[i].out = -1;
+		if (start_command(&children[i]) < 0)
+			die("Could not spawn child process #%d", i);
+	}
+
+	SAY(1, "lock");
+	LISTEN(1, "lock");
+
+	SAY(0, "trace delayed");
+	SAY(1, "trace while-locked");
+	LISTEN(1, "trace");
+
+	SAY(1, "unlock");
+	LISTEN(1, "unlock");
+	LISTEN(0, "trace");
+
+	SAY(0, "quit");
+	SAY(1, "quit");
+
+	if (finish_command(&children[0]) < 0 ||
+		finish_command(&children[1]) < 0)
+		die("Child process failed to finish");
+
+	strbuf_release(&buf);
+}
+
+static void child(const char *child_name)
+{
+	struct strbuf buf = STRBUF_INIT;
+	int fd, locked = 0;
+	const char *p;
+
+	/* This is the child process */
+	trace_printf("child start: '%s'", child_name);
+	fd = trace_default_key.fd;
+	if (fd <= 0)
+		die("child process: not tracing...");
+	while (!strbuf_getwholeline_fd(&buf, 0, '\n')) {
+		strbuf_rtrim(&buf);
+		if (!strcmp("lock", buf.buf)) {
+			if (lock_or_unlock_fd_for_appending(fd, 1) < 0 &&
+			    errno != EBADF)
+				die_errno("'%s': lock", child_name);
+			ACK("lock");
+			locked = 1;
+		} else if (!strcmp("unlock", buf.buf)) {
+			if (lock_or_unlock_fd_for_appending(fd, 0) < 0 &&
+			    errno != EBADF)
+				die_errno("'%s': unlock", child_name);
+			ACK("unlock");
+			locked = 0;
+		} else if (skip_prefix(buf.buf, "trace ", &p)) {
+			if (!locked)
+				trace_printf("%s: %s", child_name, p);
+			else {
+				char *p2 = xstrdup(p);
+
+				/* Give the racy process a run for its money. */
+				sleep_millisec(50);
+
+				strbuf_reset(&buf);
+				strbuf_addf(&buf, "%s: %s\n",
+					    child_name, p2);
+				free(p2);
+
+				if (write_in_full(fd, buf.buf, buf.len) < 0)
+					die_errno("'%s': trace", child_name);
+			}
+			ACK("trace");
+		} else if (!strcmp("quit", buf.buf)) {
+			close(0);
+			close(1);
+			break;
+		} else
+			die("Unhandled command: '%s'", buf.buf);
+
+	}
+
+	strbuf_release(&buf);
+}
+
+int cmd__trace(int argc, const char **argv)
+{
+	const char *argv0 = argv[-1];
+
+	if (argc > 1 && !strcmp("lock", argv[1])) {
+		if (argc > 2)
+			child(argv[2]);
+		else
+			contention_orchestrator(argv0);
+	} else
+		die("Usage: %s %s lock [<child-name>]", argv0, argv[0]);
+
+	return 0;
+}
diff --git a/t/t0070-fundamental.sh b/t/t0070-fundamental.sh
index 23fbe6434..57f7a1246 100755
--- a/t/t0070-fundamental.sh
+++ b/t/t0070-fundamental.sh
@@ -34,4 +34,10 @@ test_expect_success 'check for a bug in the regex routines' '
 	test-tool regex --bug
 '
 
+test_expect_success 'multiple processes can GIT_TRACE to the same file' '
+	GIT_TRACE="$(pwd)/trace" test-tool trace lock &&
+	sed -n "/while-locked/,\$s/.*delayed$/YES/p" <trace >actual &&
+	test YES = "$(cat actual)"
+'
+
 test_done
-- 
gitgitgadget

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Jeff King]

On Thu, Aug 09, 2018 at 10:35:24AM -0700, Johannes Schindelin via GitGitGadget wrote:

> The culprit is that two processes try simultaneously to write to the same
> file specified via GIT_TRACE_PACKET, and it is not well defined how that
> should work, even on Linux.

Are you sure that it's not well-defined? We open the path with O_APPEND,
which means every write() will be atomically positioned at the end of
file. So we would never lose or overwrite data.

We do our own buffering in a strbuf, writing the result out in a single
write() call (modulo the OS returning a short write, but that should not
generally happen when writing short strings to a file). So we should get
individual trace lines as atomic units.

The order of lines from the two processes is undefined, of course.

> This patch series addresses that by locking the trace fd. I chose to use 
> flock() instead of fcntl() because the Win32 API LockFileEx()
> [https://docs.microsoft.com/en-us/windows/desktop/api/fileapi/nf-fileapi-lockfileex] 
> (which does exactly what I want in this context) has much more similar
> semantics to the former than the latter.

I must admit I'm not excited to see us adding extra locking and
complexity when it is not necessarily needed. Is this a feature we
actually care about delivering for normal users of GIT_TRACE, or do we
just care about solving the test flakiness here?

Because we should be able to do the latter with the patch below.

I also wonder if we should be clearing GIT_TRACE as part of clearing
repo-env. It would do what we want automatically in this case, though
there are definitely cases where I prefer the current behavior (because
I really do want to see the upload-pack side of it). Of course I could
always use "--upload-pack 'GIT_TRACE_PACKET=... upload-pack'", so this
is really just a default.

diff --git a/t/t5552-skipping-fetch-negotiator.sh b/t/t5552-skipping-fetch-negotiator.sh
index 3b60bd44e0..5ad5bece55 100755
--- a/t/t5552-skipping-fetch-negotiator.sh
+++ b/t/t5552-skipping-fetch-negotiator.sh
@@ -28,6 +28,19 @@ have_not_sent () {
 	done
 }
 
+# trace_fetch <client_dir> <server_dir> [args]
+#
+# Trace the packet output of fetch, but make sure we disable the variable
+# in the child upload-pack, so we don't combine the results in the same file.
+trace_fetch () {
+	client=$1; shift
+	server=$1; shift
+	GIT_TRACE_PACKET="$(pwd)/trace" \
+	git -C "$client" fetch \
+	  --upload-pack 'unset GIT_TRACE_PACKET; git-upload-pack' \
+	  "$server" "$@"
+}
+
 test_expect_success 'commits with no parents are sent regardless of skip distance' '
 	git init server &&
 	test_commit -C server to_fetch &&
@@ -42,7 +55,7 @@ test_expect_success 'commits with no parents are sent regardless of skip distanc
 	# "c1" has no parent, it is still sent as "have" even though it would
 	# normally be skipped.
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
+	trace_fetch client "$(pwd)/server" &&
 	have_sent c7 c5 c2 c1 &&
 	have_not_sent c6 c4 c3
 '
@@ -88,7 +101,7 @@ test_expect_success 'when two skips collide, favor the larger one' '
 	# the next "have" sent will be "c1" (from "c6" skip 4) and not "c4"
 	# (from "c5side" skip 1).
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
+	trace_fetch client "$(pwd)/server" &&
 	have_sent c5side c11 c9 c6 c1 &&
 	have_not_sent c10 c8 c7 c5 c4 c3 c2
 '
@@ -114,7 +127,7 @@ test_expect_success 'use ref advertisement to filter out commits' '
 	# not need to send any ancestors of "c3", but we still need to send "c3"
 	# itself.
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch origin to_fetch &&
+	trace_fetch client origin to_fetch &&
 	have_sent c5 c4^ c2side &&
 	have_not_sent c4 c4^^ c4^^^
 '
@@ -144,7 +157,7 @@ test_expect_success 'handle clock skew' '
 	# and sent, because (due to clock skew) its only parent has already been
 	# popped off the priority queue.
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
+	trace_fetch client "$(pwd)/server" &&
 	have_sent c2 c1 old4 old2 old1 &&
 	have_not_sent old3
 '
@@ -176,7 +189,7 @@ test_expect_success 'do not send "have" with ancestors of commits that server AC
 	test_commit -C server commit-on-b1 &&
 
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" to_fetch &&
+	trace_fetch client "$(pwd)/server" to_fetch &&
 	grep "  fetch" trace &&
 
 	# fetch-pack sends 2 requests each containing 16 "have" lines before

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> Are you sure that it's not well-defined? We open the path with O_APPEND,
> which means every write() will be atomically positioned at the end of
> file. So we would never lose or overwrite data.
>
> We do our own buffering in a strbuf, writing the result out in a single
> write() call (modulo the OS returning a short write, but that should not
> generally happen when writing short strings to a file). So we should get
> individual trace lines as atomic units.
>
> The order of lines from the two processes is undefined, of course.

Correct.  But I am more worried about the "mixed/overwriting"
breakage, if there is one; it means we may need to be prepared for
systems that lack O_APPEND that works correctly.  I initially just
assumed that it was what Dscho was seeing, but after re-reading his
message, I am not sure anymore.

I think the "do not trace the other side" approach you suggest for
these tests that only care about one side is more appropriate
solution for this particular case.  We then do not have to worry
about overwriting or output from both sides mixed randomly.

> diff --git a/t/t5552-skipping-fetch-negotiator.sh b/t/t5552-skipping-fetch-negotiator.sh
> index 3b60bd44e0..5ad5bece55 100755
> --- a/t/t5552-skipping-fetch-negotiator.sh
> +++ b/t/t5552-skipping-fetch-negotiator.sh
> @@ -28,6 +28,19 @@ have_not_sent () {
>  	done
>  }
>  
> +# trace_fetch <client_dir> <server_dir> [args]
> +#
> +# Trace the packet output of fetch, but make sure we disable the variable
> +# in the child upload-pack, so we don't combine the results in the same file.
> +trace_fetch () {
> +	client=$1; shift
> +	server=$1; shift
> +	GIT_TRACE_PACKET="$(pwd)/trace" \
> +	git -C "$client" fetch \
> +	  --upload-pack 'unset GIT_TRACE_PACKET; git-upload-pack' \
> +	  "$server" "$@"
> +}
> +
>  test_expect_success 'commits with no parents are sent regardless of skip distance' '
>  	git init server &&
>  	test_commit -C server to_fetch &&
> @@ -42,7 +55,7 @@ test_expect_success 'commits with no parents are sent regardless of skip distanc
>  	# "c1" has no parent, it is still sent as "have" even though it would
>  	# normally be skipped.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c7 c5 c2 c1 &&
>  	have_not_sent c6 c4 c3
>  '
> @@ -88,7 +101,7 @@ test_expect_success 'when two skips collide, favor the larger one' '
>  	# the next "have" sent will be "c1" (from "c6" skip 4) and not "c4"
>  	# (from "c5side" skip 1).
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c5side c11 c9 c6 c1 &&
>  	have_not_sent c10 c8 c7 c5 c4 c3 c2
>  '
> @@ -114,7 +127,7 @@ test_expect_success 'use ref advertisement to filter out commits' '
>  	# not need to send any ancestors of "c3", but we still need to send "c3"
>  	# itself.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch origin to_fetch &&
> +	trace_fetch client origin to_fetch &&
>  	have_sent c5 c4^ c2side &&
>  	have_not_sent c4 c4^^ c4^^^
>  '
> @@ -144,7 +157,7 @@ test_expect_success 'handle clock skew' '
>  	# and sent, because (due to clock skew) its only parent has already been
>  	# popped off the priority queue.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c2 c1 old4 old2 old1 &&
>  	have_not_sent old3
>  '
> @@ -176,7 +189,7 @@ test_expect_success 'do not send "have" with ancestors of commits that server AC
>  	test_commit -C server commit-on-b1 &&
>  
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" to_fetch &&
> +	trace_fetch client "$(pwd)/server" to_fetch &&
>  	grep "  fetch" trace &&
>  
>  	# fetch-pack sends 2 requests each containing 16 "have" lines before

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Junio C Hamano]

Junio C Hamano <gitster@pobox.com> writes:

> Jeff King <peff@peff.net> writes:
>
>> Are you sure that it's not well-defined? We open the path with O_APPEND,
>> which means every write() will be atomically positioned at the end of
>> file. So we would never lose or overwrite data.
>>
>> We do our own buffering in a strbuf, writing the result out in a single
>> write() call (modulo the OS returning a short write, but that should not
>> generally happen when writing short strings to a file). So we should get
>> individual trace lines as atomic units.
>>
>> The order of lines from the two processes is undefined, of course.
>
> Correct.  But I am more worried about the "mixed/overwriting"
> breakage, if there is one; it means we may need to be prepared for
> systems that lack O_APPEND that works correctly.  I initially just
> assumed that it was what Dscho was seeing, but after re-reading his
> message, I am not sure anymore.
>
> I think the "do not trace the other side" approach you suggest for
> these tests that only care about one side is more appropriate
> solution for this particular case.  We then do not have to worry
> about overwriting or output from both sides mixed randomly.

A concluding sentence I forgot to add, after saying "this is simpler
and better to fix test breakage", was

	But if we really are seeing O_APPEND breakage, a mandatory
	locking mechanism like this one might be necessary to work
	around it (I seriously hope we do not have to, though).

Sorry for an additional noise.

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Jeff King]

On Thu, Aug 09, 2018 at 02:08:56PM -0700, Junio C Hamano wrote:

> > Correct.  But I am more worried about the "mixed/overwriting"
> > breakage, if there is one; it means we may need to be prepared for
> > systems that lack O_APPEND that works correctly.  I initially just
> > assumed that it was what Dscho was seeing, but after re-reading his
> > message, I am not sure anymore.
> >
> > I think the "do not trace the other side" approach you suggest for
> > these tests that only care about one side is more appropriate
> > solution for this particular case.  We then do not have to worry
> > about overwriting or output from both sides mixed randomly.
> 
> A concluding sentence I forgot to add, after saying "this is simpler
> and better to fix test breakage", was
> 
> 	But if we really are seeing O_APPEND breakage, a mandatory
> 	locking mechanism like this one might be necessary to work
> 	around it (I seriously hope we do not have to, though).
> 
> Sorry for an additional noise.

Yeah, my earlier email said "if we just care about this test, then...".

But if we do care about making this multiple-tracing case work all the
time, then we'd need some solution. If there's something that can work
like O_APPEND, even if we have to make some system-specific call, I'd
prefer that to locking.

I did some searching for atomic append on Windows and got mixed reports
on whether their FILE_DATA_APPEND does what we want or not. Knowing
nothing about msys, I'd _assume_ that O_APPEND would get translated to
that flag, but I got lost trying to find it in
git-for-windows/msys2-runtime.

Wouldn't it be wonderful if the solution were as simple as making sure
that flag was plumbed through? I seriously doubt it will be that easy,
though. :)

-Peff

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Jeff King]

On Thu, Aug 09, 2018 at 01:49:52PM -0700, Junio C Hamano wrote:

> Jeff King <peff@peff.net> writes:
> 
> > Are you sure that it's not well-defined? We open the path with O_APPEND,
> > which means every write() will be atomically positioned at the end of
> > file. So we would never lose or overwrite data.
> >
> > We do our own buffering in a strbuf, writing the result out in a single
> > write() call (modulo the OS returning a short write, but that should not
> > generally happen when writing short strings to a file). So we should get
> > individual trace lines as atomic units.
> >
> > The order of lines from the two processes is undefined, of course.
> 
> Correct.  But I am more worried about the "mixed/overwriting"
> breakage, if there is one; it means we may need to be prepared for
> systems that lack O_APPEND that works correctly.  I initially just
> assumed that it was what Dscho was seeing, but after re-reading his
> message, I am not sure anymore.
> 
> I think the "do not trace the other side" approach you suggest for
> these tests that only care about one side is more appropriate
> solution for this particular case.  We then do not have to worry
> about overwriting or output from both sides mixed randomly.

Here it is as a patch on top of jt/fetch-negotiator-skipping, which lets
us pursue any fix for interleaved trace output on Windows without the
pressure of an impending flaky test.

My gut says that looking into making O_APPEND work there is going to be
the nicest solution, but my gut is not very well versed in Windows
subtleties. ;)

-- >8 --
Subject: [PATCH] t5552: suppress upload-pack trace output

The t5552 test script uses GIT_TRACE_PACKET to monitor what
git-fetch sends and receives. However, because we're
accessing a local repository, the child upload-pack also
sends trace output to the same file.

On Linux, this works out OK. We open the trace file with
O_APPEND, so all writes are atomically positioned at the end
of the file. No data can be overwritten or omitted. And
since we prepare our small writes in a strbuf and write them
with a single write(), we should see each line as an atomic
unit. The order of lines between the two processes is
undefined, but the test script greps only for "fetch>" or
"fetch<" lines. So under Linux, the test results are
deterministic.

The test fails intermittently on Windows, however,
reportedly even overwriting bits of the output file (i.e.,
O_APPEND does not seem to give us an atomic position+write).

Since the test only cares about the trace output from fetch,
we can just disable the output from upload-pack. That
doesn't solve the greater question of O_APPEND/trace issues
under Windows, but it easily fixes the flakiness from this
test.

Reported-by: Johannes Schindelin <johannes.schindelin@gmx.de>
Signed-off-by: Jeff King <peff@peff.net>
---
I'm assuming that this really isn't triggerable on Linux. I tried and
couldn't manage to get it to fail, and the reasoning above explains why.
But I wasn't 100% clear that Dscho hadn't seen it fail on non-Windows.

 t/t5552-skipping-fetch-negotiator.sh | 23 ++++++++++++++++++-----
 1 file changed, 18 insertions(+), 5 deletions(-)

diff --git a/t/t5552-skipping-fetch-negotiator.sh b/t/t5552-skipping-fetch-negotiator.sh
index 0a8e0e42ed..0ad50dd839 100755
--- a/t/t5552-skipping-fetch-negotiator.sh
+++ b/t/t5552-skipping-fetch-negotiator.sh
@@ -28,6 +28,19 @@ have_not_sent () {
 	done
 }
 
+# trace_fetch <client_dir> <server_dir> [args]
+#
+# Trace the packet output of fetch, but make sure we disable the variable
+# in the child upload-pack, so we don't combine the results in the same file.
+trace_fetch () {
+	client=$1; shift
+	server=$1; shift
+	GIT_TRACE_PACKET="$(pwd)/trace" \
+	git -C "$client" fetch \
+	  --upload-pack 'unset GIT_TRACE_PACKET; git-upload-pack' \
+	  "$server" "$@"
+}
+
 test_expect_success 'commits with no parents are sent regardless of skip distance' '
 	git init server &&
 	test_commit -C server to_fetch &&
@@ -42,7 +55,7 @@ test_expect_success 'commits with no parents are sent regardless of skip distanc
 	# "c1" has no parent, it is still sent as "have" even though it would
 	# normally be skipped.
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
+	trace_fetch client "$(pwd)/server" &&
 	have_sent c7 c5 c2 c1 &&
 	have_not_sent c6 c4 c3
 '
@@ -65,7 +78,7 @@ test_expect_success 'when two skips collide, favor the larger one' '
 	# the next "have" sent will be "c1" (from "c6" skip 4) and not "c4"
 	# (from "c5side" skip 1).
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
+	trace_fetch client "$(pwd)/server" &&
 	have_sent c5side c11 c9 c6 c1 &&
 	have_not_sent c10 c8 c7 c5 c4 c3 c2
 '
@@ -91,7 +104,7 @@ test_expect_success 'use ref advertisement to filter out commits' '
 	# not need to send any ancestors of "c3", but we still need to send "c3"
 	# itself.
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch origin to_fetch &&
+	trace_fetch client origin to_fetch &&
 	have_sent c5 c4^ c2side &&
 	have_not_sent c4 c4^^ c4^^^
 '
@@ -121,7 +134,7 @@ test_expect_success 'handle clock skew' '
 	# and sent, because (due to clock skew) its only parent has already been
 	# popped off the priority queue.
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
+	trace_fetch client "$(pwd)/server" &&
 	have_sent c2 c1 old4 old2 old1 &&
 	have_not_sent old3
 '
@@ -153,7 +166,7 @@ test_expect_success 'do not send "have" with ancestors of commits that server AC
 	test_commit -C server commit-on-b1 &&
 
 	test_config -C client fetch.negotiationalgorithm skipping &&
-	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" to_fetch &&
+	trace_fetch client "$(pwd)/server" to_fetch &&
 	grep "  fetch" trace &&
 
 	# fetch-pack sends 2 requests each containing 16 "have" lines before
-- 
2.18.0.1058.g0926f0b71f

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> Here it is as a patch on top of jt/fetch-negotiator-skipping, which lets
> us pursue any fix for interleaved trace output on Windows without the
> pressure of an impending flaky test.
>
> My gut says that looking into making O_APPEND work there is going to be
> the nicest solution, but my gut is not very well versed in Windows
> subtleties. ;)

As we know these tests are only interested in "fetch" lines and not
record of communication in the other direction, I think this is a
nice clean-up that is worth doing.

For only two grep's it may not look worth doing, but it would be
also a good clean-up to give an got_acked helper that sits next to
have_sent and have_not_sent helpers for readability.  That is of
course outside the scope of this change.

Will queue.  Thansk.

> -- >8 --
> Subject: [PATCH] t5552: suppress upload-pack trace output
>
> The t5552 test script uses GIT_TRACE_PACKET to monitor what
> git-fetch sends and receives. However, because we're
> accessing a local repository, the child upload-pack also
> sends trace output to the same file.
>
> On Linux, this works out OK. We open the trace file with
> O_APPEND, so all writes are atomically positioned at the end
> of the file. No data can be overwritten or omitted. And
> since we prepare our small writes in a strbuf and write them
> with a single write(), we should see each line as an atomic
> unit. The order of lines between the two processes is
> undefined, but the test script greps only for "fetch>" or
> "fetch<" lines. So under Linux, the test results are
> deterministic.
>
> The test fails intermittently on Windows, however,
> reportedly even overwriting bits of the output file (i.e.,
> O_APPEND does not seem to give us an atomic position+write).
>
> Since the test only cares about the trace output from fetch,
> we can just disable the output from upload-pack. That
> doesn't solve the greater question of O_APPEND/trace issues
> under Windows, but it easily fixes the flakiness from this
> test.
>
> Reported-by: Johannes Schindelin <johannes.schindelin@gmx.de>
> Signed-off-by: Jeff King <peff@peff.net>
> ---
> I'm assuming that this really isn't triggerable on Linux. I tried and
> couldn't manage to get it to fail, and the reasoning above explains why.
> But I wasn't 100% clear that Dscho hadn't seen it fail on non-Windows.
>
>  t/t5552-skipping-fetch-negotiator.sh | 23 ++++++++++++++++++-----
>  1 file changed, 18 insertions(+), 5 deletions(-)
>
> diff --git a/t/t5552-skipping-fetch-negotiator.sh b/t/t5552-skipping-fetch-negotiator.sh
> index 0a8e0e42ed..0ad50dd839 100755
> --- a/t/t5552-skipping-fetch-negotiator.sh
> +++ b/t/t5552-skipping-fetch-negotiator.sh
> @@ -28,6 +28,19 @@ have_not_sent () {
>  	done
>  }
>  
> +# trace_fetch <client_dir> <server_dir> [args]
> +#
> +# Trace the packet output of fetch, but make sure we disable the variable
> +# in the child upload-pack, so we don't combine the results in the same file.
> +trace_fetch () {
> +	client=$1; shift
> +	server=$1; shift
> +	GIT_TRACE_PACKET="$(pwd)/trace" \
> +	git -C "$client" fetch \
> +	  --upload-pack 'unset GIT_TRACE_PACKET; git-upload-pack' \
> +	  "$server" "$@"
> +}
> +
>  test_expect_success 'commits with no parents are sent regardless of skip distance' '
>  	git init server &&
>  	test_commit -C server to_fetch &&
> @@ -42,7 +55,7 @@ test_expect_success 'commits with no parents are sent regardless of skip distanc
>  	# "c1" has no parent, it is still sent as "have" even though it would
>  	# normally be skipped.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c7 c5 c2 c1 &&
>  	have_not_sent c6 c4 c3
>  '
> @@ -65,7 +78,7 @@ test_expect_success 'when two skips collide, favor the larger one' '
>  	# the next "have" sent will be "c1" (from "c6" skip 4) and not "c4"
>  	# (from "c5side" skip 1).
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c5side c11 c9 c6 c1 &&
>  	have_not_sent c10 c8 c7 c5 c4 c3 c2
>  '
> @@ -91,7 +104,7 @@ test_expect_success 'use ref advertisement to filter out commits' '
>  	# not need to send any ancestors of "c3", but we still need to send "c3"
>  	# itself.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch origin to_fetch &&
> +	trace_fetch client origin to_fetch &&
>  	have_sent c5 c4^ c2side &&
>  	have_not_sent c4 c4^^ c4^^^
>  '
> @@ -121,7 +134,7 @@ test_expect_success 'handle clock skew' '
>  	# and sent, because (due to clock skew) its only parent has already been
>  	# popped off the priority queue.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c2 c1 old4 old2 old1 &&
>  	have_not_sent old3
>  '
> @@ -153,7 +166,7 @@ test_expect_success 'do not send "have" with ancestors of commits that server AC
>  	test_commit -C server commit-on-b1 &&
>  
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" to_fetch &&
> +	trace_fetch client "$(pwd)/server" to_fetch &&
>  	grep "  fetch" trace &&
>  
>  	# fetch-pack sends 2 requests each containing 16 "have" lines before

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> Here it is as a patch on top of jt/fetch-negotiator-skipping, which lets
> us pursue any fix for interleaved trace output on Windows without the
> pressure of an impending flaky test.
>
> My gut says that looking into making O_APPEND work there is going to be
> the nicest solution, but my gut is not very well versed in Windows
> subtleties. ;)

As we know these tests are only interested in "fetch" lines and not
record of communication in the other direction, I think this is a
nice clean-up that is worth doing.

For only two grep's it may not look worth doing, but it would be
also a good clean-up to give an got_acked helper that sits next to
have_sent and have_not_sent helpers for readability.  That is of
course outside the scope of this change.

Will queue.  Thanks.

> -- >8 --
> Subject: [PATCH] t5552: suppress upload-pack trace output
>
> The t5552 test script uses GIT_TRACE_PACKET to monitor what
> git-fetch sends and receives. However, because we're
> accessing a local repository, the child upload-pack also
> sends trace output to the same file.
>
> On Linux, this works out OK. We open the trace file with
> O_APPEND, so all writes are atomically positioned at the end
> of the file. No data can be overwritten or omitted. And
> since we prepare our small writes in a strbuf and write them
> with a single write(), we should see each line as an atomic
> unit. The order of lines between the two processes is
> undefined, but the test script greps only for "fetch>" or
> "fetch<" lines. So under Linux, the test results are
> deterministic.
>
> The test fails intermittently on Windows, however,
> reportedly even overwriting bits of the output file (i.e.,
> O_APPEND does not seem to give us an atomic position+write).
>
> Since the test only cares about the trace output from fetch,
> we can just disable the output from upload-pack. That
> doesn't solve the greater question of O_APPEND/trace issues
> under Windows, but it easily fixes the flakiness from this
> test.
>
> Reported-by: Johannes Schindelin <johannes.schindelin@gmx.de>
> Signed-off-by: Jeff King <peff@peff.net>
> ---
> I'm assuming that this really isn't triggerable on Linux. I tried and
> couldn't manage to get it to fail, and the reasoning above explains why.
> But I wasn't 100% clear that Dscho hadn't seen it fail on non-Windows.
>
>  t/t5552-skipping-fetch-negotiator.sh | 23 ++++++++++++++++++-----
>  1 file changed, 18 insertions(+), 5 deletions(-)
>
> diff --git a/t/t5552-skipping-fetch-negotiator.sh b/t/t5552-skipping-fetch-negotiator.sh
> index 0a8e0e42ed..0ad50dd839 100755
> --- a/t/t5552-skipping-fetch-negotiator.sh
> +++ b/t/t5552-skipping-fetch-negotiator.sh
> @@ -28,6 +28,19 @@ have_not_sent () {
>  	done
>  }
>  
> +# trace_fetch <client_dir> <server_dir> [args]
> +#
> +# Trace the packet output of fetch, but make sure we disable the variable
> +# in the child upload-pack, so we don't combine the results in the same file.
> +trace_fetch () {
> +	client=$1; shift
> +	server=$1; shift
> +	GIT_TRACE_PACKET="$(pwd)/trace" \
> +	git -C "$client" fetch \
> +	  --upload-pack 'unset GIT_TRACE_PACKET; git-upload-pack' \
> +	  "$server" "$@"
> +}
> +
>  test_expect_success 'commits with no parents are sent regardless of skip distance' '
>  	git init server &&
>  	test_commit -C server to_fetch &&
> @@ -42,7 +55,7 @@ test_expect_success 'commits with no parents are sent regardless of skip distanc
>  	# "c1" has no parent, it is still sent as "have" even though it would
>  	# normally be skipped.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c7 c5 c2 c1 &&
>  	have_not_sent c6 c4 c3
>  '
> @@ -65,7 +78,7 @@ test_expect_success 'when two skips collide, favor the larger one' '
>  	# the next "have" sent will be "c1" (from "c6" skip 4) and not "c4"
>  	# (from "c5side" skip 1).
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c5side c11 c9 c6 c1 &&
>  	have_not_sent c10 c8 c7 c5 c4 c3 c2
>  '
> @@ -91,7 +104,7 @@ test_expect_success 'use ref advertisement to filter out commits' '
>  	# not need to send any ancestors of "c3", but we still need to send "c3"
>  	# itself.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch origin to_fetch &&
> +	trace_fetch client origin to_fetch &&
>  	have_sent c5 c4^ c2side &&
>  	have_not_sent c4 c4^^ c4^^^
>  '
> @@ -121,7 +134,7 @@ test_expect_success 'handle clock skew' '
>  	# and sent, because (due to clock skew) its only parent has already been
>  	# popped off the priority queue.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c2 c1 old4 old2 old1 &&
>  	have_not_sent old3
>  '
> @@ -153,7 +166,7 @@ test_expect_success 'do not send "have" with ancestors of commits that server AC
>  	test_commit -C server commit-on-b1 &&
>  
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" to_fetch &&
> +	trace_fetch client "$(pwd)/server" to_fetch &&
>  	grep "  fetch" trace &&
>  
>  	# fetch-pack sends 2 requests each containing 16 "have" lines before

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Johannes Schindelin]

Hi,

On Fri, 10 Aug 2018, Jeff King wrote:

> On Thu, Aug 09, 2018 at 01:49:52PM -0700, Junio C Hamano wrote:
> 
> > Jeff King <peff@peff.net> writes:
> > 
> > > Are you sure that it's not well-defined? We open the path with O_APPEND,
> > > which means every write() will be atomically positioned at the end of
> > > file. So we would never lose or overwrite data.
> > >
> > > We do our own buffering in a strbuf, writing the result out in a single
> > > write() call (modulo the OS returning a short write, but that should not
> > > generally happen when writing short strings to a file). So we should get
> > > individual trace lines as atomic units.
> > >
> > > The order of lines from the two processes is undefined, of course.
> > 
> > Correct.  But I am more worried about the "mixed/overwriting"
> > breakage, if there is one; it means we may need to be prepared for
> > systems that lack O_APPEND that works correctly.  I initially just
> > assumed that it was what Dscho was seeing, but after re-reading his
> > message, I am not sure anymore.
> > 
> > I think the "do not trace the other side" approach you suggest for
> > these tests that only care about one side is more appropriate
> > solution for this particular case.  We then do not have to worry
> > about overwriting or output from both sides mixed randomly.

Just so everybody knows: I never received the above two mails. Something
is seriously rotten in GMX. This seems to have started a week or two ago.

> Here it is as a patch on top of jt/fetch-negotiator-skipping, which lets
> us pursue any fix for interleaved trace output on Windows without the
> pressure of an impending flaky test.
> 
> My gut says that looking into making O_APPEND work there is going to be
> the nicest solution, but my gut is not very well versed in Windows
> subtleties. ;)

Your patch seems to be a patch in the original sense of the word: it is
not a solution.

And let me spell it out very clearly (as I have mentioned to Jonathan a
couple times, without any response): t5552 fails regularly, way more than
rarely, see for yourself:

https://git-for-windows.visualstudio.com/git/_build/index?definitionId=1&_a=history

And the reason it fails was analyzed by me and described in the commit
message (I am sorry that the cover letter was still stale and talked
about flock(), which I had decided was not the right approach after
fighting with Linux over it).

What you cannot see easily, unless you go the route that I offered
Jonathan (open a PR on gitgitgadget/git which will automatically run the
test suite on Windows, macOS and Linux, and of course you can do anything
in a PR, including narrowing down what tests are run) is that sometimes
those lines in the `trace` file were clearly *incomplete*. That is, even
if both processes tried to write atomically, one managed to overwrite the
other's buffer in flight.

This is a pretty serious thing, even worse than the failing test suite,
and I don't think that your patch acknowledges how serious this is.

And please don't give me that "but it works on Linux" response. Seriously.
Sheesh.

Even if you have not managed to trigger it, the POSIX standard seems not
to define clearly what the behavior is of two competing write() calls,
unless you lock the files appropriately, as my patch series does.

So unless you are willing to ignore, to willfully keep this breakage, I
would suggest not to introduce the ugliness of an overridden upload-pack
for the sole purpose of disabling the tracing on one side, but instead to
get this here bug fixed, by helping me with this here patch series.

We don't have to rush this, you know? We have to fix it, though.

Thank you,
Dscho

> -- >8 --
> Subject: [PATCH] t5552: suppress upload-pack trace output
> 
> The t5552 test script uses GIT_TRACE_PACKET to monitor what
> git-fetch sends and receives. However, because we're
> accessing a local repository, the child upload-pack also
> sends trace output to the same file.
> 
> On Linux, this works out OK. We open the trace file with
> O_APPEND, so all writes are atomically positioned at the end
> of the file. No data can be overwritten or omitted. And
> since we prepare our small writes in a strbuf and write them
> with a single write(), we should see each line as an atomic
> unit. The order of lines between the two processes is
> undefined, but the test script greps only for "fetch>" or
> "fetch<" lines. So under Linux, the test results are
> deterministic.
> 
> The test fails intermittently on Windows, however,
> reportedly even overwriting bits of the output file (i.e.,
> O_APPEND does not seem to give us an atomic position+write).
> 
> Since the test only cares about the trace output from fetch,
> we can just disable the output from upload-pack. That
> doesn't solve the greater question of O_APPEND/trace issues
> under Windows, but it easily fixes the flakiness from this
> test.
> 
> Reported-by: Johannes Schindelin <johannes.schindelin@gmx.de>
> Signed-off-by: Jeff King <peff@peff.net>
> ---
> I'm assuming that this really isn't triggerable on Linux. I tried and
> couldn't manage to get it to fail, and the reasoning above explains why.
> But I wasn't 100% clear that Dscho hadn't seen it fail on non-Windows.
> 
>  t/t5552-skipping-fetch-negotiator.sh | 23 ++++++++++++++++++-----
>  1 file changed, 18 insertions(+), 5 deletions(-)
> 
> diff --git a/t/t5552-skipping-fetch-negotiator.sh b/t/t5552-skipping-fetch-negotiator.sh
> index 0a8e0e42ed..0ad50dd839 100755
> --- a/t/t5552-skipping-fetch-negotiator.sh
> +++ b/t/t5552-skipping-fetch-negotiator.sh
> @@ -28,6 +28,19 @@ have_not_sent () {
>  	done
>  }
>  
> +# trace_fetch <client_dir> <server_dir> [args]
> +#
> +# Trace the packet output of fetch, but make sure we disable the variable
> +# in the child upload-pack, so we don't combine the results in the same file.
> +trace_fetch () {
> +	client=$1; shift
> +	server=$1; shift
> +	GIT_TRACE_PACKET="$(pwd)/trace" \
> +	git -C "$client" fetch \
> +	  --upload-pack 'unset GIT_TRACE_PACKET; git-upload-pack' \
> +	  "$server" "$@"
> +}
> +
>  test_expect_success 'commits with no parents are sent regardless of skip distance' '
>  	git init server &&
>  	test_commit -C server to_fetch &&
> @@ -42,7 +55,7 @@ test_expect_success 'commits with no parents are sent regardless of skip distanc
>  	# "c1" has no parent, it is still sent as "have" even though it would
>  	# normally be skipped.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c7 c5 c2 c1 &&
>  	have_not_sent c6 c4 c3
>  '
> @@ -65,7 +78,7 @@ test_expect_success 'when two skips collide, favor the larger one' '
>  	# the next "have" sent will be "c1" (from "c6" skip 4) and not "c4"
>  	# (from "c5side" skip 1).
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c5side c11 c9 c6 c1 &&
>  	have_not_sent c10 c8 c7 c5 c4 c3 c2
>  '
> @@ -91,7 +104,7 @@ test_expect_success 'use ref advertisement to filter out commits' '
>  	# not need to send any ancestors of "c3", but we still need to send "c3"
>  	# itself.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch origin to_fetch &&
> +	trace_fetch client origin to_fetch &&
>  	have_sent c5 c4^ c2side &&
>  	have_not_sent c4 c4^^ c4^^^
>  '
> @@ -121,7 +134,7 @@ test_expect_success 'handle clock skew' '
>  	# and sent, because (due to clock skew) its only parent has already been
>  	# popped off the priority queue.
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" &&
> +	trace_fetch client "$(pwd)/server" &&
>  	have_sent c2 c1 old4 old2 old1 &&
>  	have_not_sent old3
>  '
> @@ -153,7 +166,7 @@ test_expect_success 'do not send "have" with ancestors of commits that server AC
>  	test_commit -C server commit-on-b1 &&
>  
>  	test_config -C client fetch.negotiationalgorithm skipping &&
> -	GIT_TRACE_PACKET="$(pwd)/trace" git -C client fetch "$(pwd)/server" to_fetch &&
> +	trace_fetch client "$(pwd)/server" to_fetch &&
>  	grep "  fetch" trace &&
>  
>  	# fetch-pack sends 2 requests each containing 16 "have" lines before
> -- 
> 2.18.0.1058.g0926f0b71f
> 
> 

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Jeff King]

On Fri, Aug 10, 2018 at 06:43:07PM +0200, Johannes Schindelin wrote:

> > > Correct.  But I am more worried about the "mixed/overwriting"
> > > breakage, if there is one; it means we may need to be prepared for
> > > systems that lack O_APPEND that works correctly.  I initially just
> > > assumed that it was what Dscho was seeing, but after re-reading his
> > > message, I am not sure anymore.
> > > 
> > > I think the "do not trace the other side" approach you suggest for
> > > these tests that only care about one side is more appropriate
> > > solution for this particular case.  We then do not have to worry
> > > about overwriting or output from both sides mixed randomly.
> 
> Just so everybody knows: I never received the above two mails. Something
> is seriously rotten in GMX. This seems to have started a week or two ago.

I think it may just have been that they went to the gitgitgadget
address; I explicitly added you as a cc when I sent the patch with a
commit message, which was when I first noticed you weren't cc'd on the
earlier bits.

> What you cannot see easily, unless you go the route that I offered
> Jonathan (open a PR on gitgitgadget/git which will automatically run the
> test suite on Windows, macOS and Linux, and of course you can do anything
> in a PR, including narrowing down what tests are run) is that sometimes
> those lines in the `trace` file were clearly *incomplete*. That is, even
> if both processes tried to write atomically, one managed to overwrite the
> other's buffer in flight.
> 
> This is a pretty serious thing, even worse than the failing test suite,
> and I don't think that your patch acknowledges how serious this is.

I don't see anything in what you wrote above or in your original cover
letter or series that contradicts the notion that O_APPEND is simply not
atomic on Windows. Overwriting the same byte ranges in the file is what
I would expect on Linux, as well, if the file were opened without
O_APPEND.

I have mixed reports from searching online whether an equivalent to
O_APPEND exists. Some sources seem to say that FILE_APPEND_DATA is.  I
couldn't find anything definitive in Microsoft documentation about
whether it actually provides atomicity.  From my (admittedly limited)
digging, that does not seem to be used by the msys2 runtime, so it might
be worth exploring.

> And please don't give me that "but it works on Linux" response. Seriously.
> Sheesh.

But it does. And it's designed to. There is literally nothing to fix on
Linux.

> Even if you have not managed to trigger it, the POSIX standard seems not
> to define clearly what the behavior is of two competing write() calls,
> unless you lock the files appropriately, as my patch series does.

POSIX says:

  If the O_APPEND flag of the file status flags is set, the file offset
  shall be set to the end of the file prior to each write and no
  intervening file modification operation shall occur between changing
  the file offset and the write operation.

and:

  This volume of POSIX.1-2017 does not specify the behavior of
  concurrent writes to a regular file from multiple threads, except that
  each write is atomic.

I admit the writing is a little turgid, but I think between the two it
is promising the behavior that we expect (and I think that
interpretation is pretty common in the Unix world).

> So unless you are willing to ignore, to willfully keep this breakage, I
> would suggest not to introduce the ugliness of an overridden upload-pack
> for the sole purpose of disabling the tracing on one side, but instead to
> get this here bug fixed, by helping me with this here patch series.

I'm OK if you want to live with the broken test in the interim. But
after your complaining about the imminence of it "infecting" master, I
thought you might be happy to see a solution that was more immediate.

I have tried to help with the actual problem, by identifying the root
cause (that the trace code's strategy is not fundamentally broken, but
that it relies on O_APPEND whose guarantees are obviously not portable
to Windows) and exploring possible solutions there (FILE_APPEND_DATA).

Lacking any kind of Windows development environment, I'd just as soon
stop there and let more knowledgeable people take over. But please don't
characterize my presence in this thread as some kind of willful harm or
ignoring of the problem.

-Peff

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> I have tried to help with the actual problem, by identifying the root
> cause (that the trace code's strategy is not fundamentally broken, but
> that it relies on O_APPEND whose guarantees are obviously not portable
> to Windows) and exploring possible solutions there (FILE_APPEND_DATA).
>
> Lacking any kind of Windows development environment, I'd just as soon
> stop there and let more knowledgeable people take over. But please don't
> characterize my presence in this thread as some kind of willful harm or
> ignoring of the problem.

Thanks.

It seems like the other Johannes and the other Jeff are also
interested, so we may hopefully see a properly fixed O_APPEND,
which would be the real solution that would help appenders
that are *not* tracing subsystem, too.

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Johannes Schindelin]

Hi Peff,

On Fri, 10 Aug 2018, Jeff King wrote:

> On Fri, Aug 10, 2018 at 06:43:07PM +0200, Johannes Schindelin wrote:
> 
> > So unless you are willing to ignore, to willfully keep this breakage,
> > I would suggest not to introduce the ugliness of an overridden
> > upload-pack for the sole purpose of disabling the tracing on one side,
> > but instead to get this here bug fixed, by helping me with this here
> > patch series.
> 
> I'm OK if you want to live with the broken test in the interim.

I realize that I failed to tell you that I basically spent 2.5 days worth
of worktime to figure this out and come up with three iterations of the
patch series (you only saw the latest).

I want this patch series in git.git, maybe not in the current form, but in
one form or another. I don't want to spend any more minute on trying to
figure out the same problem with any other regression test (which might
not even be as easily worked around as with a semi-simple --upload-pack
option).

Thank you for wanting to help. Please accept my apologies for expressing
in a poor way that I appreciate your eagerness to provide a patch, but
that I think nevertheless that it would be better to work on the GIT_TRACE
concurrency problem and its resolution via file locks. It would solve that
class of problems, instead of that single regression test being flakey.

Sorry,
Dscho

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Johannes Sixt]

Am 09.08.2018 um 19:35 schrieb Johannes Schindelin via GitGitGadget:
> I reported a couple of times that t5552 is not passing reliably. It has now
> reached next, and will no doubt infect master soon.
> 
> Turns out that it is not a Windows-specific issue, even if it occurs a lot
> more often on Windows than elsewhere.
> 
> The culprit is that two processes try simultaneously to write to the same
> file specified via GIT_TRACE_PACKET, and it is not well defined how that
> should work, even on Linux.

Thanks for digging down to the root cause. As has been said, the 
behavior of O_APPEND is well-defined under POSIX, but last time I looked 
for equivalent feature on Windows, I did not find any.

Last time was when I worked around the same failure in 
t5503-tagfollow.sh in my private builds:

https://github.com/j6t/git/commit/9a447a6844b50b43746d9765b3ac809e2793d742

It is basically the same as Peff suggests: log only one side of the fetch.

As this buglet looks like a recurring theme, and a proper fix is 
preferable over repeated work-arounds. To me it looks like we need some 
sort of locking on Windows. Unless your friends at Microsoft have an ace 
in their sleeves that lets us have atomic O_APPEND the POSIX way...

-- Hannes

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Jeff Hostetler]

On 8/10/2018 12:15 PM, Johannes Sixt wrote:
> Am 09.08.2018 um 19:35 schrieb Johannes Schindelin via GitGitGadget:
>> I reported a couple of times that t5552 is not passing reliably. It 
>> has now
>> reached next, and will no doubt infect master soon.
>>
>> Turns out that it is not a Windows-specific issue, even if it occurs a 
>> lot
>> more often on Windows than elsewhere.
>>
>> The culprit is that two processes try simultaneously to write to the same
>> file specified via GIT_TRACE_PACKET, and it is not well defined how that
>> should work, even on Linux.
> 
> Thanks for digging down to the root cause. As has been said, the 
> behavior of O_APPEND is well-defined under POSIX, but last time I looked 
> for equivalent feature on Windows, I did not find any.
> 
> Last time was when I worked around the same failure in 
> t5503-tagfollow.sh in my private builds:
> 
> https://github.com/j6t/git/commit/9a447a6844b50b43746d9765b3ac809e2793d742
> 
> It is basically the same as Peff suggests: log only one side of the fetch.
> 
> As this buglet looks like a recurring theme, and a proper fix is 
> preferable over repeated work-arounds. To me it looks like we need some 
> sort of locking on Windows. Unless your friends at Microsoft have an ace 
> in their sleeves that lets us have atomic O_APPEND the POSIX way...

The official Windows CRT for open() does document an O_APPEND, but after
looking at the distributed source, I'm not sure I trust it.

I have not looked at the MSYS version of the CRT yet so I cannot comment
on it.

I did find that the following code does what we want.  Notice the use of
FILE_APPEND_DATA in place of the usual GENERIC_READ.  (And yes, the docs
are very vague here.)

Before we try a locking solution, perhaps we should tweak mingw_open()
to use something like this to get a proper HANDLE directly and then use
_open_osfhandle() to get a "fd" for it.

Jeff

---------------------------------------------------------------------

#include <Windows.h>

int main()
{
	HANDLE h = CreateFileW(L"foo.txt",
		FILE_APPEND_DATA,
		FILE_SHARE_READ | FILE_SHARE_WRITE | FILE_SHARE_DELETE,
		NULL, OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);

	const char * buf = "this is a test\n";
	DWORD len = strlen(buf);
	DWORD nbw;

	WriteFile(h, buf, len, &nbw, NULL);
	CloseHandle(h);

	return 0;
}

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Jeff Hostetler]

On 8/10/2018 12:51 PM, Jeff Hostetler wrote:
> 
> 
> On 8/10/2018 12:15 PM, Johannes Sixt wrote:
>> Am 09.08.2018 um 19:35 schrieb Johannes Schindelin via GitGitGadget:
>>> I reported a couple of times that t5552 is not passing reliably. It 
>>> has now
>>> reached next, and will no doubt infect master soon.
>>>
>>> Turns out that it is not a Windows-specific issue, even if it occurs 
>>> a lot
>>> more often on Windows than elsewhere.
>>>
>>> The culprit is that two processes try simultaneously to write to the 
>>> same
>>> file specified via GIT_TRACE_PACKET, and it is not well defined how that
>>> should work, even on Linux.
>>
>> Thanks for digging down to the root cause. As has been said, the 
>> behavior of O_APPEND is well-defined under POSIX, but last time I 
>> looked for equivalent feature on Windows, I did not find any.
>>
>> Last time was when I worked around the same failure in 
>> t5503-tagfollow.sh in my private builds:
>>
>> https://github.com/j6t/git/commit/9a447a6844b50b43746d9765b3ac809e2793d742 
>>
>>
>> It is basically the same as Peff suggests: log only one side of the 
>> fetch.
>>
>> As this buglet looks like a recurring theme, and a proper fix is 
>> preferable over repeated work-arounds. To me it looks like we need 
>> some sort of locking on Windows. Unless your friends at Microsoft have 
>> an ace in their sleeves that lets us have atomic O_APPEND the POSIX 
>> way...
> 
> The official Windows CRT for open() does document an O_APPEND, but after
> looking at the distributed source, I'm not sure I trust it.
> 
> I have not looked at the MSYS version of the CRT yet so I cannot comment
> on it.
> 
> I did find that the following code does what we want.  Notice the use of
> FILE_APPEND_DATA in place of the usual GENERIC_READ.  (And yes, the docs
> are very vague here.)

d'oh

s/GENERIC_READ/GENERIC_WRITE/

> 
> Before we try a locking solution, perhaps we should tweak mingw_open()
> to use something like this to get a proper HANDLE directly and then use
> _open_osfhandle() to get a "fd" for it.
> 
> Jeff
> 
> ---------------------------------------------------------------------
> 
> #include <Windows.h>
> 
> int main()
> {
>      HANDLE h = CreateFileW(L"foo.txt",
>          FILE_APPEND_DATA,
>          FILE_SHARE_READ | FILE_SHARE_WRITE | FILE_SHARE_DELETE,
>          NULL, OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
> 
>      const char * buf = "this is a test\n";
>      DWORD len = strlen(buf);
>      DWORD nbw;
> 
>      WriteFile(h, buf, len, &nbw, NULL);
>      CloseHandle(h);
> 
>      return 0;
> }

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Johannes Sixt]

Am 10.08.2018 um 18:51 schrieb Jeff Hostetler:
> 
> 
> On 8/10/2018 12:15 PM, Johannes Sixt wrote:
>> Am 09.08.2018 um 19:35 schrieb Johannes Schindelin via GitGitGadget:
>>> I reported a couple of times that t5552 is not passing reliably. It 
>>> has now
>>> reached next, and will no doubt infect master soon.
>>>
>>> Turns out that it is not a Windows-specific issue, even if it occurs 
>>> a lot
>>> more often on Windows than elsewhere.
>>>
>>> The culprit is that two processes try simultaneously to write to the 
>>> same
>>> file specified via GIT_TRACE_PACKET, and it is not well defined how that
>>> should work, even on Linux.
>>
>> Thanks for digging down to the root cause. As has been said, the 
>> behavior of O_APPEND is well-defined under POSIX, but last time I 
>> looked for equivalent feature on Windows, I did not find any.
>>
>> Last time was when I worked around the same failure in 
>> t5503-tagfollow.sh in my private builds:
>>
>> https://github.com/j6t/git/commit/9a447a6844b50b43746d9765b3ac809e2793d742 
>>
>>
>> It is basically the same as Peff suggests: log only one side of the 
>> fetch.
>>
>> As this buglet looks like a recurring theme, and a proper fix is 
>> preferable over repeated work-arounds. To me it looks like we need 
>> some sort of locking on Windows. Unless your friends at Microsoft have 
>> an ace in their sleeves that lets us have atomic O_APPEND the POSIX 
>> way...
> 
> The official Windows CRT for open() does document an O_APPEND, but after
> looking at the distributed source, I'm not sure I trust it.

I looked at the CRT code, too, and no, we can't trust it.

> I have not looked at the MSYS version of the CRT yet so I cannot comment
> on it.
> 
> I did find that the following code does what we want.  Notice the use of
> FILE_APPEND_DATA in place of the usual GENERIC_READ.  (And yes, the docs
> are very vague here.)

As far as I understand, FILE_APPEND_DATA is just a permission flag (I'm 
not sure why that would be necessary), but at least the documentation 
states that it is still necessary for the caller to set the file pointer.

But I haven't tried your code below, yet. Should it append the line of 
text on each invocation? And if so, is it an atomic operation?

> Before we try a locking solution, perhaps we should tweak mingw_open()
> to use something like this to get a proper HANDLE directly and then use
> _open_osfhandle() to get a "fd" for it.
> 
> Jeff
> 
> ---------------------------------------------------------------------
> 
> #include <Windows.h>
> 
> int main()
> {
>      HANDLE h = CreateFileW(L"foo.txt",
>          FILE_APPEND_DATA,
>          FILE_SHARE_READ | FILE_SHARE_WRITE | FILE_SHARE_DELETE,
>          NULL, OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
> 
>      const char * buf = "this is a test\n";
>      DWORD len = strlen(buf);
>      DWORD nbw;
> 
>      WriteFile(h, buf, len, &nbw, NULL);
>      CloseHandle(h);
> 
>      return 0;
> }
> 

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Junio C Hamano]

Johannes Sixt <j6t@kdbg.org> writes:

> As this buglet looks like a recurring theme, and a proper fix is
> preferable over repeated work-arounds. To me it looks like we need
> some sort of locking on Windows. Unless your friends at Microsoft have
> an ace in their sleeves that lets us have atomic O_APPEND the POSIX
> way...

Just to put the severity of the issue in context, we use O_APPEND in
a few codepaths, and the trace thing for debugging is the only thing
that could have multiple writers.  Other users of O_APPEND are:

 * refs/files-backend.c uses it so that a reflog entry can be
   appended at the end, but because update to each ref is protected
   from racing at a lot higher layer with a lock, no two people
   would try to append to the same reflog file, so atomicity of
   O_APPEND does not matter here.

 * sequencer.c wants to use it when moving one insn from the todo
   list to the 'done' list when it finishes one operation.  If you
   are running two sequences in a single repository, intermixed
   'done' list would be the least of your problem, so presumably we
   are fine here.

It may make sense to allow GIT_TRACE to have a placeholder
(e.g. "/tmp/traceout.$$") to help debuggers arrange to give
different processes their own trace output file, which perhaps may
be a simpler and less impactful to the performance solution than
having to make locks at an application layer.

Re: [PATCH 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Jeff King]

On Fri, Aug 10, 2018 at 11:34:59AM -0700, Junio C Hamano wrote:

> Johannes Sixt <j6t@kdbg.org> writes:
> 
> > As this buglet looks like a recurring theme, and a proper fix is
> > preferable over repeated work-arounds. To me it looks like we need
> > some sort of locking on Windows. Unless your friends at Microsoft have
> > an ace in their sleeves that lets us have atomic O_APPEND the POSIX
> > way...
> 
> Just to put the severity of the issue in context, we use O_APPEND in
> a few codepaths, and the trace thing for debugging is the only thing
> that could have multiple writers.  Other users of O_APPEND are:
> 
>  * refs/files-backend.c uses it so that a reflog entry can be
>    appended at the end, but because update to each ref is protected
>    from racing at a lot higher layer with a lock, no two people
>    would try to append to the same reflog file, so atomicity of
>    O_APPEND does not matter here.

Just an interesting side note, but I think one of the reasons we use
dot-locks and not flock() is that the former generally works on network
filesystems. I think O_APPEND also is not reliable for non-local files,
though, so short of actually dot-locking trace files (yuck) I don't
think there's a great solution there.

> It may make sense to allow GIT_TRACE to have a placeholder
> (e.g. "/tmp/traceout.$$") to help debuggers arrange to give
> different processes their own trace output file, which perhaps may
> be a simpler and less impactful to the performance solution than
> having to make locks at an application layer.

Heh, I actually wrote that patch several years ago, as part of an
abandoned effort to have config-triggered tracing (e.g., on the server
side where you're getting hundreds of requests and you want to enable
tracing on a repo for a slice of time).

One annoying thing for a case like the test in question is that you
don't actually know the pid of the process you're interested in. So we'd
generate two trace files, and then you'd have to figure out which one is
which. In my earlier work, I coupled it with some magic to allow
per-command config, like:

  [trace "fetch"]
  packet = /tmp/trace.%p

but you could also imagine a "%n" which uses the command name.

I don't remember why I abandoned it, but I think a lot had to do with
violating the "don't look at config" rules for our repo startup code. A
lot of that has been fixed since then, but I haven't really needed it.
If anybody is really interested, the patches are at:

  https://github.com/peff/git jk/trace-stdin

(my ultimate goal was to record stdin for pack-objects to replay slow
fetches, but I ended up hacking together a patch to pack-objects
instead).

-Peff

[PATCH] mingw: enable atomic O_APPEND

[Johannes Sixt]

The Windows CRT implements O_APPEND "manually": on write() calls, the
file pointer is set to EOF before the data is written. Clearly, this is
not atomic. And in fact, this is the root cause of failures observed in
t5552-skipping-fetch-negotiator.sh and t5503-tagfollow.sh, where
different processes write to the same trace file simultanously; it also
occurred in t5400-send-pack.sh, but there it was worked around in
71406ed4d6 ("t5400: avoid concurrent writes into a trace file",
2017-05-18).

Fortunately, Windows does support atomic O_APPEND semantics using the
file access mode FILE_APPEND_DATA. Provide an implementation that does.

This implementation is minimal in such a way that it only implements
the open modes that are actually used in the Git code base. Emulation
for other modes can be added as necessary later. To become aware of
the necessity early, the unusal error ENOSYS is reported if an
unsupported mode is encountered.

Diagnosed-by: Johannes Schindelin <Johannes.Schindelin@gmx.de>
Helped-by: Jeff Hostetler <git@jeffhostetler.com>
Signed-off-by: Johannes Sixt <j6t@kdbg.org>
---
 compat/mingw.c | 41 +++++++++++++++++++++++++++++++++++++++--
 1 file changed, 39 insertions(+), 2 deletions(-)

diff --git a/compat/mingw.c b/compat/mingw.c
index 6ded1c859f..858ca14a57 100644
--- a/compat/mingw.c
+++ b/compat/mingw.c
@@ -341,12 +341,44 @@ int mingw_mkdir(const char *path, int mode)
 	return ret;
 }
 
+static int mingw_open_append(wchar_t const *wfilename, int oflags, ...)
+{
+	HANDLE handle;
+	int fd;
+	DWORD create = (oflags & O_CREAT) ? OPEN_ALWAYS : OPEN_EXISTING;
+
+	/* only these flags are supported */
+	if ((oflags & ~O_CREAT) != (O_WRONLY | O_APPEND))
+		return errno = ENOSYS, -1;
+
+	/*
+	 * FILE_SHARE_WRITE is required to permit child processes
+	 * to append to the file.
+	 */
+	handle = CreateFileW(wfilename, FILE_APPEND_DATA,
+			FILE_SHARE_WRITE | FILE_SHARE_READ,
+			NULL, create, FILE_ATTRIBUTE_NORMAL, NULL);
+	if (handle == INVALID_HANDLE_VALUE)
+		return errno = err_win_to_posix(GetLastError()), -1;
+	/*
+	 * No O_APPEND here, because the CRT uses it only to reset the
+	 * file pointer to EOF on write(); but that is not necessary
+	 * for a file created with FILE_APPEND_DATA.
+	 */
+	fd = _open_osfhandle((intptr_t)handle, O_BINARY);
+	if (fd < 0)
+		CloseHandle(handle);
+	return fd;
+}
+
 int mingw_open (const char *filename, int oflags, ...)
 {
+	typedef int (*open_fn_t)(wchar_t const *wfilename, int oflags, ...);
 	va_list args;
 	unsigned mode;
 	int fd;
 	wchar_t wfilename[MAX_PATH];
+	open_fn_t open_fn;
 
 	va_start(args, oflags);
 	mode = va_arg(args, int);
@@ -355,9 +387,14 @@ int mingw_open (const char *filename, int oflags, ...)
 	if (filename && !strcmp(filename, "/dev/null"))
 		filename = "nul";
 
+	if (oflags & O_APPEND)
+		open_fn = mingw_open_append;
+	else
+		open_fn = _wopen;
+
 	if (xutftowcs_path(wfilename, filename) < 0)
 		return -1;
-	fd = _wopen(wfilename, oflags, mode);
+	fd = open_fn(wfilename, oflags, mode);
 
 	if (fd < 0 && (oflags & O_ACCMODE) != O_RDONLY && errno == EACCES) {
 		DWORD attrs = GetFileAttributesW(wfilename);
@@ -375,7 +412,7 @@ int mingw_open (const char *filename, int oflags, ...)
 		 * CREATE_ALWAYS flag of CreateFile()).
 		 */
 		if (fd < 0 && errno == EACCES)
-			fd = _wopen(wfilename, oflags & ~O_CREAT, mode);
+			fd = open_fn(wfilename, oflags & ~O_CREAT, mode);
 		if (fd >= 0 && set_hidden_flag(wfilename, 1))
 			warning("could not mark '%s' as hidden.", filename);
 	}
-- 
2.18.0.rc0.112.g5f42c6ebd3

Re: [PATCH] mingw: enable atomic O_APPEND

[Junio C Hamano]

Johannes Sixt <j6t@kdbg.org> writes:

> The Windows CRT implements O_APPEND "manually": on write() calls, the
> file pointer is set to EOF before the data is written. Clearly, this is
> not atomic. And in fact, this is the root cause of failures observed in
> t5552-skipping-fetch-negotiator.sh and t5503-tagfollow.sh, where
> different processes write to the same trace file simultanously; it also
> occurred in t5400-send-pack.sh, but there it was worked around in
> 71406ed4d6 ("t5400: avoid concurrent writes into a trace file",
> 2017-05-18).
>
> Fortunately, Windows does support atomic O_APPEND semantics using the
> file access mode FILE_APPEND_DATA. Provide an implementation that does.
>
> This implementation is minimal in such a way that it only implements
> the open modes that are actually used in the Git code base. Emulation
> for other modes can be added as necessary later. To become aware of
> the necessity early, the unusal error ENOSYS is reported if an
> unsupported mode is encountered.
>
> Diagnosed-by: Johannes Schindelin <Johannes.Schindelin@gmx.de>
> Helped-by: Jeff Hostetler <git@jeffhostetler.com>
> Signed-off-by: Johannes Sixt <j6t@kdbg.org>
> ---
>  compat/mingw.c | 41 +++++++++++++++++++++++++++++++++++++++--
>  1 file changed, 39 insertions(+), 2 deletions(-)

Nice.

I wonder how much more expensive using this implementation is
compared with the original "race susceptible" open(), when raciness
is known not to be an issue (e.g. there is higher level lock that
protects the appending).

If it turns out to be quite more costly, I do not think we'd mind
introducing a thin wrapper

#ifndef race_safe_append_open
#ifndef race_safe_append_open(fn) open(fn, O_WRONLY|O_APPEND|O_CREAT, 0666)
#endif

in git-compat-util.h after it includes "compat/mingw.h" and replace
the call to open(... O_APPEND ...) in trace.c::get_trace_fd() with a
call to that wrapper.  That way, other codepaths that use O_APPEND
(namely, reflog and todo-list writers) can avoid the additional
cost, if any.

Some may find it beneficial from code readability POV because that
approach marks the codepath that needs to have non-racy fd more
explicitly.

I am assuming that in this case other users of O_APPEND are not
performance critical, so hopefully the following is only theoretical
and not necessary.

 git-compat-util.h | 5 +++++
 trace.c           | 2 +-
 2 files changed, 6 insertions(+), 1 deletion(-)

diff --git a/git-compat-util.h b/git-compat-util.h
index 9a64998b24..a981c50800 100644
--- a/git-compat-util.h
+++ b/git-compat-util.h
@@ -218,6 +218,11 @@
 #else
 #include <stdint.h>
 #endif
+
+#ifndef race_safe_append_open
+#define race_safe_append_open(fn) open(fn, O_WRONLY|O_APPEND|O_CREAT, 0666)
+#endif
+
 #ifdef NO_INTPTR_T
 /*
  * On I16LP32, ILP32 and LP64 "long" is the save bet, however
diff --git a/trace.c b/trace.c
index fc623e91fd..bef9cee1da 100644
--- a/trace.c
+++ b/trace.c
@@ -47,7 +47,7 @@ static int get_trace_fd(struct trace_key *key)
 	else if (strlen(trace) == 1 && isdigit(*trace))
 		key->fd = atoi(trace);
 	else if (is_absolute_path(trace)) {
-		int fd = open(trace, O_WRONLY | O_APPEND | O_CREAT, 0666);
+		int fd = race_safe_append_open(trace);
 		if (fd == -1) {
 			warning("could not open '%s' for tracing: %s",
 				trace, strerror(errno));

Re: [PATCH] mingw: enable atomic O_APPEND

[Johannes Sixt]

Am 13.08.2018 um 22:20 schrieb Junio C Hamano:
> Johannes Sixt <j6t@kdbg.org> writes:
> 
>> The Windows CRT implements O_APPEND "manually": on write() calls, the
>> file pointer is set to EOF before the data is written. Clearly, this is
>> not atomic. And in fact, this is the root cause of failures observed in
>> t5552-skipping-fetch-negotiator.sh and t5503-tagfollow.sh, where
>> different processes write to the same trace file simultanously; it also
>> occurred in t5400-send-pack.sh, but there it was worked around in
>> 71406ed4d6 ("t5400: avoid concurrent writes into a trace file",
>> 2017-05-18).
>>
>> Fortunately, Windows does support atomic O_APPEND semantics using the
>> file access mode FILE_APPEND_DATA. Provide an implementation that does.
>>
>> This implementation is minimal in such a way that it only implements
>> the open modes that are actually used in the Git code base. Emulation
>> for other modes can be added as necessary later. To become aware of
>> the necessity early, the unusal error ENOSYS is reported if an
>> unsupported mode is encountered.
>>
>> Diagnosed-by: Johannes Schindelin <Johannes.Schindelin@gmx.de>
>> Helped-by: Jeff Hostetler <git@jeffhostetler.com>
>> Signed-off-by: Johannes Sixt <j6t@kdbg.org>
>> ---
>>   compat/mingw.c | 41 +++++++++++++++++++++++++++++++++++++++--
>>   1 file changed, 39 insertions(+), 2 deletions(-)
> 
> Nice.
> 
> I wonder how much more expensive using this implementation is
> compared with the original "race susceptible" open(), when raciness
> is known not to be an issue (e.g. there is higher level lock that
> protects the appending).

Certainly, the former way that uses two syscalls 
(SetFilePointer+WriteFile) is more costly than this new way with just 
one syscall (WriteFile). Of course, I don't know how atomic append would 
be implemented in the kernel, but I can't think of a reason why it 
should be slow on Windows, but fast on POSIX.

(But I can't provide numbers to back up my gut feeling...)

(And I also assume that you are not worried about the performance of 
open() itself.)

> ...[define race_safe_append_open]... and replace
> the call to open(... O_APPEND ...) in trace.c::get_trace_fd() with a
> call to that wrapper.  That way, other codepaths that use O_APPEND
> (namely, reflog and todo-list writers) can avoid the additional
> cost, if any.
> 
> Some may find it beneficial from code readability POV because that
> approach marks the codepath that needs to have non-racy fd more
> explicitly.

O_APPEND is POSIX and means race-free append. If you mark some call 
sites with O_APPEND, then that must be the ones that need race-free 
append. Hence, you would have to go the other route: Mark those call 
sites that do _not_ need race-free append with some custom 
function/macro. (Or mark both with different helpers and avoid writing 
down O_APPEND.)

-- Hannes

Re: [PATCH] mingw: enable atomic O_APPEND

[Ævar Arnfjörð Bjarmason]

On Mon, Aug 13 2018, Johannes Sixt wrote:

> Am 13.08.2018 um 22:20 schrieb Junio C Hamano:
>> Johannes Sixt <j6t@kdbg.org> writes:
>>
>>> The Windows CRT implements O_APPEND "manually": on write() calls, the
>>> file pointer is set to EOF before the data is written. Clearly, this is
>>> not atomic. And in fact, this is the root cause of failures observed in
>>> t5552-skipping-fetch-negotiator.sh and t5503-tagfollow.sh, where
>>> different processes write to the same trace file simultanously; it also
>>> occurred in t5400-send-pack.sh, but there it was worked around in
>>> 71406ed4d6 ("t5400: avoid concurrent writes into a trace file",
>>> 2017-05-18).
>>>
>>> Fortunately, Windows does support atomic O_APPEND semantics using the
>>> file access mode FILE_APPEND_DATA. Provide an implementation that does.
>>>
>>> This implementation is minimal in such a way that it only implements
>>> the open modes that are actually used in the Git code base. Emulation
>>> for other modes can be added as necessary later. To become aware of
>>> the necessity early, the unusal error ENOSYS is reported if an
>>> unsupported mode is encountered.
>>>
>>> Diagnosed-by: Johannes Schindelin <Johannes.Schindelin@gmx.de>
>>> Helped-by: Jeff Hostetler <git@jeffhostetler.com>
>>> Signed-off-by: Johannes Sixt <j6t@kdbg.org>
>>> ---
>>>   compat/mingw.c | 41 +++++++++++++++++++++++++++++++++++++++--
>>>   1 file changed, 39 insertions(+), 2 deletions(-)
>>
>> Nice.
>>
>> I wonder how much more expensive using this implementation is
>> compared with the original "race susceptible" open(), when raciness
>> is known not to be an issue (e.g. there is higher level lock that
>> protects the appending).
>
> Certainly, the former way that uses two syscalls
> (SetFilePointer+WriteFile) is more costly than this new way with just
> one syscall (WriteFile). Of course, I don't know how atomic append
> would be implemented in the kernel, but I can't think of a reason why
> it should be slow on Windows, but fast on POSIX.
>
> (But I can't provide numbers to back up my gut feeling...)
>
> (And I also assume that you are not worried about the performance of
> open() itself.)
>
>> ...[define race_safe_append_open]... and replace
>> the call to open(... O_APPEND ...) in trace.c::get_trace_fd() with a
>> call to that wrapper.  That way, other codepaths that use O_APPEND
>> (namely, reflog and todo-list writers) can avoid the additional
>> cost, if any.
>>
>> Some may find it beneficial from code readability POV because that
>> approach marks the codepath that needs to have non-racy fd more
>> explicitly.
>
> O_APPEND is POSIX and means race-free append. If you mark some call
> sites with O_APPEND, then that must be the ones that need race-free
> append. Hence, you would have to go the other route: Mark those call
> sites that do _not_ need race-free append with some custom
> function/macro. (Or mark both with different helpers and avoid writing
> down O_APPEND.)

O_APPEND in POSIX is race-free only up to PIPE_MAX bytes written at a
time, which is e.g. 2^12 by default on linux, after that all bets are
off and the kernel is free to interleave different write calls.

I've written code (not for git.git) that implements such a
"write_non_racy" function in the past, and the first thing it needs to
do is to assert that the length of the buffer being written doesn't
exceed PIPE_MAX.

So there's still a use for a race_safe_append_open() wrapper function,
to O_APPEND and do the PIPE_MAX assertion. Otherwise you're calling a
"safe" function which isn't safe at all anymore.

I have no idea what the equivalent of that PIPE_MAX caveat is on
non-POSIX (e.g. Windows), but would be interested to find out.

Re: [PATCH] mingw: enable atomic O_APPEND

[Junio C Hamano]

Ævar Arnfjörð Bjarmason <avarab@gmail.com> writes:

> O_APPEND in POSIX is race-free only up to PIPE_MAX bytes written at a
> time, which is e.g. 2^12 by default on linux, after that all bets are
> off and the kernel is free to interleave different write calls.

We are only interested in the use of race-safe append in the
tracing, so we should be OK in practice.  but then ...

> So there's still a use for a race_safe_append_open() wrapper function,
> to O_APPEND and do the PIPE_MAX assertion. Otherwise you're calling a
> "safe" function which isn't safe at all anymore.

... having an assert that would never trigger is not all that bad
;-)

Re: [PATCH] mingw: enable atomic O_APPEND

[Jeff King]

On Mon, Aug 13, 2018 at 11:22:10PM +0200, Ævar Arnfjörð Bjarmason wrote:

> > O_APPEND is POSIX and means race-free append. If you mark some call
> > sites with O_APPEND, then that must be the ones that need race-free
> > append. Hence, you would have to go the other route: Mark those call
> > sites that do _not_ need race-free append with some custom
> > function/macro. (Or mark both with different helpers and avoid writing
> > down O_APPEND.)
> 
> O_APPEND in POSIX is race-free only up to PIPE_MAX bytes written at a
> time, which is e.g. 2^12 by default on linux, after that all bets are
> off and the kernel is free to interleave different write calls.

This is a claim I've run across often, but I've never seen a good
citation for it.

Certainly atomic writes to _pipes_ are determined by PIPE_BUF (which
IIRC is not even a constant on Linux, but can be changed at run-time).
But is it relevant for regular-file writes?

Another gem I found while digging on this O_APPEND/FILE_APPEND_DATA
stuff the other day: somebody claimed that the max atomic-append size on
Linux is 4096 and 1024 on Windows. But their experimental script was
done in bash! So I suspect they were really just measuring the size of
stdio buffers.

Here's my attempt at a test setup. This C program forces two processes
to write simultaneously to the same file with O_APPEND:

-- >8 --
#include <stdlib.h>
#include <string.h>
#include <stdio.h>
#include <sys/types.h>
#include <fcntl.h>
#include <unistd.h>

static void doit(int size, const char *fn, char c)
{
	int fd;
	char *buf;

	fd = open(fn, O_WRONLY|O_APPEND|O_CREAT, 0666);
	if (fd < 0) {
		perror("open");
		return;
	}

	buf = malloc(size);
	memset(buf, c, size);

	while (1)
		write(fd, buf, size);
}

int main(int argc, const char **argv)
{
	int size = atoi(argv[1]);

	if (fork())
		doit(size, argv[2], '1');
	else
		doit(size, argv[2], '2');
	return 0;
}
-- 8< --

and then this program checks that we saw atomic units of the correct
size:

-- >8 --
#include <stdlib.h>
#include <stdio.h>
#include <unistd.h>

int main(int argc, const char **argv)
{
	int size = atoi(argv[1]);
	char *buf;

	buf = malloc(size);
	while (1) {
		int i;
		/* assume atomic reads, i.e., no signals */
		int r = read(0, buf, size);
		if (!r)
			break;
		for (i = 1; i < size; i++) {
			if (buf[i] != buf[0]) {
				fprintf(stderr, "overlap\n");
				return 1;
			}
		}
	}
	return 0;
}
-- 8< --

And then you can do something like:

  for size in 4097 8193 16385 32769 65537 131073 262145 524289 1048577; do
    >out ;# clean up from last run
    echo "Trying $size..."
    timeout 5 ./write $size out
    if ! ./check $size <out; then
      echo "$size failed"
      break
    fi
  done

On my Linux system, each of those seems to write several gigabytes
without overlapping. I did manage to hit some failing cases, but they
were never sheared writes, but rather cases where there was an
incomplete write at the end-of-file.

So obviously this is all a bit of a tangent. I'd be fine declaring that
trace output is generally small enough not to worry about this in the
first place. But those results show that it shouldn't matter even if
we're writing 1MB trace lines on Linux. I wouldn't be at all surprised
to see different results on other operating systems, though.

-Peff

Re: [PATCH] mingw: enable atomic O_APPEND

[Ævar Arnfjörð Bjarmason]

On Mon, Aug 13 2018, Jeff King wrote:

> On Mon, Aug 13, 2018 at 11:22:10PM +0200, Ævar Arnfjörð Bjarmason wrote:
>
>> > O_APPEND is POSIX and means race-free append. If you mark some call
>> > sites with O_APPEND, then that must be the ones that need race-free
>> > append. Hence, you would have to go the other route: Mark those call
>> > sites that do _not_ need race-free append with some custom
>> > function/macro. (Or mark both with different helpers and avoid writing
>> > down O_APPEND.)
>>
>> O_APPEND in POSIX is race-free only up to PIPE_MAX bytes written at a
>> time, which is e.g. 2^12 by default on linux, after that all bets are
>> off and the kernel is free to interleave different write calls.

[I should have said PIPE_BUF, not PIPE_MAX]

> This is a claim I've run across often, but I've never seen a good
> citation for it.

To clarify I'm claiming that this is not a guarantee POSIX or linux
support. Not that in practice it doesn't work on some systems.

The relevant POSIX docs are here:
http://pubs.opengroup.org/onlinepubs/9699919799/functions/write.html

    Write requests of {PIPE_BUF} bytes or less shall not be interleaved
    with data from other processes doing writes on the same pipe. Writes
    of greater than {PIPE_BUF} bytes may have data interleaved, on
    arbitrary boundaries, with writes by other processes, whether or not
    the O_NONBLOCK flag of the file status flags is set.

And the Linux docs at http://man7.org/linux/man-pages/man7/pipe.7.html
say something similar:

    Writes of more than PIPE_BUF bytes may be nonatomic: the kernel may
    interleave the data with data written by other processes.  POSIX.1
    requires PIPE_BUF to be at least 512 bytes.  (On Linux, PIPE_BUF is
    4096 bytes.)

> Certainly atomic writes to _pipes_ are determined by PIPE_BUF (which
> IIRC is not even a constant on Linux, but can be changed at run-time).
> But is it relevant for regular-file writes?

I believe it's hardcoded at PIPE_BUF which is defined as PAGE_SIZE on
linux. I think you may be thinking of /proc/sys/fs/pipe-max-pages which
is the number of pages that a pipe will take before filling up, but I
may be wrong.

> Another gem I found while digging on this O_APPEND/FILE_APPEND_DATA
> stuff the other day: somebody claimed that the max atomic-append size on
> Linux is 4096 and 1024 on Windows. But their experimental script was
> done in bash! So I suspect they were really just measuring the size of
> stdio buffers.

Yes, and some tests for this are wrong because they use e.g. "print" in
some higher-level language which'll always split stuff into writes of
1024 or something.

> Here's my attempt at a test setup. This C program forces two processes
> to write simultaneously to the same file with O_APPEND:
>
> -- >8 --
> #include <stdlib.h>
> #include <string.h>
> #include <stdio.h>
> #include <sys/types.h>
> #include <fcntl.h>
> #include <unistd.h>
>
> static void doit(int size, const char *fn, char c)
> {
> 	int fd;
> 	char *buf;
>
> 	fd = open(fn, O_WRONLY|O_APPEND|O_CREAT, 0666);
> 	if (fd < 0) {
> 		perror("open");
> 		return;
> 	}
>
> 	buf = malloc(size);
> 	memset(buf, c, size);
>
> 	while (1)
> 		write(fd, buf, size);
> }
>
> int main(int argc, const char **argv)
> {
> 	int size = atoi(argv[1]);
>
> 	if (fork())
> 		doit(size, argv[2], '1');
> 	else
> 		doit(size, argv[2], '2');
> 	return 0;
> }
> -- 8< --
>
> and then this program checks that we saw atomic units of the correct
> size:
>
> -- >8 --
> #include <stdlib.h>
> #include <stdio.h>
> #include <unistd.h>
>
> int main(int argc, const char **argv)
> {
> 	int size = atoi(argv[1]);
> 	char *buf;
>
> 	buf = malloc(size);
> 	while (1) {
> 		int i;
> 		/* assume atomic reads, i.e., no signals */
> 		int r = read(0, buf, size);
> 		if (!r)
> 			break;
> 		for (i = 1; i < size; i++) {
> 			if (buf[i] != buf[0]) {
> 				fprintf(stderr, "overlap\n");
> 				return 1;
> 			}
> 		}
> 	}
> 	return 0;
> }
> -- 8< --
>
> And then you can do something like:
>
>   for size in 4097 8193 16385 32769 65537 131073 262145 524289 1048577; do
>     >out ;# clean up from last run
>     echo "Trying $size..."
>     timeout 5 ./write $size out
>     if ! ./check $size <out; then
>       echo "$size failed"
>       break
>     fi
>   done
>
> On my Linux system, each of those seems to write several gigabytes
> without overlapping. I did manage to hit some failing cases, but they
> were never sheared writes, but rather cases where there was an
> incomplete write at the end-of-file.

Yeah I can't make that fail experimentally either, except in the case
you mentioned. I also checked on a NetBSD & OpenBSD and OpenBSD box I
have access to, same thing.

> So obviously this is all a bit of a tangent. I'd be fine declaring that
> trace output is generally small enough not to worry about this in the
> first place. But those results show that it shouldn't matter even if
> we're writing 1MB trace lines on Linux. I wouldn't be at all surprised
> to see different results on other operating systems, though.

I don't know how this works internally in the kernel, but I'd be very
careful to make that assertion. Most likely this in practice depends on
what FS you're using, its mount options, whether fsync() is involved,
I/O pressure etc.

FWIW this is something I've ran into in the past on Linux as a practical
matter, but that was many kernel versions ago, so maybe the semantics
changed.

We had an ad-hoc file format with each chunk a "<start
marker><length><content><end marker>\n" format (and the <content> was
guaranteed not to contain "\n"). These would be written to the same file
by N workers. We would get corrupt data because of this in cases where
we were writing more than PIPE_BUF, e.g. start markers for unrelated
payloads interleaved with content, lines that were incorrectly formed
etc.

But yeah, whether this is a practical concern for git trace output is
another matter. I just wanted to chime in to note that atomic appends to
files are only portable on POSIX up to PIPE_BUF.

Re: [PATCH] mingw: enable atomic O_APPEND

[Jeff King]

On Tue, Aug 14, 2018 at 03:47:54PM +0200, Ævar Arnfjörð Bjarmason wrote:

> The relevant POSIX docs are here:
> http://pubs.opengroup.org/onlinepubs/9699919799/functions/write.html
> 
>     Write requests of {PIPE_BUF} bytes or less shall not be interleaved
>     with data from other processes doing writes on the same pipe. Writes
>     of greater than {PIPE_BUF} bytes may have data interleaved, on
>     arbitrary boundaries, with writes by other processes, whether or not
>     the O_NONBLOCK flag of the file status flags is set.

Right, this is the part I've seen, but it's pretty clearly only about
pipes, not regular files.

> > Certainly atomic writes to _pipes_ are determined by PIPE_BUF (which
> > IIRC is not even a constant on Linux, but can be changed at run-time).
> > But is it relevant for regular-file writes?
> 
> I believe it's hardcoded at PIPE_BUF which is defined as PAGE_SIZE on
> linux. I think you may be thinking of /proc/sys/fs/pipe-max-pages which
> is the number of pages that a pipe will take before filling up, but I
> may be wrong.

Yeah, you're probably right.

> > So obviously this is all a bit of a tangent. I'd be fine declaring that
> > trace output is generally small enough not to worry about this in the
> > first place. But those results show that it shouldn't matter even if
> > we're writing 1MB trace lines on Linux. I wouldn't be at all surprised
> > to see different results on other operating systems, though.
> 
> I don't know how this works internally in the kernel, but I'd be very
> careful to make that assertion. Most likely this in practice depends on
> what FS you're using, its mount options, whether fsync() is involved,
> I/O pressure etc.

Definitely it depends on the filesystem (and I'm pretty sure that at
least old versions of NFS could not possibly do O_APPEND correctly,
because the protocol did not support an atomic seek+write).

I agree that the experiment I did doesn't really tell us anything for
sure. It _seems_ to work, but the machine was not under any kind of
memory or I/O pressure.

I'd feel pretty confident that writes under a page are always going to
be fine, but anything else is "seems to work". To me that's enough for
tracing, as the absolute worst case is jumbled output, not an on-disk
corruption.

> FWIW this is something I've ran into in the past on Linux as a practical
> matter, but that was many kernel versions ago, so maybe the semantics
> changed.
> 
> We had an ad-hoc file format with each chunk a "<start
> marker><length><content><end marker>\n" format (and the <content> was
> guaranteed not to contain "\n"). These would be written to the same file
> by N workers. We would get corrupt data because of this in cases where
> we were writing more than PIPE_BUF, e.g. start markers for unrelated
> payloads interleaved with content, lines that were incorrectly formed
> etc.

Interesting. I wonder if it is because of PIPE_BUF, or it is simply the
page size, which also happens to be the value of PIPE_BUF.

> But yeah, whether this is a practical concern for git trace output is
> another matter. I just wanted to chime in to note that atomic appends to
> files are only portable on POSIX up to PIPE_BUF.

I still think POSIX doesn't say anything either way here. The PIPE_BUF
bits are _just_ about pipes. At any rate, I think we have a decent
handle on what systems actually _do_, which is more important than POSIX
anyway.

-Peff

Re: [PATCH] mingw: enable atomic O_APPEND

[Johannes Sixt]

Am 14.08.2018 um 00:37 schrieb Jeff King:
> And then you can do something like:
> 
>    for size in 4097 8193 16385 32769 65537 131073 262145 524289 1048577; do
>      >out ;# clean up from last run
>      echo "Trying $size..."
>      timeout 5 ./write $size out
>      if ! ./check $size <out; then
>        echo "$size failed"
>        break
>      fi
>    done
> 
> On my Linux system, each of those seems to write several gigabytes
> without overlapping. I did manage to hit some failing cases, but they
> were never sheared writes, but rather cases where there was an
> incomplete write at the end-of-file.

I used your programs with necessary adjustments (as fork() is not 
available), and did similar tests with concurrent processes. With packet 
sizes 1025, 4093, 7531 (just to include some odd number), and 8193 I did 
not observe any overlapping or short writes.

I'm now very confident that we are on the safe side for our purposes.

-- Hannes

Re: [PATCH] mingw: enable atomic O_APPEND

[Jeff King]

On Tue, Aug 14, 2018 at 08:29:04PM +0200, Johannes Sixt wrote:

> Am 14.08.2018 um 00:37 schrieb Jeff King:
> > And then you can do something like:
> > 
> >    for size in 4097 8193 16385 32769 65537 131073 262145 524289 1048577; do
> >      >out ;# clean up from last run
> >      echo "Trying $size..."
> >      timeout 5 ./write $size out
> >      if ! ./check $size <out; then
> >        echo "$size failed"
> >        break
> >      fi
> >    done
> > 
> > On my Linux system, each of those seems to write several gigabytes
> > without overlapping. I did manage to hit some failing cases, but they
> > were never sheared writes, but rather cases where there was an
> > incomplete write at the end-of-file.
> 
> I used your programs with necessary adjustments (as fork() is not
> available), and did similar tests with concurrent processes. With packet
> sizes 1025, 4093, 7531 (just to include some odd number), and 8193 I did not
> observe any overlapping or short writes.
> 
> I'm now very confident that we are on the safe side for our purposes.

Great, thanks for testing!

Re-reading what I wrote about end-of-file above and thinking about the
conversation with Ævar elsewhere in the thread, I suspect it _is_ easy
to get overlapping writes if the processes are receiving signals (since
clearly the TERM signal caused a partial write).

My experiment doesn't simulate that at all. I suppose the parent process
could send SIGUSR1 to the child in each loop, and the child would catch
it but keep going.

Hmm, that was easy enough to do (programs below for reference), but
surprisingly it didn't fail for me (except for the normal end-of-file
truncation). It's like the OS is willing to truncate the write of a
dying program but not one for a signal that is getting handled. Which is
great for us, since it's exactly what we want, but makes me even more
suspicious that a non-Linux kernel might behave completely differently.

I still think we're fine in practice, as I'd expect any kernel to be
atomic under the page size. So this was mostly just for my own
edification.

-Peff

-- >8 --
/* check.c, with separate short-read reporting */
#include <stdlib.h>
#include <stdio.h>
#include <unistd.h>

int main(int argc, const char **argv)
{
	int size = atoi(argv[1]);
	int block = 0;
	char *buf;

	buf = malloc(size);
	while (1) {
		int i;
		/* assume atomic reads */
		int r = read(0, buf, size);
		if (!r)
			break;
		if (r < size) {
			fprintf(stderr, "short read\n");
			return 1;
		}
		for (i = 1; i < size; i++) {
			if (buf[i] != buf[0]) {
				fprintf(stderr, "overlap in block %d\n", block);
				return 1;
			}
		}
		block++;
	}
}
-- >8 --

-- >8 --
/* write.c with signals; you can also confirm via strace
   that each write is atomic */
#include <stdlib.h>
#include <string.h>
#include <stdio.h>
#include <sys/types.h>
#include <fcntl.h>
#include <unistd.h>
#include <signal.h>

void handle_signal(int sig)
{
	/* do nothing */
}

static void doit(int size, const char *fn, char c, pid_t pid)
{
	int fd;
	char *buf;

	fd = open(fn, O_WRONLY|O_APPEND|O_CREAT, 0666);
	if (fd < 0) {
		perror("open");
		return;
	}

	buf = malloc(size);
	memset(buf, c, size);

	while (1) {
		if (pid)
			kill(pid, SIGUSR1);
		write(fd, buf, size);
	}
}

int main(int argc, const char **argv)
{
	int size = atoi(argv[1]);
	pid_t pid;

	signal(SIGUSR1, handle_signal);

	pid = fork();
	if (pid)
		doit(size, argv[2], '1', pid);
	else
		doit(size, argv[2], '2', pid);
	return 0;
}
-- >8 --

Re: [PATCH] mingw: enable atomic O_APPEND

[Jeff Hostetler]

On 8/13/2018 3:02 PM, Johannes Sixt wrote:
> The Windows CRT implements O_APPEND "manually": on write() calls, the
> file pointer is set to EOF before the data is written. Clearly, this is
> not atomic. And in fact, this is the root cause of failures observed in
> t5552-skipping-fetch-negotiator.sh and t5503-tagfollow.sh, where
> different processes write to the same trace file simultanously; it also
> occurred in t5400-send-pack.sh, but there it was worked around in
> 71406ed4d6 ("t5400: avoid concurrent writes into a trace file",
> 2017-05-18).
> 
> Fortunately, Windows does support atomic O_APPEND semantics using the
> file access mode FILE_APPEND_DATA. Provide an implementation that does.
> 
> This implementation is minimal in such a way that it only implements
> the open modes that are actually used in the Git code base. Emulation
> for other modes can be added as necessary later. To become aware of
> the necessity early, the unusal error ENOSYS is reported if an
> unsupported mode is encountered.
> 
> Diagnosed-by: Johannes Schindelin <Johannes.Schindelin@gmx.de>
> Helped-by: Jeff Hostetler <git@jeffhostetler.com>
> Signed-off-by: Johannes Sixt <j6t@kdbg.org>
> ---
>   compat/mingw.c | 41 +++++++++++++++++++++++++++++++++++++++--
>   1 file changed, 39 insertions(+), 2 deletions(-)
> 

[...]

This looks good.  Thanks for following up on this.

Jeff

Re: [PATCH] mingw: enable atomic O_APPEND

[Junio C Hamano]

Jeff Hostetler <git@jeffhostetler.com> writes:

> On 8/13/2018 3:02 PM, Johannes Sixt wrote:
>>
>> Fortunately, Windows does support atomic O_APPEND semantics using the
>> file access mode FILE_APPEND_DATA. Provide an implementation that does.
>> ...
>>
>> Diagnosed-by: Johannes Schindelin <Johannes.Schindelin@gmx.de>
>> Helped-by: Jeff Hostetler <git@jeffhostetler.com>
>> Signed-off-by: Johannes Sixt <j6t@kdbg.org>
>> ---
>
> This looks good.  Thanks for following up on this.

Thanks, all.  Will queue.

[PATCH v2 0/4] t5552: fix flakiness by introducing proper locking for GIT_TRACE

[Johannes Schindelin via GitGitGadget]

I reported a couple of times that t5552 is not passing reliably. It has now
reached next, and will no doubt infect master soon.

Turns out that it is not a Windows-specific issue, even if it occurs a lot 
more often on Windows than elsewhere. (And even if it is apparently
impossible to trigger on Linux.)

The culprit is that two processes try to write simultaneously to the same
file specified via GIT_TRACE_PACKET, and it is not well defined how that
should work, even when only looking at the POSIX specification (the
documentation of write()
[http://pubs.opengroup.org/onlinepubs/9699919799/functions/write.html] says
"Applications should use some form of concurrency control.").

This patch series addresses that by locking the trace fd. I chose to use 
fcntl() for the Unix(-y) platforms we support instead of flock() (even if
the latter has much simpler semantics) because fcntl() is in POSIX while 
flock() is not. On Windows, I use the Win32 API function LockFileEx()
[https://docs.microsoft.com/en-us/windows/desktop/api/fileapi/nf-fileapi-lockfileex]
.

Of course, I have to admit that I am not super solid on the fcntl() 
semantics. Junio was nice enough to educate me on l_len = 0 meaning the
entire file. If anybody has more experience with locking file descriptors
referring not to files, but, say, to pipes or to an interactive terminal, I
would be very thankful for help (while the POSIX documentation states that
the errno should be EINVAL on a file descriptor that cannot be locked,
apparently macOS sets errno to EBADF when trying to lock a redirected stdout
)?

Changes since v1:

 * Touched up the cover letter and the first commit message (in particular,
   removed the bogus squash! line giving away just how much I rely on the 
   --autosquash feature these days).
 * Now we're locking the entire file via l_len = 0 (except on Windows).
 * To cover all bases, EINVAL is now also treated as "cannot lock this fd"
   (in addition to EBADF).
 * Removed some superfluous flock()-related left-overs from a previous
   attempt (that caused a lot of me fighting with Linux).

Johannes Schindelin (4):
  Introduce a function to lock/unlock file descriptors when appending
  mingw: implement lock_or_unlock_fd_for_appending()
  trace: lock the trace file to avoid racy trace_write() calls
  trace: verify that locking works

 Makefile               |   1 +
 compat/mingw.c         |  19 ++++++
 compat/mingw.h         |   3 +
 git-compat-util.h      |   2 +
 t/helper/test-tool.c   |   1 +
 t/helper/test-tool.h   |   1 +
 t/helper/test-trace.c  | 130 +++++++++++++++++++++++++++++++++++++++++
 t/t0070-fundamental.sh |   6 ++
 trace.c                |  11 +++-
 wrapper.c              |  16 +++++
 10 files changed, 189 insertions(+), 1 deletion(-)
 create mode 100644 t/helper/test-trace.c


base-commit: 42cc7485a2ec49ecc440c921d2eb0cae4da80549
Published-As: https://github.com/gitgitgadget/git/releases/tags/pr-17%2Fdscho%2Ffetch-negotiator-skipping-v2
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-17/dscho/fetch-negotiator-skipping-v2
Pull-Request: https://github.com/gitgitgadget/git/pull/17

Range-diff vs v1:

 1:  e449ed75f ! 1:  a19904682 Introduce a function to lock/unlock file descriptors when appending
     @@ -30,7 +30,7 @@
          added in this commit.
      
          But fcntl() allows a lot more versatile file region locking that we
     -    actually need, to by necessity the fcntl() emulation would be quite
     +    actually need, so by necessity the fcntl() emulation would be quite
          complex: To support the `l_whence = SEEK_CUR` (which we would use, if it
          did not require so much book-keeping due to our writing between locking
          and unlocking the file), we would have to call `SetFilePointerEx()`
     @@ -47,18 +47,16 @@
          to do, as we would once again fail to have an abstraction that clearly
          says what *exact*functionality we want to use.
      
     -    To set a precedent for a better approach, let's introduce a proper
     -    abstraction: a function that says in its name precisely what Git
     -    wants it to do (as opposed to *how* it does it on Linux):
     -    lock_or_unlock_fd_for_appending().
     +    This commit expressly tries to set a precedent for a better approach:
     +    Let's introduce a proper abstraction: a function that says in its name
     +    precisely what Git wants it to do (as opposed to *how* it does it on
     +    Linux): lock_or_unlock_fd_for_appending().
      
          The next commit will provide a Windows-specific implementation of this
          function/functionality.
      
          Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
      
     -    squash! Introduce a function to lock/unlock file descriptors when appending
     -
      diff --git a/git-compat-util.h b/git-compat-util.h
      --- a/git-compat-util.h
      +++ b/git-compat-util.h
     @@ -86,9 +84,11 @@
      +	struct flock flock;
      +
      +	flock.l_type = lock_it ? F_WRLCK : F_UNLCK;
     ++
     ++	/* (un-)lock the whole file */
      +	flock.l_whence = SEEK_SET;
      +	flock.l_start = 0;
     -+	flock.l_len = 0xffffffff; /* arbitrary number of bytes */
     ++	flock.l_len = 0;
      +
      +	return fcntl(fd, F_SETLKW, &flock);
      +}
 2:  8dda2d530 ! 2:  fa0c282aa mingw: implement lock_or_unlock_fd_for_appending()
     @@ -54,24 +54,3 @@
       #define has_dos_drive_prefix(path) \
       	(isalpha(*(path)) && (path)[1] == ':' ? 2 : 0)
       int mingw_skip_dos_drive_prefix(char **path);
     -
     -diff --git a/config.mak.uname b/config.mak.uname
     ---- a/config.mak.uname
     -+++ b/config.mak.uname
     -@@
     - 	NO_POSIX_GOODIES = UnfortunatelyYes
     - 	NATIVE_CRLF = YesPlease
     - 	DEFAULT_HELP_FORMAT = html
     -+	HAVE_FLOCK = YesWeEmulate
     - 
     - 	CC = compat/vcbuild/scripts/clink.pl
     - 	AR = compat/vcbuild/scripts/lib.pl
     -@@
     - 	NO_INET_NTOP = YesPlease
     - 	NO_POSIX_GOODIES = UnfortunatelyYes
     - 	DEFAULT_HELP_FORMAT = html
     -+	HAVE_FLOCK = YesWeEmulate
     -+
     - 	COMPAT_CFLAGS += -DNOGDI -Icompat -Icompat/win32
     - 	COMPAT_CFLAGS += -DSTRIP_EXTENSION=\".exe\"
     - 	COMPAT_OBJS += compat/mingw.o compat/winansi.o \
 3:  a53e72198 ! 3:  1f5c15c7e trace: lock the trace file to avoid racy trace_write() calls
     @@ -14,6 +14,17 @@
          To remedy this, let's lock the file descriptors for exclusive writing,
          using the function we just introduced in the previous commit.
      
     +    Note: while the POSIX documentation of fcntl() at
     +    http://pubs.opengroup.org/onlinepubs/9699919799/functions/fcntl.html
     +    suggests that the `errno` is set to `EINVAL` when being asked to
     +    lock a file descriptor that cannot be locked, on macOS it results in
     +    `EBADF` when trying to lock a redirected `stdout` (which the
     +    documentation claims should indicate that the file descriptor is not
     +    valid for writing).
     +
     +    To cover all our bases, we simply treat both `EINVAL` and `EBADF` as
     +    indicators that we cannot lock/unlock this file descriptor.
     +
          Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
      
      diff --git a/trace.c b/trace.c
     @@ -27,7 +38,7 @@
      +	int fd = get_trace_fd(key), locked;
      +
      +	locked = !lock_or_unlock_fd_for_appending(fd, 1);
     -+	if (!locked && errno != EBADF)
     ++	if (!locked && errno != EBADF && errno != EINVAL)
      +		warning("unable to lock file descriptor for %s: %s",
      +			key->key, strerror(errno));
      +	if (write_in_full(fd, buf, len) < 0) {
 4:  f57234154 ! 4:  38358ac74 trace: verify that locking works
     @@ -131,13 +131,13 @@
      +		strbuf_rtrim(&buf);
      +		if (!strcmp("lock", buf.buf)) {
      +			if (lock_or_unlock_fd_for_appending(fd, 1) < 0 &&
     -+			    errno != EBADF)
     ++			    errno != EBADF && errno != EINVAL)
      +				die_errno("'%s': lock", child_name);
      +			ACK("lock");
      +			locked = 1;
      +		} else if (!strcmp("unlock", buf.buf)) {
      +			if (lock_or_unlock_fd_for_appending(fd, 0) < 0 &&
     -+			    errno != EBADF)
     ++			    errno != EBADF && errno != EINVAL)
      +				die_errno("'%s': unlock", child_name);
      +			ACK("unlock");
      +			locked = 0;

-- 
gitgitgadget

[PATCH v2 1/4] Introduce a function to lock/unlock file descriptors when appending

[Johannes Schindelin via GitGitGadget]

From: Johannes Schindelin <johannes.schindelin@gmx.de>

This function will be used to make write accesses in trace_write() a bit
safer.

Note: this patch takes a very different approach for cross-platform
support than Git is historically taking: the original approach is to
first implement everything on Linux, using the functions available on
Linux, and then trying to emulate these functions on platforms that do
not have those functions such as Windows.

This leads to all kinds of undesirable quirks in Git's source code (and
performance characteristics) because of the lack of a proper abstraction
layer: instead of declaring functions for the functionality we
*actually* need, we abuse POSIX functions to say what we need, even if
those functions serve much broader purposes (and do not make at all
clear what the caller wants of them).

For example, when Git wants to determine whether a path refers to a
symbolic link, it calls lstat(). That POSIX function has to be emulated
on Windows, painstakingly filling all the information lstat() would,
only for the caller to throw away everything except that one bit of
information, and all of the time figuring out the mtime/atime/ctime and
file size and whatnot was spent in vain.

If we were to follow that approach, we would extend the fcntl()
emulation in compat/mingw.c after this commit, to support the function
added in this commit.

But fcntl() allows a lot more versatile file region locking that we
actually need, so by necessity the fcntl() emulation would be quite
complex: To support the `l_whence = SEEK_CUR` (which we would use, if it
did not require so much book-keeping due to our writing between locking
and unlocking the file), we would have to call `SetFilePointerEx()`
(after obtaining the `HANDLE` on which all Win32 API functions work
instead of the integer file descriptors used by all POSIX functions).
Multiplying the number of Win32 API round-trips. Of course, we could
implement an incomplete emulation of fcntl()'s F_WRLCK, but that would
be unsatisfying.

An alternative approach would be to use the `flock()` function, whose
semantics are much closer to existing Win32 API. But `flock()` is not
even a POSIX standard, so we would have to implement emulation of
`flock()` for *other* platforms. And it would again be the wrong thing
to do, as we would once again fail to have an abstraction that clearly
says what *exact*functionality we want to use.

This commit expressly tries to set a precedent for a better approach:
Let's introduce a proper abstraction: a function that says in its name
precisely what Git wants it to do (as opposed to *how* it does it on
Linux): lock_or_unlock_fd_for_appending().

The next commit will provide a Windows-specific implementation of this
function/functionality.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 git-compat-util.h |  2 ++
 wrapper.c         | 16 ++++++++++++++++
 2 files changed, 18 insertions(+)

diff --git a/git-compat-util.h b/git-compat-util.h
index 9a64998b2..13b83bade 100644
--- a/git-compat-util.h
+++ b/git-compat-util.h
@@ -1202,6 +1202,8 @@ struct tm *git_gmtime_r(const time_t *, struct tm *);
 #define getc_unlocked(fh) getc(fh)
 #endif
 
+extern int lock_or_unlock_fd_for_appending(int fd, int lock_it);
+
 /*
  * Our code often opens a path to an optional file, to work on its
  * contents when we can successfully open it.  We can ignore a failure
diff --git a/wrapper.c b/wrapper.c
index e4fa9d84c..5aecbda34 100644
--- a/wrapper.c
+++ b/wrapper.c
@@ -690,3 +690,19 @@ int xgethostname(char *buf, size_t len)
 		buf[len - 1] = 0;
 	return ret;
 }
+
+#ifndef GIT_WINDOWS_NATIVE
+int lock_or_unlock_fd_for_appending(int fd, int lock_it)
+{
+	struct flock flock;
+
+	flock.l_type = lock_it ? F_WRLCK : F_UNLCK;
+
+	/* (un-)lock the whole file */
+	flock.l_whence = SEEK_SET;
+	flock.l_start = 0;
+	flock.l_len = 0;
+
+	return fcntl(fd, F_SETLKW, &flock);
+}
+#endif
-- 
gitgitgadget

Re: [PATCH v2 1/4] Introduce a function to lock/unlock file descriptors when appending

[Junio C Hamano]

"Johannes Schindelin via GitGitGadget" <gitgitgadget@gmail.com>
writes:

> +
> +#ifndef GIT_WINDOWS_NATIVE
> +int lock_or_unlock_fd_for_appending(int fd, int lock_it)
> +{
> +	struct flock flock;
> +
> +	flock.l_type = lock_it ? F_WRLCK : F_UNLCK;
> +
> +	/* (un-)lock the whole file */
> +	flock.l_whence = SEEK_SET;
> +	flock.l_start = 0;
> +	flock.l_len = 0;
> +
> +	return fcntl(fd, F_SETLKW, &flock);
> +}
> +#endif

I think people already told you that this is not needed on systems
with properly working O_APPEND [*1*]

	Side note #1: and with network filesystems where O_APPEND
        may not work reliably, fcntl based range locking would not
        work either, so having this would not help.

I saw other Johannes and other Jeff peeking into fixing O_APPEND;
I do not know how well that effort goes, but it would be preferrable
if we can successfully go that route.  

As I said in my review of the first patch in v1 series, I am not
fundamentally opposed to a few "lock here to work around lack of
O_APPEND" and "unlock here for the same reason" calls to limited
codepaths as a workaround, as the damage is limited (that is why I
earlier looked at our use of O_APPEND), but that would be the last
resort if O_APPEND cannot be made to work reliably on Windows.

But even if we end up doing so, on systems with POSIX O_APPEND
working, I think that function should be

    #define lock_or_unlock_for_appending(fd, lock) 0 /* nothing to do */

Re: [PATCH v2 1/4] Introduce a function to lock/unlock file descriptors when appending

[Johannes Schindelin]

Hi Junio,

On Fri, 10 Aug 2018, Junio C Hamano wrote:

> "Johannes Schindelin via GitGitGadget" <gitgitgadget@gmail.com>
> writes:
> 
> > +
> > +#ifndef GIT_WINDOWS_NATIVE
> > +int lock_or_unlock_fd_for_appending(int fd, int lock_it)
> > +{
> > +	struct flock flock;
> > +
> > +	flock.l_type = lock_it ? F_WRLCK : F_UNLCK;
> > +
> > +	/* (un-)lock the whole file */
> > +	flock.l_whence = SEEK_SET;
> > +	flock.l_start = 0;
> > +	flock.l_len = 0;
> > +
> > +	return fcntl(fd, F_SETLKW, &flock);
> > +}
> > +#endif
> 
> I think people already told you that this is not needed on systems
> with properly working O_APPEND [*1*]

I also wanted to safeguard against other (well-behaved) programs writing
to the trace file.

Granted, this is a bit theoretical, but it is quite possible that other
Git implementations do things differently than our trace.c. But with the
file locking that even that POSIX man page I quoted recommends, all this
is not an issue.

And this patch series implements that locking.

> 	Side note #1: and with network filesystems where O_APPEND
>         may not work reliably, fcntl based range locking would not
>         work either, so having this would not help.

At least on Windows, it would help, though.

And if there *is* a way to lock via NFS (which is the only network
filesystem I am aware of that has these locking issues, at least *some*
others are just fine), we would at least already have that function where
to implement it.

> I saw other Johannes and other Jeff peeking into fixing O_APPEND;
> I do not know how well that effort goes, but it would be preferrable
> if we can successfully go that route.  

As I pointed out previously, my mail provider is losing mails left and
right for me. Could I ask for a pointer?

> As I said in my review of the first patch in v1 series, I am not
> fundamentally opposed to a few "lock here to work around lack of
> O_APPEND" and "unlock here for the same reason" calls to limited
> codepaths as a workaround, as the damage is limited (that is why I
> earlier looked at our use of O_APPEND), but that would be the last
> resort if O_APPEND cannot be made to work reliably on Windows.
> 
> But even if we end up doing so, on systems with POSIX O_APPEND
> working, I think that function should be
> 
>     #define lock_or_unlock_for_appending(fd, lock) 0 /* nothing to do */

I think that that would be only appropriate if there were no other Git
implementations.

Ciao,
Dscho

[PATCH v2 2/4] mingw: implement lock_or_unlock_fd_for_appending()

[Johannes Schindelin via GitGitGadget]

From: Johannes Schindelin <johannes.schindelin@gmx.de>

For some reason, t/t5552-skipping-fetch-negotiator.sh fails particularly
often on Windows due to racy tracing where the `git upload-pack` and the
`git fetch` processes compete for the same file.

We just introduced a remedy that uses fcntl(), but Windows does not have
fcntl(). So let's implement an alternative.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 compat/mingw.c | 19 +++++++++++++++++++
 compat/mingw.h |  3 +++
 2 files changed, 22 insertions(+)

diff --git a/compat/mingw.c b/compat/mingw.c
index 6ded1c859..6da9ce861 100644
--- a/compat/mingw.c
+++ b/compat/mingw.c
@@ -514,6 +514,25 @@ int mingw_chmod(const char *filename, int mode)
 	return _wchmod(wfilename, mode);
 }
 
+int mingw_lock_or_unlock_fd_for_appending(int fd, int lock_it)
+{
+	HANDLE handle = (HANDLE)_get_osfhandle(fd);
+	OVERLAPPED overlapped = { 0 };
+	DWORD err;
+
+	if (!lock_it && UnlockFileEx(handle, 0, -1, 0, &overlapped))
+		return 0;
+	if (lock_it &&
+	    LockFileEx(handle, LOCKFILE_EXCLUSIVE_LOCK, 0, -1, 0, &overlapped))
+		return 0;
+
+	err = GetLastError();
+	/* LockFileEx() cannot lock pipes */
+	errno = err == ERROR_INVALID_FUNCTION ?
+		EBADF : err_win_to_posix(GetLastError());
+	return -1;
+}
+
 /*
  * The unit of FILETIME is 100-nanoseconds since January 1, 1601, UTC.
  * Returns the 100-nanoseconds ("hekto nanoseconds") since the epoch.
diff --git a/compat/mingw.h b/compat/mingw.h
index 571019d0b..0f76d89a9 100644
--- a/compat/mingw.h
+++ b/compat/mingw.h
@@ -397,6 +397,9 @@ HANDLE winansi_get_osfhandle(int fd);
  * git specific compatibility
  */
 
+int mingw_lock_or_unlock_fd_for_appending(int fd, int lock_it);
+#define lock_or_unlock_fd_for_appending mingw_lock_or_unlock_fd_for_appending
+
 #define has_dos_drive_prefix(path) \
 	(isalpha(*(path)) && (path)[1] == ':' ? 2 : 0)
 int mingw_skip_dos_drive_prefix(char **path);
-- 
gitgitgadget

[PATCH v2 3/4] trace: lock the trace file to avoid racy trace_write() calls

[Johannes Schindelin via GitGitGadget]

From: Johannes Schindelin <johannes.schindelin@gmx.de>

When multiple processes try to write to the same file, it is not
guaranteed that everything works as expected: those writes can overlap,
and in the worst case even lose messages.

This happens in t/t5552-skipping-fetch-negotiator.sh, where we abuse the
`GIT_TRACE` facility to write traces of two concurrent processes (`git
fetch` and `git upload-pack`) to the same file, and then verify that the
trace contains certain expected breadcrumbs.

To remedy this, let's lock the file descriptors for exclusive writing,
using the function we just introduced in the previous commit.

Note: while the POSIX documentation of fcntl() at
http://pubs.opengroup.org/onlinepubs/9699919799/functions/fcntl.html
suggests that the `errno` is set to `EINVAL` when being asked to
lock a file descriptor that cannot be locked, on macOS it results in
`EBADF` when trying to lock a redirected `stdout` (which the
documentation claims should indicate that the file descriptor is not
valid for writing).

To cover all our bases, we simply treat both `EINVAL` and `EBADF` as
indicators that we cannot lock/unlock this file descriptor.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 trace.c | 11 ++++++++++-
 1 file changed, 10 insertions(+), 1 deletion(-)

diff --git a/trace.c b/trace.c
index fc623e91f..16abdb816 100644
--- a/trace.c
+++ b/trace.c
@@ -114,11 +114,20 @@ static int prepare_trace_line(const char *file, int line,
 
 static void trace_write(struct trace_key *key, const void *buf, unsigned len)
 {
-	if (write_in_full(get_trace_fd(key), buf, len) < 0) {
+	int fd = get_trace_fd(key), locked;
+
+	locked = !lock_or_unlock_fd_for_appending(fd, 1);
+	if (!locked && errno != EBADF && errno != EINVAL)
+		warning("unable to lock file descriptor for %s: %s",
+			key->key, strerror(errno));
+	if (write_in_full(fd, buf, len) < 0) {
 		warning("unable to write trace for %s: %s",
 			key->key, strerror(errno));
 		trace_disable(key);
 	}
+	if (locked && lock_or_unlock_fd_for_appending(fd, 0) < 0)
+		warning("failed to remove lock on fd for %s: %s",
+			key->key, strerror(errno));
 }
 
 void trace_verbatim(struct trace_key *key, const void *buf, unsigned len)
-- 
gitgitgadget

[PATCH v2 4/4] trace: verify that locking works

[Johannes Schindelin via GitGitGadget]

From: Johannes Schindelin <johannes.schindelin@gmx.de>

Recently, t5552 introduced a pattern where two processes try to write to
the same GIT_TRACE file in parallel. This is not safe, as the two
processes fighting over who gets to append to the file can cause garbled
lines and may even result in data loss on Windows (where buffers are
written to before they are flushed).

To remedy this, we introduced the lock_or_unlock_fd_for_appending()
function. And to make sure that this works, this commit introduces a
regression test.

Signed-off-by: Johannes Schindelin <johannes.schindelin@gmx.de>
---
 Makefile               |   1 +
 t/helper/test-tool.c   |   1 +
 t/helper/test-tool.h   |   1 +
 t/helper/test-trace.c  | 130 +++++++++++++++++++++++++++++++++++++++++
 t/t0070-fundamental.sh |   6 ++
 5 files changed, 139 insertions(+)
 create mode 100644 t/helper/test-trace.c

diff --git a/Makefile b/Makefile
index 617475622..2e3fb5b8d 100644
--- a/Makefile
+++ b/Makefile
@@ -729,6 +729,7 @@ TEST_BUILTINS_OBJS += test-strcmp-offset.o
 TEST_BUILTINS_OBJS += test-string-list.o
 TEST_BUILTINS_OBJS += test-submodule-config.o
 TEST_BUILTINS_OBJS += test-subprocess.o
+TEST_BUILTINS_OBJS += test-trace.o
 TEST_BUILTINS_OBJS += test-urlmatch-normalization.o
 TEST_BUILTINS_OBJS += test-wildmatch.o
 TEST_BUILTINS_OBJS += test-write-cache.o
diff --git a/t/helper/test-tool.c b/t/helper/test-tool.c
index 805a45de9..7adce872b 100644
--- a/t/helper/test-tool.c
+++ b/t/helper/test-tool.c
@@ -39,6 +39,7 @@ static struct test_cmd cmds[] = {
 	{ "string-list", cmd__string_list },
 	{ "submodule-config", cmd__submodule_config },
 	{ "subprocess", cmd__subprocess },
+	{ "trace", cmd__trace },
 	{ "urlmatch-normalization", cmd__urlmatch_normalization },
 	{ "wildmatch", cmd__wildmatch },
 	{ "write-cache", cmd__write_cache },
diff --git a/t/helper/test-tool.h b/t/helper/test-tool.h
index 7116ddfb9..c462ac924 100644
--- a/t/helper/test-tool.h
+++ b/t/helper/test-tool.h
@@ -33,6 +33,7 @@ int cmd__strcmp_offset(int argc, const char **argv);
 int cmd__string_list(int argc, const char **argv);
 int cmd__submodule_config(int argc, const char **argv);
 int cmd__subprocess(int argc, const char **argv);
+int cmd__trace(int argc, const char **argv);
 int cmd__urlmatch_normalization(int argc, const char **argv);
 int cmd__wildmatch(int argc, const char **argv);
 int cmd__write_cache(int argc, const char **argv);
diff --git a/t/helper/test-trace.c b/t/helper/test-trace.c
new file mode 100644
index 000000000..04159c77a
--- /dev/null
+++ b/t/helper/test-trace.c
@@ -0,0 +1,130 @@
+#include "test-tool.h"
+#include "cache.h"
+#include "run-command.h"
+
+static struct child_process children[2] = {
+	CHILD_PROCESS_INIT,
+	CHILD_PROCESS_INIT,
+};
+
+#define SAY(child, what) \
+	if (write_in_full(children[child].in, \
+			  what "\n", strlen(what) + 1) < 0) \
+		die("Failed to tell child process #%d to %s", child, what)
+
+#define LISTEN(child, what) \
+	if (strbuf_getwholeline_fd(&buf, children[child].out, '\n') < 0) \
+		die("Child process #%d failed to acknowledge %s", child, what)
+
+#define ACK(what) \
+	if (write_in_full(1, what ": ACK\n", strlen(what) + 6) < 0) \
+		die_errno("'%s': %s ACK", child_name, what)
+
+static void contention_orchestrator(const char *argv0)
+{
+	struct strbuf buf = STRBUF_INIT;
+	int i;
+
+	/* Spawn two children and simulate write contention */
+	trace_printf("start");
+
+	for (i = 0; i < 2; i++) {
+		strbuf_reset(&buf);
+		strbuf_addf(&buf, "child #%d", i);
+		argv_array_pushl(&children[i].args,
+					argv0, "trace", "lock", buf.buf, NULL);
+		children[i].in = children[i].out = -1;
+		if (start_command(&children[i]) < 0)
+			die("Could not spawn child process #%d", i);
+	}
+
+	SAY(1, "lock");
+	LISTEN(1, "lock");
+
+	SAY(0, "trace delayed");
+	SAY(1, "trace while-locked");
+	LISTEN(1, "trace");
+
+	SAY(1, "unlock");
+	LISTEN(1, "unlock");
+	LISTEN(0, "trace");
+
+	SAY(0, "quit");
+	SAY(1, "quit");
+
+	if (finish_command(&children[0]) < 0 ||
+		finish_command(&children[1]) < 0)
+		die("Child process failed to finish");
+
+	strbuf_release(&buf);
+}
+
+static void child(const char *child_name)
+{
+	struct strbuf buf = STRBUF_INIT;
+	int fd, locked = 0;
+	const char *p;
+
+	/* This is the child process */
+	trace_printf("child start: '%s'", child_name);
+	fd = trace_default_key.fd;
+	if (fd <= 0)
+		die("child process: not tracing...");
+	while (!strbuf_getwholeline_fd(&buf, 0, '\n')) {
+		strbuf_rtrim(&buf);
+		if (!strcmp("lock", buf.buf)) {
+			if (lock_or_unlock_fd_for_appending(fd, 1) < 0 &&
+			    errno != EBADF && errno != EINVAL)
+				die_errno("'%s': lock", child_name);
+			ACK("lock");
+			locked = 1;
+		} else if (!strcmp("unlock", buf.buf)) {
+			if (lock_or_unlock_fd_for_appending(fd, 0) < 0 &&
+			    errno != EBADF && errno != EINVAL)
+				die_errno("'%s': unlock", child_name);
+			ACK("unlock");
+			locked = 0;
+		} else if (skip_prefix(buf.buf, "trace ", &p)) {
+			if (!locked)
+				trace_printf("%s: %s", child_name, p);
+			else {
+				char *p2 = xstrdup(p);
+
+				/* Give the racy process a run for its money. */
+				sleep_millisec(50);
+
+				strbuf_reset(&buf);
+				strbuf_addf(&buf, "%s: %s\n",
+					    child_name, p2);
+				free(p2);
+
+				if (write_in_full(fd, buf.buf, buf.len) < 0)
+					die_errno("'%s': trace", child_name);
+			}
+			ACK("trace");
+		} else if (!strcmp("quit", buf.buf)) {
+			close(0);
+			close(1);
+			break;
+		} else
+			die("Unhandled command: '%s'", buf.buf);
+
+	}
+
+	strbuf_release(&buf);
+}
+
+int cmd__trace(int argc, const char **argv)
+{
+	const char *argv0 = argv[-1];
+
+	if (argc > 1 && !strcmp("lock", argv[1])) {
+		if (argc > 2)
+			child(argv[2]);
+		else
+			contention_orchestrator(argv0);
+	} else
+		die("Usage: %s %s lock [<child-name>]", argv0, argv[0]);
+
+	return 0;
+}
diff --git a/t/t0070-fundamental.sh b/t/t0070-fundamental.sh
index 23fbe6434..57f7a1246 100755
--- a/t/t0070-fundamental.sh
+++ b/t/t0070-fundamental.sh
@@ -34,4 +34,10 @@ test_expect_success 'check for a bug in the regex routines' '
 	test-tool regex --bug
 '
 
+test_expect_success 'multiple processes can GIT_TRACE to the same file' '
+	GIT_TRACE="$(pwd)/trace" test-tool trace lock &&
+	sed -n "/while-locked/,\$s/.*delayed$/YES/p" <trace >actual &&
+	test YES = "$(cat actual)"
+'
+
 test_done
-- 
gitgitgadget