install: amortize metalog locking/flushing with a memory buffer

[rlibby]

Summary

This was good for an 18% time reduction in an installworld where the
metalog file was on nfs. It will not affect installworld without a
metalog file, and it will probably not help installworld with a local
metalog file.

[des]

I wonder if we could achieve the same goal more cleanly by adding a multi-line buffering mode to stdio. Call it _IOMBF and make it work like fully buffered, except that when the buffer is full we only flush up to the last newline in the buffer, and keep the leftovers. That probably means the last line is lost on close if not terminated, but that's fine if we document it.

[rlibby]

In D59380#1362364, @des wrote:

I wonder if we could achieve the same goal more cleanly by adding a multi-line buffering mode to stdio. Call it _IOMBF and make it work like fully buffered, except that when the buffer is full we only flush up to the last newline in the buffer, and keep the leftovers. That probably means the last line is lost on close if not terminated, but that's fine if we document it.

I'm not sure I follow. Are you saying, and then get rid of the advisory locking entirely, and just hope that flushes are applied atomically?

My understanding of what is making my use case slow (metalog on nfs) is that releasing the advisory lock results in a flush and nfs commit. This patch tries to reduce that by at least reducing the advisory lock acquire/release to once per install invocation (which admittedly only helps for the minority of cases where the install command line has multiple files). That is, I'm not exactly trying to reduce the stdio flushes, I'm trying to reduce the nfs commits. I don't think changing stdio buffering by itself would change this at all (and note the location of the fflush(), under the advisory lock). Getting rid of the advisory locks would probably make this much faster, regardless of stdio buffering, but I think that would break parallel install using the same metalog.

Maybe one could imagine installworld etc using j distinct metalog files and then merging them at the end instead, and in that way eliminate the need for the advisory locking. That would probably take some plumbing in make.

[des]

In D59380#1362584, @rlibby wrote:

My understanding of what is making my use case slow (metalog on nfs) is that releasing the advisory lock results in a flush and nfs commit. This patch tries to reduce that by at least reducing the advisory lock acquire/release to once per install invocation (which admittedly only helps for the minority of cases where the install command line has multiple files). That is, I'm not exactly trying to reduce the stdio flushes, I'm trying to reduce the nfs commits. I don't think changing stdio buffering by itself would change this at all (and note the location of the fflush(), under the advisory lock). Getting rid of the advisory locks would probably make this much faster, regardless of stdio buffering, but I think that would break parallel install using the same metalog.

I glossed over the diff, I didn't realize the metalog was locked. That shouldn't be necessary as long as it's opened in append mode and line-buffered. I would suggest running some tests with just the locking and flushes removed and setvbuf(metafp, NULL, _IOLBF, 0) added.

@brd do you have an opinion on this?

[rlibby]

In D59380#1362615, @des wrote:

In D59380#1362584, @rlibby wrote:

My understanding of what is making my use case slow (metalog on nfs) is that releasing the advisory lock results in a flush and nfs commit. This patch tries to reduce that by at least reducing the advisory lock acquire/release to once per install invocation (which admittedly only helps for the minority of cases where the install command line has multiple files). That is, I'm not exactly trying to reduce the stdio flushes, I'm trying to reduce the nfs commits. I don't think changing stdio buffering by itself would change this at all (and note the location of the fflush(), under the advisory lock). Getting rid of the advisory locks would probably make this much faster, regardless of stdio buffering, but I think that would break parallel install using the same metalog.

I glossed over the diff, I didn't realize the metalog was locked. That shouldn't be necessary as long as it's opened in append mode and line-buffered. I would suggest running some tests with just the locking and flushes removed and setvbuf(metafp, NULL, _IOLBF, 0) added.

@brd do you have an opinion on this?

I think the integrity of that under parallel installs inherently assumes that writes are atomic. I don't think that is guaranteed in general, and especially over nfs. I'm also not sure that that will be any faster than this, due to nfs flush/commit on close. But I can certainly measure it.

[des]

In D59380#1362629, @rlibby wrote:

I think the integrity of that under parallel installs inherently assumes that writes are atomic. I don't think that is guaranteed in general, and especially over nfs.

If metafp is line-buffered, stdio will automatically flush every time a newline character is written to it. The flush operation writes the entire buffer in a single syscall. Even if another program is writing to the same file at the same time, the kernel serializes those writes and each line is written atomically. If the log is on NFS each write is a single request and should be handled atomically by the server, even if it is too long for a single packet. I encourage you to experiment.

I'm also not sure that that will be any faster than this, due to nfs flush/commit on close. But I can certainly measure it.

It will be significantly faster without locking.

[rlibby]

In D59380#1362825, @des wrote:

It will be significantly faster without locking.

Yes indeed, removing the locks made it 15x faster, compared to 30% faster for the lock amortization.

base install, nfs objdir, local metalog
make installworld $JOPT DESTDIR=/usr/obj/foo NO_ROOT=yes   84.32s user 93.89s system 430% cpu 41.352 total

base install, nfs objdir, nfs metalog
make installworld $JOPT DESTDIR=/usr/obj/foo NO_ROOT=yes   60.75s user 72.10s system 17% cpu 13:01.29 total

amortized install, nfs objdir, local metalog
make installworld $JOPT DESTDIR=/usr/obj/foo NO_ROOT=yes   84.56s user 93.95s system 415% cpu 42.997 total

amortized install, nfs objdir, nfs metalog
make installworld $JOPT DESTDIR=/usr/obj/foo NO_ROOT=yes   61.87s user 72.56s system 22% cpu 9:56.98 total

nolock install, nfs objdir, nfs metalog
make installworld $JOPT DESTDIR=/usr/obj/foo NO_ROOT=yes   84.59s user 96.17s system 370% cpu 48.726 total

Even if another program is writing to the same file at the same time, the kernel serializes those writes and each line is written atomically. If the log is on NFS each write is a single request and should be handled atomically by the server, even if it is too long for a single packet.

This is the part that makes me uneasy. This seems to amount to "short writes can't happen". I do not believe write(2) makes any such guarantee and I am familiar with file systems where this is not true. The implementation of the kernel function dofilewrite (sys_write / kern_writev / dofilewrite) seems to support the idea that short writes are a contemplated and supported part of the VFS design. This very program handles short writes in its copy() routine.

Anyway, I agree that an 30% gain is small potatoes when a 15x gain seems possible, so maybe the patch at hand is not the right approach.

[brooks]

In D59380#1363039, @rlibby wrote:

In D59380#1362825, @des wrote:

Even if another program is writing to the same file at the same time, the kernel serializes those writes and each line is written atomically. If the log is on NFS each write is a single request and should be handled atomically by the server, even if it is too long for a single packet.

This is the part that makes me uneasy. This seems to amount to "short writes can't happen". I do not believe write(2) makes any such guarantee and I am familiar with file systems where this is not true. The implementation of the kernel function dofilewrite (sys_write / kern_writev / dofilewrite) seems to support the idea that short writes are a contemplated and supported part of the VFS design. This very program handles short writes in its copy() routine.

Anyway, I agree that an 30% gain is small potatoes when a 15x gain seems possible, so maybe the patch at hand is not the right approach.

It's potentially worth noting that the other major writer to the METALOG is cat -l consuming the input of a number of different tools (at least echo, sed, and mtree in a quick search).