<div dir="ltr">On Mon, Jul 13, 2015 at 2:06 PM, Matt Mackall <span dir="ltr"><<a href="mailto:mpm@selenic.com" target="_blank">mpm@selenic.com</a>></span> wrote:<br><div class="gmail_extra"><div class="gmail_quote"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div class=""><div class="h5">On Mon, 2015-07-13 at 09:16 -0700, Gregory Szorc wrote:<br>
> On Sat, Jul 11, 2015 at 3:26 PM, Gregory Szorc <<a href="mailto:gregory.szorc@gmail.com">gregory.szorc@gmail.com</a>><br>
> wrote:<br>
><br>
> > On Sat, Jul 11, 2015 at 1:17 PM, Matt Mackall <<a href="mailto:mpm@selenic.com">mpm@selenic.com</a>> wrote:<br>
> ><br>
> >> On Sat, 2015-07-11 at 11:26 -0700, Gregory Szorc wrote:<br>
> >> > On Fri, Jul 10, 2015 at 5:03 PM, Matt Mackall <<a href="mailto:mpm@selenic.com">mpm@selenic.com</a>> wrote:<br>
> >> ><br>
> >> > > On Fri, 2015-07-10 at 16:46 -0700, Gregory Szorc wrote:<br>
> >> > > > # HG changeset patch<br>
> >> > > > # User Gregory Szorc <<a href="mailto:gregory.szorc@gmail.com">gregory.szorc@gmail.com</a>><br>
> >> > > > # Date 1436571961 25200<br>
> >> > > > #      Fri Jul 10 16:46:01 2015 -0700<br>
> >> > > > # Node ID bca84aa6ea80b386a01c245e7f4e4ebdb720cd8c<br>
> >> > > > # Parent  648323f41a89619d9eeeb7287213378c340866c8<br>
> >> > > > revlog/changegroup: use callbacks for populating efiles<br>
> >> > ><br>
> >> > > Probably needs to use the flush() thingy that the nearby censor code<br>
> >> is<br>
> >> > > using.<br>
> >> > ><br>
> >> ><br>
> >> > Calling flush() makes the error go away!<br>
> >> ><br>
> >> > While my SSD equipped MBP didn't appear to exhibit a slowdown unbundling<br>
> >> > mozilla-central, flushing file descriptors after applying each changeset<br>
> >> > feels a bit excessive and it makes me uncomfortable due to potential<br>
> >> > performance implications. I just don't think an extra I/O related<br>
> >> syscall<br>
> >> > should be required for this feature.<br>
> >><br>
> >> The flush is only a flush from the userspace file buffers to kernel-side<br>
> >> buffers, it won't actually force I/O. It'll still be lazily written by<br>
> >> the kernel's caching layer at roughly the same rate as without the<br>
> >> buffering because the userspace buffers are tiny (4k) relative a modern<br>
> >> system's disk cache. But yes, it is a syscall and syscalls aren't free.<br>
> >><br>
> >> > But you have a stronger grasp on these things than me. Is calling<br>
> >> flush()<br>
> >> > after every changeset add acceptable? Keep in mind this will be the only<br>
> >> > behavior for addchangegroup(), regardless of whether progress bars are<br>
> >> > displayed.<br>
> >><br>
> >> Well, it can be conditional on there being a callback.<br>
> >><br>
> ><br>
> > Right. But for changegroup.addchangegroup(), there will always be a<br>
> > callback so this will be the default behavior for many cases.<br>
> ><br>
> ><br>
> >><br>
> >> In the slightly bigger picture, we might want to make the revlog object<br>
> >> aware of the file handles it might need to flush so that rather than<br>
> >> explicitly flushing on the write side, the read side can flush only if<br>
> >> needed. Something like:<br>
> >><br>
> >> for f in self._flushonread:<br>
> >>     f.flush()<br>
> >><br>
> >> ..with the appropriate try/finally around the writers.<br>
> >><br>
> >> In the even bigger still picture, we might want to make it optionally<br>
> >> possible for revlog to hold onto file handles for the object's lifetime<br>
> >> to reduce syscall count and filesystem lookup overhead. Historically we<br>
> >> don't do this because Windows.<br>
> >><br>
> ><br>
> > Looking at things a bit more, my original patch series also added<br>
> > additional flushes because buildtext() inside revlog._addrevision() does<br>
> > flushing and my "return text" patch made the call to buildtext()<br>
> > unconditional.<br>
> ><br>
> > Tracing the system calls when applying a bunch of changesets, I'm seeing<br>
> > what I think is "odd" behavior. .hg/store/00changelog.i.a is opened,<br>
> > fstat()d twice, lseek()d twice, read() a few times, maybe write()n, and<br>
> > closed. This cycle repeats over and over. I'm still trying to grok what is<br>
> > happening. But it certainly doesn't feel very efficient. I suspect it has<br>
> > something to do with the flushing, which happens every couple of changesets<br>
> > inside buildtext(). I'm pretty sure this corresponds to starting/ending a<br>
> > delta chain.<br>
> ><br>
> > This is the first time I've dug into the bowels of revlogs. It's a bit<br>
> > overwhelming. On the bright side, I think I'm starting to identify some<br>
> > potential performance improvements!<br>
> ><br>
><br>
> I tracked down the source of all the extra opens. The stack looks like this:<br>
><br>
>   /Users/gps/src/hg/mercurial/changegroup.py(757)addchangegroup()<br>
> -> srccontent = cl.addgroup(source, csmap, trp)<br>
>   /Users/gps/src/hg/mercurial/revlog.py(1461)addgroup()<br>
> -> ifh, dfh)<br>
>   /Users/gps/src/hg/mercurial/revlog.py(1346)_addrevision()<br>
> -> text = buildtext()<br>
>   /Users/gps/src/hg/mercurial/revlog.py(1265)buildtext()<br>
> -> basetext = self.revision(self.node(baserev))<br>
>   /Users/gps/src/hg/mercurial/revlog.py(1094)revision()<br>
> -> bins = self._chunks(chain)<br>
>   /Users/gps/src/hg/mercurial/revlog.py(1001)_chunks()<br>
> -> self._chunkraw(revs[0], revs[-1])<br>
>   /Users/gps/src/hg/mercurial/revlog.py(976)_chunkraw()<br>
> -> return self._getchunk(start, length)<br>
>   /Users/gps/src/hg/mercurial/revlog.py(967)_getchunk()<br>
> -> return self._loadchunk(offset, length)<br>
>   /Users/gps/src/hg/mercurial/revlog.py(936)_loadchunk()<br>
> -> df = self.opener(self.indexfile)<br>
><br>
> Essentially, every time we start/end a new delta chain, we need to flush<br>
> the revlog (+ index), open a new file handle, and read in revisions<br>
> necessary to construct the full revision text. In the case of the changelog<br>
> during addgroup() (where delta chains are typically 2-4 in length), this<br>
> results in tons of extra file I/O. On mozilla-central, we perform ~100,000<br>
> flush + opens over ~250,000 changesets.<br>
><br>
> I'll continue to poke around with creative solutions that don't regress<br>
> performance.<br>
<br>
</div></div>One possibility would be to prime the chunk cache as we go.<br></blockquote><div><br></div><div>I tried this and it reduced performance significantly. I suspect the immutable nature of the chunk cache being a str resulted in tons of allocations, copies, and GC pressure.<br><br>The next thing I want to try is to cache the full text revision as we go (probably only for changelog, since doing this for large manifests will be slow). If that doesn't pan out, rewriting the chunk cache as a mutable buffer (potentially in C) or restructuring the chunk cache so it is an iterable of segments feel like viable alternatives.<br><br>Also, the chunk cache feels somewhat primitive to me. e.g. it throws away old data instead of attempting to create a sliding window, etc (<a href="https://selenic.com/repo/hg/file/tip/mercurial/revlog.py#l926">https://selenic.com/repo/hg/file/tip/mercurial/revlog.py#l926</a>). It feels like there is room to optimize this cache. I wouldn't be surprised if making it a bit smarter would benefit read performance as well.<br></div></div></div></div>