Update Nov. 2020, nine+ years later:
With Git 2.30 (Q1 2021), the side-band status report can be sent at the same time as the primary payload multiplexed, but the demultiplexer on the receiving end incorrectly split a single status report into two, which has been corrected.
That could help avoid errors from the "remote end", as seen in the OP.
In 2b695ecd74d (t5500: count objects through stderr, not trace, 2020-05-06) we tried to ensure that the "Total 3" message could be grepped in Git's output, even if it sometimes got chopped up into multiple lines in the trace machinery.
However, the first instance where this mattered now goes through the sideband machinery, where it is still possible for messages to get chopped up: it is possible for the standard error stream to be sent byte-for-byte and hence it can be easily interrupted.
Meaning: it is possible for the single line that we're looking for to be chopped up into multiple sideband packets, with a primary packet being delivered between them.
This seems to happen occasionally in the vs-test part of our CI builds, i.e. with binaries built using Visual C, but not when building with GCC or clang; The symptom is that t5500.43 fails to find a line matching remote: Total 3 in the log file, which ends in something along these lines:
remote: Tota
remote: l 3 (delta 0), reused 0 (delta 0), pack-reused 0
This should not happen, though: we have code in demultiplex_sideband() specifically to stitch back together lines that were delivered in separate sideband packets.
However, this stitching was broken in a subtle way in fbd76cd450 ("sideband: reverse its dependency on pkt-line", 2019-01-16, Git v2.21.0-rc0 -- merge listed in batch #5): before that change, incomplete sideband lines would not be flushed upon receiving a primary packet, but after that patch, they would be.
The subtleness of this bug comes from the fact that it is easy to get confused by the ambiguous meaning of the break keyword: after writing the primary packet contents, the break; in the original version of recv_sideband() does not break out of the while loop, but instead only ends the switch case:
while (!retval) {
[...]
switch (band) {
[...]
case 1:
/* Write the contents of the primary packet */> write_or_die(out, buf + 1, len);
/* Here, we do *not* break out of the loop, `retval` is unchanged */
break;
...]
}
if (outbuf.len) {
/* Write any remaining sideband messages lacking a trailing LF */
strbuf_addch(&outbuf, '\n');
xwrite(2, outbuf.buf, outbuf.len);
}
In contrast, after fbd76cd450 ("sideband: reverse its dependency on pkt-line", 2019-01-16, Git v2.21.0-rc0 -- merge listed in batch #5), the body of the while loop was extracted into demultiplex_sideband(), crucially _including_ the logic to write incomplete sideband messages:
switch (band) {
[...]
case 1:
*sideband_type = SIDEBAND_PRIMARY;> /* This does not break out of the loop: the loop is in the caller */> break;
...]
}
cleanup:
[...]
/* This logic is now no longer `_outside`_ the loop but `_inside`_ */
if (scratch->len) {
strbuf_addch(scratch, '\n');
xwrite(2, scratch->buf, scratch->len);
}
The correct way to fix this is to return from demultiplex_sideband() early.
The caller will then write out the contents of the primary packet and continue looping.
The scratch buffer for incomplete sideband messages is owned by that caller, and will continue to accumulate the remainder(s) of those messages.
The loop will only end once demultiplex_sideband() returned non-zero and did not indicate a primary packet, which is the case only when we hit the cleanup: path, in which we take care of flushing any unfinished sideband messages and release the scratch buffer.
To ensure that this does not get broken again, we introduce a pair of subcommands of the pkt-line test helper that specifically chop up the sideband message and squeeze a primary packet into the middle.
Final note: The other test case touched by 2b695ecd74d (t5500: count objects through stderr, not trace, 2020-05-06, Git v2.27.0-rc0) is not affected by this issue because the sideband machinery is not involved there.
