view tests/test-journal.t @ 44118:f81c17ec303c

hgdemandimport: apply lazy module loading to sys.meta_path finders

Python's `sys.meta_path` finders are the primary objects whose job it
is to find a module at import time. When `import` is called, Python
iterates objects in this list and calls `o.find_spec(...)` to find
a `ModuleSpec` (or None if the module couldn't be found by that
finder). If no meta path finder can find a module, import fails.

One of the default meta path finders is `PathFinder`. Its job is to
import modules from the filesystem and is probably the most important
importer. This finder looks at `sys.path` and `sys.path_hooks` to do
its job.

The `ModuleSpec` returned by `MetaPathImporter.find_spec()` has a
`loader` attribute, which defines the concrete module loader to use.
`sys.path_hooks` is a hook point for teaching `PathFinder` to
instantiate custom loader types.

Previously, we injected a custom `sys.path_hook` that told `PathFinder`
to wrap the default loaders with a loader that creates a module object
that is lazy.

This approach worked. But its main limitation was that it only applied
to the `PathFinder` meta path importer. There are other meta path
importers that are registered. And in the case of PyOxidizer loading
modules from memory, `PathFinder` doesn't come into play since
PyOxidizer's own meta path importer was handling all imports.

This commit changes our approach to lazy module loading by proxying
all meta path importers. Specifically, we overload the `find_spec()`
method to swap in a wrapped loader on the `ModuleSpec` before it
is returned. The end result of this is all meta path importers should
be lazy.

As much as I would have loved to utilize .__class__ manipulation to
achieve this, some meta path importers are implemented in C/Rust
in such a way that they cannot be monkeypatched. This is why we
use __getattribute__ to define a proxy.

Also, this change could theoretically open us up to regressions in
meta path importers whose loader is creating module objects which
can't be monkeypatched. But I'm not aware of any of these in the
wild. So I think we'll be safe.

According to hyperfine, this change yields a decent startup time win of
5-6ms:

```
Benchmark #1: ~/.pyenv/versions/3.6.10/bin/python ./hg version
  Time (mean ± σ):      86.8 ms ±   0.5 ms    [User: 78.0 ms, System: 8.7 ms]
  Range (min … max):    86.0 ms …  89.1 ms    50 runs

  Time (mean ± σ):      81.1 ms ±   2.7 ms    [User: 74.5 ms, System: 6.5 ms]
  Range (min … max):    77.8 ms …  90.5 ms    50 runs

Benchmark #2: ~/.pyenv/versions/3.7.6/bin/python ./hg version
  Time (mean ± σ):      78.9 ms ±   0.6 ms    [User: 70.2 ms, System: 8.7 ms]
  Range (min … max):    78.1 ms …  81.2 ms    50 runs

  Time (mean ± σ):      73.4 ms ±   0.6 ms    [User: 65.3 ms, System: 8.0 ms]
  Range (min … max):    72.4 ms …  75.7 ms    50 runs

Benchmark #3: ~/.pyenv/versions/3.8.1/bin/python ./hg version
  Time (mean ± σ):      78.1 ms ±   0.6 ms    [User: 70.2 ms, System: 7.9 ms]
  Range (min … max):    77.4 ms …  80.9 ms    50 runs

  Time (mean ± σ):      72.1 ms ±   0.4 ms    [User: 64.4 ms, System: 7.6 ms]
  Range (min … max):    71.4 ms …  74.1 ms    50 runs
```

Differential Revision: https://phab.mercurial-scm.org/D7954

Tests for the journal extension; records bookmark locations.

  $ cat >> testmocks.py << EOF
  > # mock out procutil.getuser() and util.makedate() to supply testable values
  > import os
  > from mercurial import pycompat, util
  > from mercurial.utils import dateutil, procutil
  > def mockgetuser():
  >     return b'foobar'
  > 
  > def mockmakedate():
  >     filename = os.path.join(os.environ['TESTTMP'], 'testtime')
  >     try:
  >         with open(filename, 'rb') as timef:
  >             time = float(timef.read()) + 1
  >     except IOError:
  >         time = 0.0
  >     with open(filename, 'wb') as timef:
  >         timef.write(pycompat.bytestr(time))
  >     return (time, 0)
  > 
  > procutil.getuser = mockgetuser
  > dateutil.makedate = mockmakedate
  > EOF

  $ cat >> $HGRCPATH << EOF
  > [extensions]
  > journal=
  > testmocks=`pwd`/testmocks.py
  > EOF

Setup repo

  $ hg init repo
  $ cd repo

Test empty journal

  $ hg journal
  previous locations of '.':
  no recorded locations
  $ hg journal foo
  previous locations of 'foo':
  no recorded locations

Test that working copy changes are tracked

  $ echo a > a
  $ hg commit -Aqm a
  $ hg journal
  previous locations of '.':
  cb9a9f314b8b  commit -Aqm a
  $ echo b > a
  $ hg commit -Aqm b
  $ hg journal
  previous locations of '.':
  1e6c11564562  commit -Aqm b
  cb9a9f314b8b  commit -Aqm a
  $ hg up 0
  1 files updated, 0 files merged, 0 files removed, 0 files unresolved
  $ hg journal
  previous locations of '.':
  cb9a9f314b8b  up 0
  1e6c11564562  commit -Aqm b
  cb9a9f314b8b  commit -Aqm a

Test that bookmarks are tracked

  $ hg book -r tip bar
  $ hg journal bar
  previous locations of 'bar':
  1e6c11564562  book -r tip bar
  $ hg book -f bar
  $ hg journal bar
  previous locations of 'bar':
  cb9a9f314b8b  book -f bar
  1e6c11564562  book -r tip bar
  $ hg up
  1 files updated, 0 files merged, 0 files removed, 0 files unresolved
  updating bookmark bar
  $ hg journal bar
  previous locations of 'bar':
  1e6c11564562  up
  cb9a9f314b8b  book -f bar
  1e6c11564562  book -r tip bar

Test that bookmarks and working copy tracking is not mixed

  $ hg journal
  previous locations of '.':
  1e6c11564562  up
  cb9a9f314b8b  up 0
  1e6c11564562  commit -Aqm b
  cb9a9f314b8b  commit -Aqm a

Test that you can list all entries as well as limit the list or filter on them

  $ hg book -r tip baz
  $ hg journal --all
  previous locations of the working copy and bookmarks:
  1e6c11564562  baz       book -r tip baz
  1e6c11564562  bar       up
  1e6c11564562  .         up
  cb9a9f314b8b  bar       book -f bar
  1e6c11564562  bar       book -r tip bar
  cb9a9f314b8b  .         up 0
  1e6c11564562  .         commit -Aqm b
  cb9a9f314b8b  .         commit -Aqm a
  $ hg journal --limit 2
  previous locations of '.':
  1e6c11564562  up
  cb9a9f314b8b  up 0
  $ hg journal bar
  previous locations of 'bar':
  1e6c11564562  up
  cb9a9f314b8b  book -f bar
  1e6c11564562  book -r tip bar
  $ hg journal foo
  previous locations of 'foo':
  no recorded locations
  $ hg journal .
  previous locations of '.':
  1e6c11564562  up
  cb9a9f314b8b  up 0
  1e6c11564562  commit -Aqm b
  cb9a9f314b8b  commit -Aqm a
  $ hg journal "re:ba."
  previous locations of 're:ba.':
  1e6c11564562  baz       book -r tip baz
  1e6c11564562  bar       up
  cb9a9f314b8b  bar       book -f bar
  1e6c11564562  bar       book -r tip bar

Test that verbose, JSON, template and commit output work

  $ hg journal --verbose --all
  previous locations of the working copy and bookmarks:
  000000000000 -> 1e6c11564562 foobar    baz      1970-01-01 00:00 +0000  book -r tip baz
  cb9a9f314b8b -> 1e6c11564562 foobar    bar      1970-01-01 00:00 +0000  up
  cb9a9f314b8b -> 1e6c11564562 foobar    .        1970-01-01 00:00 +0000  up
  1e6c11564562 -> cb9a9f314b8b foobar    bar      1970-01-01 00:00 +0000  book -f bar
  000000000000 -> 1e6c11564562 foobar    bar      1970-01-01 00:00 +0000  book -r tip bar
  1e6c11564562 -> cb9a9f314b8b foobar    .        1970-01-01 00:00 +0000  up 0
  cb9a9f314b8b -> 1e6c11564562 foobar    .        1970-01-01 00:00 +0000  commit -Aqm b
  000000000000 -> cb9a9f314b8b foobar    .        1970-01-01 00:00 +0000  commit -Aqm a
  $ hg journal --verbose -Tjson
  [
   {
    "command": "up",
    "date": [5, 0],
    "name": ".",
    "newnodes": ["1e6c11564562b4ed919baca798bc4338bd299d6a"],
    "oldnodes": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"],
    "user": "foobar"
   },
   {
    "command": "up 0",
    "date": [2, 0],
    "name": ".",
    "newnodes": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"],
    "oldnodes": ["1e6c11564562b4ed919baca798bc4338bd299d6a"],
    "user": "foobar"
   },
   {
    "command": "commit -Aqm b",
    "date": [1, 0],
    "name": ".",
    "newnodes": ["1e6c11564562b4ed919baca798bc4338bd299d6a"],
    "oldnodes": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"],
    "user": "foobar"
   },
   {
    "command": "commit -Aqm a",
    "date": [0, 0],
    "name": ".",
    "newnodes": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"],
    "oldnodes": ["0000000000000000000000000000000000000000"],
    "user": "foobar"
   }
  ]

  $ cat <<EOF >> $HGRCPATH
  > [templates]
  > j = "{oldnodes % '{node|upper}'} -> {newnodes % '{node|upper}'}
  >      - user: {user}
  >      - command: {command}
  >      - date: {date|rfc3339date}
  >      - newnodes: {newnodes}
  >      - oldnodes: {oldnodes}
  >      "
  > EOF
  $ hg journal -Tj -l1
  previous locations of '.':
  CB9A9F314B8B07BA71012FCDBC544B5A4D82FF5B -> 1E6C11564562B4ED919BACA798BC4338BD299D6A
  - user: foobar
  - command: up
  - date: 1970-01-01T00:00:05+00:00
  - newnodes: 1e6c11564562b4ed919baca798bc4338bd299d6a
  - oldnodes: cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b

  $ hg journal --commit
  previous locations of '.':
  1e6c11564562  up
  changeset:   1:1e6c11564562
  bookmark:    bar
  bookmark:    baz
  tag:         tip
  user:        test
  date:        Thu Jan 01 00:00:00 1970 +0000
  summary:     b
  
  cb9a9f314b8b  up 0
  changeset:   0:cb9a9f314b8b
  user:        test
  date:        Thu Jan 01 00:00:00 1970 +0000
  summary:     a
  
  1e6c11564562  commit -Aqm b
  changeset:   1:1e6c11564562
  bookmark:    bar
  bookmark:    baz
  tag:         tip
  user:        test
  date:        Thu Jan 01 00:00:00 1970 +0000
  summary:     b
  
  cb9a9f314b8b  commit -Aqm a
  changeset:   0:cb9a9f314b8b
  user:        test
  date:        Thu Jan 01 00:00:00 1970 +0000
  summary:     a
  

  $ hg journal --commit -Tjson
  [
   {
    "changesets": [{"bookmarks": ["bar", "baz"], "branch": "default", "date": [0, 0], "desc": "b", "node": "1e6c11564562b4ed919baca798bc4338bd299d6a", "parents": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"], "phase": "draft", "rev": 1, "tags": ["tip"], "user": "test"}],
    "command": "up",
    "date": [5, 0],
    "name": ".",
    "newnodes": ["1e6c11564562b4ed919baca798bc4338bd299d6a"],
    "oldnodes": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"],
    "user": "foobar"
   },
   {
    "changesets": [{"bookmarks": [], "branch": "default", "date": [0, 0], "desc": "a", "node": "cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b", "parents": ["0000000000000000000000000000000000000000"], "phase": "draft", "rev": 0, "tags": [], "user": "test"}],
    "command": "up 0",
    "date": [2, 0],
    "name": ".",
    "newnodes": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"],
    "oldnodes": ["1e6c11564562b4ed919baca798bc4338bd299d6a"],
    "user": "foobar"
   },
   {
    "changesets": [{"bookmarks": ["bar", "baz"], "branch": "default", "date": [0, 0], "desc": "b", "node": "1e6c11564562b4ed919baca798bc4338bd299d6a", "parents": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"], "phase": "draft", "rev": 1, "tags": ["tip"], "user": "test"}],
    "command": "commit -Aqm b",
    "date": [1, 0],
    "name": ".",
    "newnodes": ["1e6c11564562b4ed919baca798bc4338bd299d6a"],
    "oldnodes": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"],
    "user": "foobar"
   },
   {
    "changesets": [{"bookmarks": [], "branch": "default", "date": [0, 0], "desc": "a", "node": "cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b", "parents": ["0000000000000000000000000000000000000000"], "phase": "draft", "rev": 0, "tags": [], "user": "test"}],
    "command": "commit -Aqm a",
    "date": [0, 0],
    "name": ".",
    "newnodes": ["cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b"],
    "oldnodes": ["0000000000000000000000000000000000000000"],
    "user": "foobar"
   }
  ]

  $ hg journal --commit \
  > -T'command: {command}\n{changesets % " rev: {rev}\n children: {children}\n"}'
  previous locations of '.':
  command: up
   rev: 1
   children: 
  command: up 0
   rev: 0
   children: 1:1e6c11564562
  command: commit -Aqm b
   rev: 1
   children: 
  command: commit -Aqm a
   rev: 0
   children: 1:1e6c11564562

Test for behaviour on unexpected storage version information

  $ printf '42\0' > .hg/namejournal
  $ hg journal
  previous locations of '.':
  abort: unknown journal file version '42'
  [255]
  $ hg book -r tip doomed
  unsupported journal file version '42'