changeset 25753:fe03f522dda9

context: write dirstate out explicitly after marking files as clean

To detect change of a file without redundant comparison of file
content, dirstate recognizes a file as certainly clean, if:

  (1) it is already known as "normal",
  (2) dirstate entry for it has valid (= not "-1") timestamp, and
  (3) mode, size and timestamp of it on the filesystem are as same as
      ones expected in dirstate

This works as expected in many cases, but doesn't in the corner case
that changing a file keeps mode, size and timestamp of it on the
filesystem.

The timetable below shows steps in one of typical such situations:

  ---- ----------------------------------- ----------------
                                           timestamp of "f"
                                           ----------------
                                           dirstate   file-
  time          action                     mem  file  system
  ---- ----------------------------------- ---- ----- -----
  N                                              -1    ***
       - make file "f" clean                            N

       - execute 'hg foobar'
         - instantiate 'dirstate'           -1   -1
         - 'dirstate.normal("f")'           N    -1
           (e.g. via dirty check)
         - change "f", but keep size                    N
  N+1
         - release wlock
           - 'dirstate.write()'             N    N

       - 'hg status' shows "f" as "clean"   N    N      N
  ---- ----------------------------------- ---- ----- -----

The most important point is that 'dirstate.write()' is executed at N+1
or later. This causes writing dirstate timestamp N of "f" out
successfully. If it is executed at N, 'parsers.pack_dirstate()'
replaces timestamp N with "-1" before actual writing dirstate out.

Occasional test failure for unexpected file status is typical example
of this corner case. Batch execution with small working directory is
finished in no time, and rarely satisfies condition (2) above.

This issue can occur in cases below;

  - 'hg revert --rev REV' for revisions other than the parent
  - failure of 'merge.update()' before 'merge.recordupdates()'

The root cause of this issue is that files are changed without
flushing in-memory dirstate changes via 'repo.commit()' (even though
omitting 'dirstate.normallookup()' on changed files also causes this
issue).

To detect changes of files correctly, this patch writes in-memory
dirstate changes out explicitly after marking files as clean in
'workingctx._checklookup()', which is invoked via 'repo.status()'.

After this change, timetable is changed as below:

  ---- ----------------------------------- ----------------
                                           timestamp of "f"
                                           ----------------
                                           dirstate   file-
  time          action                     mem  file  system
  ---- ----------------------------------- ---- ----- -----
  N                                              -1    ***
       - make file "f" clean                            N

       - execute 'hg foobar'
         - instantiate 'dirstate'           -1   -1
         - 'dirstate.normal("f")'           N    -1
           (e.g. via dirty check)
       ----------------------------------- ---- ----- -----
         - 'dirsttate.write()'              -1   -1
       ----------------------------------- ---- ----- -----
         - change "f", but keep size                    N
  N+1
         - release wlock
           - 'dirstate.write()'             -1   -1

       - 'hg status'                        -1   -1      N
  ---- ----------------------------------- ---- ----- -----

To reproduce this issue in tests certainly, this patch emulates some
timing critical actions as below:

  - timestamp of "f" in '.hg/dirstate' is -1 at the beginning

    'hg debugrebuildstate' before command invocation ensures it.

  - make file "f" clean at N
  - change "f" at N

    'touch -t 200001010000' before and after command invocation
    changes mtime of "f" to "2000-01-01 00:00" (= N).

  - invoke 'dirstate.write()' via 'repo.status()' at N

    'fakedirstatewritetime.py' forces 'pack_dirstate()' to use
    "2000-01-01 00:00" as "now", only if 'pack_dirstate()' is invoked
    via 'workingctx._checklookup()'.

  - invoke 'dirstate.write()' via releasing wlock at N+1 (or "not at N")

    'pack_dirstate()' via releasing wlock uses actual timestamp at
    runtime as "now", and it should be different from the "2000-01-01
    00:00" of "f".

BTW, this patch also changes 'test-largefiles-misc.t', because adding
'dirstate.write()' makes recent dirstate changes visible to external
process.

--- a/mercurial/context.py	Wed Jul 08 17:01:09 2015 +0900
+++ b/mercurial/context.py	Wed Jul 08 17:01:09 2015 +0900
@@ -1517,6 +1517,10 @@
                 try:
                     for f in fixup:
                         normal(f)
+                    # write changes out explicitly, because nesting
+                    # wlock at runtime may prevent 'wlock.release()'
+                    # below from doing so for subsequent changing files
+                    self._repo.dirstate.write()
                 finally:
                     wlock.release()
             except error.LockError:

--- a/tests/test-largefiles-misc.t	Wed Jul 08 17:01:09 2015 +0900
+++ b/tests/test-largefiles-misc.t	Wed Jul 08 17:01:09 2015 +0900
@@ -1008,10 +1008,6 @@
   > EOF
   $ hg clone -q enabled-but-no-largefiles no-largefiles
 
-(test rebasing implied by pull: precommit while rebasing unexpectedly
-shows "normal3" as "?", because lfdirstate isn't yet written out at
-that time)
-
   $ echo normal2 > enabled-but-no-largefiles/normal2
   $ hg -R enabled-but-no-largefiles add enabled-but-no-largefiles/normal2
   $ hg -R enabled-but-no-largefiles commit -m '#1@enabled-but-no-largefiles'
@@ -1026,7 +1022,7 @@
 
   $ hg -R no-largefiles -q pull --rebase
   Invoking status precommit hook
-  M normal3
+  A normal3
 
 (test reverting)
 

--- a/tests/test-merge-tools.t	Wed Jul 08 17:01:09 2015 +0900
+++ b/tests/test-merge-tools.t	Wed Jul 08 17:01:09 2015 +0900
@@ -601,6 +601,17 @@
 
 update is a merge ...
 
+(this also tests that files reverted with '--rev REV' are treated as
+"modified", even if none of mode, size and timestamp of them isn't
+changed on the filesystem (see also issue4583))
+
+  $ cat >> $HGRCPATH <<EOF
+  > [fakedirstatewritetime]
+  > # emulate invoking dirstate.write() via repo.status()
+  > # at 2000-01-01 00:00
+  > fakenow = 200001010000
+  > EOF
+
   $ beforemerge
   [merge-tools]
   false.whatever=
@@ -611,8 +622,16 @@
   $ f -s f
   f: size=17
   $ touch -t 200001010000 f
-  $ hg status f
+  $ hg debugrebuildstate
+  $ cat >> $HGRCPATH <<EOF
+  > [extensions]
+  > fakedirstatewritetime = $TESTDIR/fakedirstatewritetime.py
+  > EOF
   $ hg revert -q -r 1 .
+  $ cat >> $HGRCPATH <<EOF
+  > [extensions]
+  > fakedirstatewritetime = !
+  > EOF
   $ f -s f
   f: size=17
   $ touch -t 200001010000 f
@@ -646,8 +665,16 @@
   $ f -s f
   f: size=17
   $ touch -t 200001010000 f
-  $ hg status f
+  $ hg debugrebuildstate
+  $ cat >> $HGRCPATH <<EOF
+  > [extensions]
+  > fakedirstatewritetime = $TESTDIR/fakedirstatewritetime.py
+  > EOF
   $ hg revert -q -r 1 .
+  $ cat >> $HGRCPATH <<EOF
+  > [extensions]
+  > fakedirstatewritetime = !
+  > EOF
   $ f -s f
   f: size=17
   $ touch -t 200001010000 f

--- a/tests/test-merge1.t	Wed Jul 08 17:01:09 2015 +0900
+++ b/tests/test-merge1.t	Wed Jul 08 17:01:09 2015 +0900
@@ -206,4 +206,91 @@
   $ hg revert -r -2 b
   $ hg up -q -- -2
 
+Test that updated files are treated as "modified", when
+'merge.update()' is aborted before 'merge.recordupdates()' (= parents
+aren't changed), even if none of mode, size and timestamp of them
+isn't changed on the filesystem (see also issue4583).
+
+  $ cat > $TESTTMP/abort.py <<EOF
+  > # emulate aborting before "recordupdates()". in this case, files
+  > # are changed without updating dirstate
+  > from mercurial import extensions, merge, util
+  > def applyupdates(orig, *args, **kwargs):
+  >     orig(*args, **kwargs)
+  >     raise util.Abort('intentional aborting')
+  > def extsetup(ui):
+  >     extensions.wrapfunction(merge, "applyupdates", applyupdates)
+  > EOF
+
+  $ cat >> .hg/hgrc <<EOF
+  > [fakedirstatewritetime]
+  > # emulate invoking dirstate.write() via repo.status()
+  > # at 2000-01-01 00:00
+  > fakenow = 200001010000
+  > EOF
+
+(file gotten from other revision)
+
+  $ hg update -q -C 2
+  $ echo 'THIS IS FILE B5' > b
+  $ hg commit -m 'commit #5'
+
+  $ hg update -q -C 3
+  $ cat b
+  This is file b1
+  $ touch -t 200001010000 b
+  $ hg debugrebuildstate
+
+  $ cat >> .hg/hgrc <<EOF
+  > [extensions]
+  > fakedirstatewritetime = $TESTDIR/fakedirstatewritetime.py
+  > abort = $TESTTMP/abort.py
+  > EOF
+  $ hg merge 5
+  abort: intentional aborting
+  [255]
+  $ cat >> .hg/hgrc <<EOF
+  > [extensions]
+  > fakedirstatewritetime = !
+  > abort = !
+  > EOF
+
+  $ cat b
+  THIS IS FILE B5
+  $ touch -t 200001010000 b
+  $ hg status -A b
+  M b
+
+(file merged from other revision)
+
+  $ hg update -q -C 3
+  $ echo 'this is file b6' > b
+  $ hg commit -m 'commit #6'
+  created new head
+
+  $ cat b
+  this is file b6
+  $ touch -t 200001010000 b
+  $ hg debugrebuildstate
+
+  $ cat >> .hg/hgrc <<EOF
+  > [extensions]
+  > fakedirstatewritetime = $TESTDIR/fakedirstatewritetime.py
+  > abort = $TESTTMP/abort.py
+  > EOF
+  $ hg merge --tool internal:other 5
+  abort: intentional aborting
+  [255]
+  $ cat >> .hg/hgrc <<EOF
+  > [extensions]
+  > fakedirstatewritetime = !
+  > abort = !
+  > EOF
+
+  $ cat b
+  THIS IS FILE B5
+  $ touch -t 200001010000 b
+  $ hg status -A b
+  M b
+
   $ cd ..

--- a/tests/test-revert.t	Wed Jul 08 17:01:09 2015 +0900
+++ b/tests/test-revert.t	Wed Jul 08 17:01:09 2015 +0900
@@ -175,6 +175,46 @@
   executable
 #endif
 
+Test that files reverted to other than the parent are treated as
+"modified", even if none of mode, size and timestamp of it isn't
+changed on the filesystem (see also issue4583).
+
+  $ echo 321 > e
+  $ hg diff --git
+  diff --git a/e b/e
+  --- a/e
+  +++ b/e
+  @@ -1,1 +1,1 @@
+  -123
+  +321
+  $ hg commit -m 'ambiguity from size'
+
+  $ cat e
+  321
+  $ touch -t 200001010000 e
+  $ hg debugrebuildstate
+
+  $ cat >> .hg/hgrc <<EOF
+  > [fakedirstatewritetime]
+  > # emulate invoking dirstate.write() via repo.status()
+  > # at 2000-01-01 00:00
+  > fakenow = 200001010000
+  > 
+  > [extensions]
+  > fakedirstatewritetime = $TESTDIR/fakedirstatewritetime.py
+  > EOF
+  $ hg revert -r 0 e
+  $ cat >> .hg/hgrc <<EOF
+  > [extensions]
+  > fakedirstatewritetime = !
+  > EOF
+
+  $ cat e
+  123
+  $ touch -t 200001010000 e
+  $ hg status -A e
+  M e
+
   $ cd ..
 
 

--- a/tests/test-subrepo.t	Wed Jul 08 17:01:09 2015 +0900
+++ b/tests/test-subrepo.t	Wed Jul 08 17:01:09 2015 +0900
@@ -939,14 +939,32 @@
 
 test if untracked file is not overwritten
 
+(this also tests that updated .hgsubstate is treated as "modified",
+when 'merge.update()' is aborted before 'merge.recordupdates()', even
+if none of mode, size and timestamp of it isn't changed on the
+filesystem (see also issue4583))
+
   $ echo issue3276_ok > repo/s/b
   $ hg -R repo2 push -f -q
   $ touch -t 200001010000 repo/.hgsubstate
-  $ hg -R repo status --config debug.dirstate.delaywrite=2 repo/.hgsubstate
+
+  $ cat >> repo/.hg/hgrc <<EOF
+  > [fakedirstatewritetime]
+  > # emulate invoking dirstate.write() via repo.status()
+  > # at 2000-01-01 00:00
+  > fakenow = 200001010000
+  > 
+  > [extensions]
+  > fakedirstatewritetime = $TESTDIR/fakedirstatewritetime.py
+  > EOF
   $ hg -R repo update
   b: untracked file differs
   abort: untracked files in working directory differ from files in requested revision (in subrepo s)
   [255]
+  $ cat >> repo/.hg/hgrc <<EOF
+  > [extensions]
+  > fakedirstatewritetime = !
+  > EOF
 
   $ cat repo/s/b
   issue3276_ok