<div dir="ltr"><br><br><div class="gmail_quote"><div dir="ltr">On Tue, Jun 2, 2015 at 9:27 AM FUJIWARA Katsunori <<a href="mailto:foozy@lares.dti.ne.jp">foozy@lares.dti.ne.jp</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><br>
At Mon, 01 Jun 2015 18:57:16 +0000,<br>
Martin von Zweigbergk wrote:<br>
><br>
> [1  <text/plain; UTF-8 (7bit)>]<br>
> On Mon, Jun 1, 2015 at 11:07 AM FUJIWARA Katsunori <<a href="mailto:foozy@lares.dti.ne.jp" target="_blank">foozy@lares.dti.ne.jp</a>><br>
> wrote:<br>
><br>
> > At Mon, 01 Jun 2015 17:02:10 +0000,<br>
> > Martin von Zweigbergk wrote:<br>
> > ><br>
> > > [1  <text/plain; UTF-8 (7bit)>]<br>
> > > Thanks. I think I knew most of that, but the subrepo case for interrupted<br>
> > > update was a good example I had not thought about. My question remains,<br>
> > > however. In the sequence in this test case, you do this:<br>
> > ><br>
> > > $ hg update -q -C 3<br>
> > > $ touch -t 200001010000 b<br>
> > > $ hg status -A b<br>
> > > $ hg --config extensions.abort=$TESTTMP/abort.py merge 5<br>
> > > $ touch -t 200001010000 b<br>
> > ><br>
> > > What I'm wondering is what real-world scenarios could lead to file b's<br>
> > > timestamp being the same in those two cases (where you artificially touch<br>
> > > them here). Since we said that 'hg status' is run strictly after (at<br>
> > > whatever granularity is recorded by the FS, perhaps second-level), how<br>
> > can<br>
> > > the 'hg merge' produce a timestamp for file b that's the same as what 'hg<br>
> > > update' does?<br>
> ><br>
> > `hg merge` can be aborted by same reason at `hg update` before<br>
> > updating dirstate:<br>
> ><br>
> >   (0) cleanup working directory for examination of `hg merge`<br>
> >       (let's ignore this while focusing on examination of `hg merge`)<br>
> > > $ hg update -q -C 3<br>
> ><br>
> >   (1) ensure forcibly that `repo.dirstate['b']` has valid timestamp<br>
> > > $ touch -t 200001010000 b<br>
> > > $ hg status -A b<br>
> ><br>
><br>
> We said that this 'hg status' is run at 200001010000(00)+1sec (otherwise<br>
> the timestamp in the dirstate would be unset). Correct?<br>
<br>
Yes, it is correct.<br>
<br>
> ><br>
> >   (2) execute `hg merge`, but it is aborted before "update dirstate"<br>
> >       for example:<br>
> >       - invalid updating in subrepositories<br>
> >       - keyboard interruption by user, file I/O error and so on<br>
> > > $ hg --config extensions.abort=$TESTTMP/abort.py merge 5<br>
> ><br>
> >   (3) (re-)set timestamp of 'b' on the filesystem for mis-leading<br>
> >       this emulates that `hg merge` update 'b' before 200001010000(00)+1sec<br>
> > > $ touch -t 200001010000 b<br>
> ><br>
><br>
> Since 'hg status' above was run at 200001010000(00)+1sec (or later), how<br>
> can this (interrupted) merge be run at 200001010000(00)?<br>
<br>
Oh, your wondering is natural. My explanation was wrong :-<<br>
<br>
In real world, steps below reproduce this issue:<br></blockquote><div><br></div><div>Great explanation! Thanks!</div><div><br></div><div>So the problem is that we mark the file clean in dirstate as a result of checking its status, then we update it on disk, abort the update, write the clean dirstate to disk and stay on the old revision. It seems a little strange to me that we write the dirstate even on failure. Do you know if there is a good reason for that?</div><div><br></div><div>Perhaps another option is to mark all files in the merge normallookup() before applyupdates()? That should mean that an abort later on would be safe, no?</div><div><br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<br>
  == @200001010000(00)<br>
<br>
  (A) 'b' should be modified at this point, but<br>
<br>
  (B) it is assumed that dirstate timestamp of 'b' is -1 at this point<br>
<br>
  (C) invoke `hg merge`<br>
<br>
    (C-1) get wlock<br>
<br>
    (C-2) check uncommitted changes in `merge.update()` by `wc.files()`:<br>
<br>
          this indirectly sets dirstate timestamp of 'b' as 200001010000(00)<br>
<br>
            wc.files() => wc._status() => repo.status() => ... =><br>
            wc._dirstatestatus() => wc._checklookup() => dirstate.normal()<br>
<br></blockquote><div><br></div><div>Would an alternative fix be to write the dirstate here (and after recordupdates(), of course)? Would that be unacceptably slow, perhaps?</div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
    (C-3) `merge.applyupates()` overwrites 'b' by the data in same size<br>
<br>
          FS timestamp of it is still 200001010000(00)<br>
<br>
    (C-3) fail before `merge.recordupdates()`<br>
<br>
  == @200001010000(00) + 1<br>
<br>
    (C-4) release wlock, and this causes written dirty dirstate out<br>
<br>
          this also writes out 200001010000(00) of 'b' successfully,<br>
          because FS timestamp of dirstate is 200001010000(00) + 1<br>
<br>
  (D) `hg status` treats 'b' as CLEAN, because FS timestamp/size of it<br>
      aren't changed<br>
<br>
Then, steps below (= without 'hg status -A b') can reproduce this<br>
issue almost always:<br>
<br>
  $ hg update -q -C 3<br>
  $ touch -t 200001010000 b<br>
  $ hg --config extensions.abort=$TESTTMP/abort.py merge 5<br>
  $ touch -t 200001010000 b<br>
<br>
But timestamp of dirstate may be set accidentally at `hg update`, and<br>
this breaks assumption (B) above.<br>
<br>
This is timing critical problem and we can't fully control it :-<<br>
<br>
On the other hand, tests in my patch execute steps below to make<br>
similar (but a little different in detail) situation:<br>
<br>
  == @200001010000(00)<br>
<br>
  (A) `touch -t 200001010000 b` emulates that 'b' is modified at this point<br>
<br>
  (B') `hg status` can write 200001010000(00) of 'b' into dirstate successfully<br>
<br>
      because `hg status` isn't actually executed at 200001010000(00) :-)<br>
<br>
  (C) invoke `hg merge`<br>
<br>
    (C-1) get wlock<br>
<br>
    (C-2) check uncommitted changes in `merge.update()` by `wc.files()`<br>
<br>
          'b' is already known as CLEAN by 200001010000(00)<br>
<br>
    (C-3) `merge.applyupates()` overwrites 'b' by the data in same size<br>
<br>
          FS timestamp of it isn't 200001010000(00), because `hg<br>
          merge` isn't actually executed at 200001010000(00)<br>
<br>
          but `touch -t 200001010000 b` after `hg merge` emulates it.<br>
<br>
    (C-3) fail before `merge.recordupdates()`<br>
<br>
  == @200001010000(00) + 1<br>
<br>
    (C-4) release wlock, and this causes written dirty dirstate out<br>
<br>
          dirstate timestamp of 'b' is still 200001010000(00)<br>
<br>
  (D) `hg status` treats 'b' as CLEAN, because FS timestamp/size of it<br>
      aren't changed (only if this issue isn't fixed well)<br>
<br>
<br>
<br>
> > In addition to it, '.hgsubstate' may have to be focused on.<br>
> ><br>
> > Regardless of `hg update`/`hg merge` result, size of it on the<br>
> > filesystem is often kept, because '.hgsubstate' consists of "hashid<br>
> > subrepopath": "hashid" of hg subrepo is always 40 letters :-)<br>
> ><br>
> ><br>
> > (Do I understand your question correctly ?)<br>
> ><br>
> ><br>
> > > On Sun, May 31, 2015 at 10:24 PM FUJIWARA Katsunori <<br>
> > <a href="mailto:foozy@lares.dti.ne.jp" target="_blank">foozy@lares.dti.ne.jp</a>><br>
> > > wrote:<br>
> > ><br>
> > > > At Fri, 29 May 2015 18:05:18 +0000,<br>
> > > > Martin von Zweigbergk wrote:<br>
> > > > ><br>
> > > > > [1  <text/plain; UTF-8 (7bit)>]<br>
> > > > > On Wed, May 27, 2015 at 10:06 AM FUJIWARA Katsunori <<br>
> > > > <a href="mailto:foozy@lares.dti.ne.jp" target="_blank">foozy@lares.dti.ne.jp</a>><br>
> > > > > wrote:<br>
> > > > ><br>
> > > > > > # HG changeset patch<br>
> > > > > > # User FUJIWARA Katsunori <<a href="mailto:foozy@lares.dti.ne.jp" target="_blank">foozy@lares.dti.ne.jp</a>><br>
> > > > > > # Date 1432745859 -32400<br>
> > > > > > #      Thu May 28 01:57:39 2015 +0900<br>
> > > > > > # Node ID b82f32b8734b109b84f533dc62dd3f23195d1e0a<br>
> > > > > > # Parent  ab9f120295b59933d1acd72771f01b5fac8d221d<br>
> > > > > > localrepo: invoke dirstate.unsureifambig in wwrite for safety<br>
> > > > > ><br>
> > > > > > Modified file may be mis-recognized as clean by dirstate, if mode,<br>
> > > > > > size and timestamp of it on the filesystem aren't changed.<br>
> > > > > ><br>
> > > > > > To avoid such ambiguous situation, this patch invokes<br>
> > > > > > `dirstate.unsureifambig()` at the end of<br>
> > `localrepository.wwrite()`.<br>
> > > > > ><br>
> > > > > > When file is cleanly reverted or updated, subsequent<br>
> > > > > > `dirstate.lookup()` makes `dirstate.unsureifambig()` a little<br>
> > > > > > redundant. But it is enough cheap for keeping consistency.<br>
> > > > > ><br>
> > > > > > diff --git a/mercurial/localrepo.py b/mercurial/localrepo.py<br>
> > > > > > --- a/mercurial/localrepo.py<br>
> > > > > > +++ b/mercurial/localrepo.py<br>
> > > > > > @@ -927,7 +927,9 @@<br>
> > > > > >              self.wvfs.write(filename, data)<br>
> > > > > >              if 'x' in flags:<br>
> > > > > >                  self.wvfs.setflags(filename, False, True)<br>
> > > > > > -        return len(data)<br>
> > > > > > +        wsize = len(data)<br>
> > > > > > +        self.dirstate.unsureifambig(filename, wsize)<br>
> > > > > > +        return wsize<br>
> > > > > ><br>
> > > > > >      def wwritedata(self, filename, data):<br>
> > > > > >          return self._filter(self._decodefilterpats, filename,<br>
> > data)<br>
> > > > > > diff --git a/tests/test-merge1.t b/tests/test-merge1.t<br>
> > > > > > --- a/tests/test-merge1.t<br>
> > > > > > +++ b/tests/test-merge1.t<br>
> > > > > > @@ -206,4 +206,60 @@<br>
> > > > > >    $ hg revert -r -2 b<br>
> > > > > >    $ hg up -q -- -2<br>
> > > > > ><br>
> > > > > > +Test for ambiguity from same size, timestamp and mode<br>
> > > > > > +<br>
> > > > > > +  $ cat > $TESTTMP/abort.py <<EOF<br>
> > > > > > +  > from mercurial import extensions, merge, util<br>
> > > > > > +  > def applyupdates(orig, *args, **kwargs):<br>
> > > > > > +  >     orig(*args, **kwargs)<br>
> > > > > > +  >     # emulate aborting before "recordupdates()"<br>
> > > > > > +  >     # => files are changed without updating dirstate<br>
> > > > > > +  >     raise util.Abort('intentional aborting')<br>
> > > > > > +  > def extsetup(ui):<br>
> > > > > > +  >     extensions.wrapfunction(merge, "applyupdates",<br>
> > applyupdates)<br>
> > > > > > +  > EOF<br>
> > > > > > +<br>
> > > > > > +(file gotten from other revision)<br>
> > > > > > +<br>
> > > > > > +  $ hg update -q -C 2<br>
> > > > > > +  $ echo 'THIS IS FILE B5' > b<br>
> > > > > > +  $ hg commit -m 'commit #5'<br>
> > > > > > +<br>
> > > > > > +  $ hg update -q -C 3<br>
> > > > > > +  $ touch -t 200001010000 b<br>
> > > > > > +  $ hg status -A b<br>
> > > > > > +  C b<br>
> > > > > > +  $ cat b<br>
> > > > > > +  This is file b1<br>
> > > > > > +<br>
> > > > > > +  $ hg --config extensions.abort=$TESTTMP/abort.py merge 5<br>
> > > > > > +  abort: intentional aborting<br>
> > > > > > +  [255]<br>
> > > > > > +  $ touch -t 200001010000 b<br>
> > > > > ><br>
> > > > ><br>
> > > > > I'm sorry I'm slow, but I'm still trying to understand this series.<br>
> > This<br>
> > > > is<br>
> > > > > of course an artificial way of reproducing the problem you were<br>
> > seeing,<br>
> > > > but<br>
> > > > > how does it sometimes happen in real life? Since the dirstate is<br>
> > written<br>
> > > > on<br>
> > > > > the 'hg status' call above, and that command is run after (not<br>
> > within the<br>
> > > > > same second, as we discussed on path 1/5) the file was modified on<br>
> > disk,<br>
> > > > > how can the 'hg merge' command be run at the earlier time again<br>
> > (which<br>
> > > > you<br>
> > > > > seem to be simulating here by setting the same timestamp)?<br>
> > > ><br>
> > > > Sorry for not enough explanation. I'll add more detailed explanation<br>
> > > > in revised version.<br>
> > > ><br>
> > > > Core of `hg update` and `hg merge` consists of steps below:<br>
> > > ><br>
> > > >   1. calculate result of updating and examine some additional points<br>
> > below<br>
> > > ><br>
> > > >      - `_checkunknownfiles()` (implied by `calculateupdates()`)<br>
> > > >      - `_checkcollision()`<br>
> > > ><br>
> > > >   2. update files in the working directory in `merge.applyupdates()`<br>
> > > ><br>
> > > >      this also implies updating files in subrepositories recursively<br>
> > > >      (= `preupdate`/`update` hooks in them are also executed)<br>
> > > ><br>
> > > >   3. update dirstate in `merge.recordupdates()`<br>
> > > ><br>
> > > >   4. write in-memory dirstate changes out at releasing wlock<br>
> > > ><br>
> > > ><br>
> > > > Tests in this patch emulate that `hg update` and `hg merge` (at top of<br>
> > > > subrepo tree) are aborted between (2) and (3) by:<br>
> > > ><br>
> > > >   - invalid updating in subrepositories<br>
> > > ><br>
> > > >     for example:<br>
> > > >     - uncommitted changes<br>
> > > >     - collision against unknown files in the working directory<br>
> > > >     - case-insensitive collision between files in new revision (and<br>
> > > >       current one at merging)<br>
> > > >     - failure of `preupdate` or `update` hooks<br>
> > > ><br>
> > > >   - keyboard interruption by user, file I/O error and so on<br>
> > > ><br>
> > > > `test-subrepo.t` actually treats the former situation, and<br>
> > > > 6becb9dbca25 tried to fix (part of) this issue. Tests in this patch<br>
> > > > can be said as "generalized version of test in 6becb9dbca25".<br>
> > > ><br>
> > > ><br>
> > > > Even though some existing tests are enough as a white box test<br>
> > > > examining whether `repo.wwrite()` invokes `dirstate.unsureifambig()`<br>
> > > > correctly, testing in multiple situations should be useful to avoid<br>
> > > > unexpected regression in the future, IMHO.<br>
> > > ><br>
> > > ><br>
> > > ><br>
> > > > > > +  $ cat b<br>
> > > > > > +  THIS IS FILE B5<br>
> > > > > > +  $ hg status -A b<br>
> > > > > > +  M b<br>
> > > > > > +<br>
> > > > > > +(file merged from other revision)<br>
> > > > > > +<br>
> > > > > > +  $ hg update -q -C 3<br>
> > > > > > +  $ echo 'this is file b6' > b<br>
> > > > > > +  $ hg commit -m 'commit #6'<br>
> > > > > > +  created new head<br>
> > > > > > +  $ touch -t 200001010000 b<br>
> > > > > > +  $ hg status -A b<br>
> > > > > > +  C b<br>
> > > > > > +  $ cat b<br>
> > > > > > +  this is file b6<br>
> > > > > > +<br>
> > > > > > +  $ hg --config extensions.abort=$TESTTMP/abort.py merge --tool<br>
> > > > > > internal:other 5<br>
> > > > > > +  abort: intentional aborting<br>
> > > > > > +  [255]<br>
> > > > > > +  $ touch -t 200001010000 b<br>
> > > > > > +  $ cat b<br>
> > > > > > +  THIS IS FILE B5<br>
> > > > > > +  $ hg status -A b<br>
> > > > > > +  M b<br>
> > > > > > +<br>
> > > > > >    $ cd ..<br>
> > > > > > _______________________________________________<br>
> > > > > > Mercurial-devel mailing list<br>
> > > > > > <a href="mailto:Mercurial-devel@selenic.com" target="_blank">Mercurial-devel@selenic.com</a><br>
> > > > > > <a href="https://selenic.com/mailman/listinfo/mercurial-devel" target="_blank">https://selenic.com/mailman/listinfo/mercurial-devel</a><br>
> > > > > ><br>
> > > > > [2  <text/html; UTF-8 (quoted-printable)>]<br>
> > > > ><br>
> > > ><br>
> > > > ----------------------------------------------------------------------<br>
> > > > [FUJIWARA Katsunori]                             <a href="mailto:foozy@lares.dti.ne.jp" target="_blank">foozy@lares.dti.ne.jp</a><br>
> > > ><br>
> > > [2  <text/html; UTF-8 (quoted-printable)>]<br>
> > ><br>
> ><br>
> > ----------------------------------------------------------------------<br>
> > [FUJIWARA Katsunori]                             <a href="mailto:foozy@lares.dti.ne.jp" target="_blank">foozy@lares.dti.ne.jp</a><br>
> ><br>
> [2  <text/html; UTF-8 (quoted-printable)>]<br>
><br>
<br>
----------------------------------------------------------------------<br>
[FUJIWARA Katsunori]                             <a href="mailto:foozy@lares.dti.ne.jp" target="_blank">foozy@lares.dti.ne.jp</a><br>
</blockquote></div></div>