Re: [RFC PATCH 4/4] t/lib-httpd: sort log based on timestamp to avoid occasional failure

From: Jeff King <peff@peff.net>
Date: Jul 11, 2018, 14:45 UTC
Message-ID: <20180711144555.GA15269@sigill.intra.peff.net>
In-Reply-To: <CAM0VKjmXoOaYFrkNJzNp_wgzReaXSZHiDCtJRADX0RRG123wPw@mail.gmail.com>

On Wed, Jul 11, 2018 at 02:53:23PM +0200, SZEDER Gábor wrote:

Show 6 quoted lines

> > I.e., could we have a situation where we make a request, the client
> > finishes, and then we look at the logs, but nothing has been written by
> > apache yet?
> 
> That's possible, I suppose.  Highly improbable, but possible.  Or the
> log entries can be written only partially by the time we look at them.

Digging into earlier cases I had seen on my local box, my impression was that this was the problem I was seeing (not reordering). But it's entirely possible that I was confused by reordering. I've been trying to reproduce, but after 5 minutes of t5561 running in a tight loop under high load, I haven't gotten a single failure.

> Anyway, I would prefer not to do anything about it just yet, because
> I'm curious :) and I'd like to see whether this actually happens in
> practice.

I can't reproduce for now, so I'm happy either way. :)

Show 8 quoted lines

> > What if the test script provides the in-order expectation, but we check
> > only the unordered version (by sorting both actual and expected output
> > on the fly)? That would give us a more relaxed check most of the time,
> > but somebody digging in to a failure could run the ordered diff (or we
> > could even show it automatically on failure instead of just using
> > test_cmp).
> 
> this is the fix I'll go for in v2.

Great. That seems much simpler to reason about. I'll take a look.

-Peff