Show More
@@ -1,129 +1,141 b'' | |||
|
1 | 1 | # pull_logger.py - Logs pulls to a JSON-line file in the repo's VFS. |
|
2 | 2 | # |
|
3 | 3 | # Copyright 2022 Pacien TRAN-GIRARD <pacien.trangirard@pacien.net> |
|
4 | 4 | # |
|
5 | 5 | # This software may be used and distributed according to the terms of the |
|
6 | 6 | # GNU General Public License version 2 or any later version. |
|
7 | 7 | |
|
8 | 8 | |
|
9 | 9 | '''logs pull parameters to a file |
|
10 | 10 | |
|
11 | 11 | This extension logs the pull parameters, i.e. the remote and common heads, |
|
12 | 12 | when pulling from the local repository. |
|
13 | 13 | |
|
14 | 14 | The collected data should give an idea of the state of a pair of repositories |
|
15 | 15 | and allow replaying past synchronisations between them. This is particularly |
|
16 | 16 | useful for working on data exchange, bundling and caching-related |
|
17 | 17 | optimisations. |
|
18 | 18 | |
|
19 | 19 | The record is a JSON-line file located in the repository's VFS at |
|
20 | 20 | .hg/pull_log.jsonl. |
|
21 | 21 | |
|
22 | 22 | Log write failures are not considered fatal: log writes may be skipped for any |
|
23 | 23 | reason such as insufficient storage or a timeout. |
|
24 | 24 | |
|
25 | Some basic log file rotation can be enabled by setting 'rotate-size' to a value | |
|
26 | greater than 0. This causes the current log file to be moved to | |
|
27 | .hg/pull_log.jsonl.rotated when this threshold is met, discarding any | |
|
28 | previously rotated log file. | |
|
29 | ||
|
25 | 30 | The timeouts of the exclusive lock used when writing to the lock file can be |
|
26 | 31 | configured through the 'timeout.lock' and 'timeout.warn' options of this |
|
27 | 32 | plugin. Those are not expected to be held for a significant time in practice.:: |
|
28 | 33 | |
|
29 | 34 | [pull-logger] |
|
30 | 35 | timeout.lock = 300 |
|
31 | 36 | timeout.warn = 100 |
|
32 | ||
|
33 | Note: there is no automatic log rotation and the size of the log is not capped. | |
|
37 | rotate-size = 1kb | |
|
34 | 38 | ''' |
|
35 | 39 | |
|
36 | 40 | |
|
37 | 41 | import json |
|
38 | 42 | import time |
|
39 | 43 | |
|
40 | 44 | from mercurial.i18n import _ |
|
41 | 45 | from mercurial.utils import stringutil |
|
42 | 46 | from mercurial import ( |
|
43 | 47 | error, |
|
44 | 48 | extensions, |
|
45 | 49 | lock, |
|
46 | 50 | registrar, |
|
47 | 51 | wireprotov1server, |
|
48 | 52 | ) |
|
49 | 53 | |
|
50 | 54 | EXT_NAME = b'pull-logger' |
|
51 | 55 | EXT_VERSION_CODE = 0 |
|
52 | 56 | |
|
53 | 57 | LOG_FILE = b'pull_log.jsonl' |
|
58 | OLD_LOG_FILE = LOG_FILE + b'.rotated' | |
|
54 | 59 | LOCK_NAME = LOG_FILE + b'.lock' |
|
55 | 60 | |
|
56 | 61 | configtable = {} |
|
57 | 62 | configitem = registrar.configitem(configtable) |
|
58 | 63 | configitem(EXT_NAME, b'timeout.lock', default=600) |
|
59 | 64 | configitem(EXT_NAME, b'timeout.warn', default=120) |
|
65 | configitem(EXT_NAME, b'rotate-size', default=b'100MB') | |
|
60 | 66 | |
|
61 | 67 | |
|
62 | 68 | def wrap_getbundle(orig, repo, proto, others, *args, **kwargs): |
|
63 | 69 | heads, common = extract_pull_heads(others) |
|
64 | 70 | log_entry = { |
|
65 | 71 | 'timestamp': time.time(), |
|
66 | 72 | 'logger_version': EXT_VERSION_CODE, |
|
67 | 73 | 'heads': sorted(heads), |
|
68 | 74 | 'common': sorted(common), |
|
69 | 75 | } |
|
70 | 76 | |
|
71 | 77 | try: |
|
72 | 78 | write_to_log(repo, log_entry) |
|
73 | 79 | except (IOError, error.LockError) as err: |
|
74 | 80 | msg = stringutil.forcebytestr(err) |
|
75 | 81 | repo.ui.warn(_(b'unable to append to pull log: %s\n') % msg) |
|
76 | 82 | |
|
77 | 83 | return orig(repo, proto, others, *args, **kwargs) |
|
78 | 84 | |
|
79 | 85 | |
|
80 | 86 | def extract_pull_heads(bundle_args): |
|
81 | 87 | opts = wireprotov1server.options( |
|
82 | 88 | b'getbundle', |
|
83 | 89 | wireprotov1server.wireprototypes.GETBUNDLE_ARGUMENTS.keys(), |
|
84 | 90 | bundle_args.copy(), # this call consumes the args destructively |
|
85 | 91 | ) |
|
86 | 92 | |
|
87 | 93 | heads = opts.get(b'heads', b'').decode('utf-8').split(' ') |
|
88 | 94 | common = opts.get(b'common', b'').decode('utf-8').split(' ') |
|
89 | 95 | return (heads, common) |
|
90 | 96 | |
|
91 | 97 | |
|
92 | 98 | def write_to_log(repo, entry): |
|
93 | 99 | locktimeout = repo.ui.configint(EXT_NAME, b'timeout.lock') |
|
94 | 100 | lockwarntimeout = repo.ui.configint(EXT_NAME, b'timeout.warn') |
|
101 | rotatesize = repo.ui.configbytes(EXT_NAME, b'rotate-size') | |
|
95 | 102 | |
|
96 | 103 | with lock.trylock( |
|
97 | 104 | ui=repo.ui, |
|
98 | 105 | vfs=repo.vfs, |
|
99 | 106 | lockname=LOCK_NAME, |
|
100 | 107 | timeout=locktimeout, |
|
101 | 108 | warntimeout=lockwarntimeout, |
|
102 | 109 | ): |
|
110 | if rotatesize > 0 and repo.vfs.exists(LOG_FILE): | |
|
111 | if repo.vfs.stat(LOG_FILE).st_size >= rotatesize: | |
|
112 | repo.vfs.rename(LOG_FILE, OLD_LOG_FILE) | |
|
113 | ||
|
103 | 114 | with repo.vfs.open(LOG_FILE, b'a+') as logfile: |
|
104 | 115 | serialised = json.dumps(entry, sort_keys=True) |
|
105 | 116 | logfile.write(serialised.encode('utf-8')) |
|
106 | 117 | logfile.write(b'\n') |
|
107 | 118 | logfile.flush() |
|
108 | 119 | |
|
109 | 120 | |
|
110 | 121 | def reposetup(ui, repo): |
|
111 | 122 | if repo.local(): |
|
112 | 123 | repo._wlockfreeprefix.add(LOG_FILE) |
|
124 | repo._wlockfreeprefix.add(OLD_LOG_FILE) | |
|
113 | 125 | |
|
114 | 126 | |
|
115 | 127 | def uisetup(ui): |
|
116 | 128 | del wireprotov1server.commands[b'getbundle'] |
|
117 | 129 | decorator = wireprotov1server.wireprotocommand( |
|
118 | 130 | name=b'getbundle', |
|
119 | 131 | args=b'*', |
|
120 | 132 | permission=b'pull', |
|
121 | 133 | ) |
|
122 | 134 | |
|
123 | 135 | extensions.wrapfunction( |
|
124 | 136 | container=wireprotov1server, |
|
125 | 137 | funcname='getbundle', |
|
126 | 138 | wrapper=wrap_getbundle, |
|
127 | 139 | ) |
|
128 | 140 | |
|
129 | 141 | decorator(wireprotov1server.getbundle) |
@@ -1,61 +1,78 b'' | |||
|
1 | 1 | Check that the pull logger plugins logs pulls |
|
2 | 2 | ============================================= |
|
3 | 3 | |
|
4 | 4 | Enable the extension |
|
5 | 5 | |
|
6 | 6 | $ echo "[extensions]" >> $HGRCPATH |
|
7 | 7 | $ echo "pull-logger = $TESTDIR/../contrib/pull_logger.py" >> $HGRCPATH |
|
8 | 8 | |
|
9 | 9 | |
|
10 | 10 | Check the format of the generated log entries, with a bunch of elements in the |
|
11 | 11 | common and heads set |
|
12 | 12 | |
|
13 | 13 | $ hg init server |
|
14 | 14 | $ hg -R server debugbuilddag '.*2+2' |
|
15 | 15 | $ hg clone ssh://user@dummy/server client --rev 0 |
|
16 | 16 | adding changesets |
|
17 | 17 | adding manifests |
|
18 | 18 | adding file changes |
|
19 | 19 | added 1 changesets with 0 changes to 0 files |
|
20 | 20 | new changesets 1ea73414a91b |
|
21 | 21 | updating to branch default |
|
22 | 22 | 0 files updated, 0 files merged, 0 files removed, 0 files unresolved |
|
23 | 23 | $ tail -1 server/.hg/pull_log.jsonl |
|
24 | 24 | {"common": ["0000000000000000000000000000000000000000"], "heads": ["1ea73414a91b0920940797d8fc6a11e447f8ea1e"], "logger_version": 0, "timestamp": *} (glob) |
|
25 | 25 | $ hg -R client pull --rev 1 --rev 2 |
|
26 | 26 | pulling from ssh://user@dummy/server |
|
27 | 27 | searching for changes |
|
28 | 28 | adding changesets |
|
29 | 29 | adding manifests |
|
30 | 30 | adding file changes |
|
31 | 31 | added 2 changesets with 0 changes to 0 files (+1 heads) |
|
32 | 32 | new changesets d8736c3a2c84:fa28e81e283b |
|
33 | 33 | (run 'hg heads' to see heads, 'hg merge' to merge) |
|
34 | 34 | $ tail -1 server/.hg/pull_log.jsonl |
|
35 | 35 | {"common": ["1ea73414a91b0920940797d8fc6a11e447f8ea1e"], "heads": ["d8736c3a2c84ee759a2821385804bcb67f266ade", "fa28e81e283b3416de4d48ee0dd2d446e9e38d7c"], "logger_version": 0, "timestamp": *} (glob) |
|
36 | 36 | $ hg -R client pull --rev 2 --rev 3 |
|
37 | 37 | pulling from ssh://user@dummy/server |
|
38 | 38 | searching for changes |
|
39 | 39 | adding changesets |
|
40 | 40 | adding manifests |
|
41 | 41 | adding file changes |
|
42 | 42 | added 1 changesets with 0 changes to 0 files |
|
43 | 43 | new changesets 944641ddcaef |
|
44 | 44 | (run 'hg update' to get a working copy) |
|
45 | 45 | $ tail -1 server/.hg/pull_log.jsonl |
|
46 | 46 | {"common": ["1ea73414a91b0920940797d8fc6a11e447f8ea1e", "fa28e81e283b3416de4d48ee0dd2d446e9e38d7c"], "heads": ["944641ddcaef174df7ce1bc2751a5f165129778b", "fa28e81e283b3416de4d48ee0dd2d446e9e38d7c"], "logger_version": 0, "timestamp": *} (glob) |
|
47 | 47 | |
|
48 | 48 | |
|
49 | 49 | Check the number of entries generated in the log when pulling from multiple |
|
50 | 50 | clients at the same time |
|
51 | 51 | |
|
52 | 52 | $ rm -f server/.hg/pull_log.jsonl |
|
53 | 53 | $ for i in $($TESTDIR/seq.py 32); do |
|
54 | 54 | > hg clone ssh://user@dummy/server client_$i --rev 0 |
|
55 | 55 | > done > /dev/null |
|
56 | 56 | $ for i in $($TESTDIR/seq.py 32); do |
|
57 | 57 | > hg -R client_$i pull --rev 1 & |
|
58 | 58 | > done > /dev/null |
|
59 | 59 | $ wait |
|
60 | 60 | $ wc -l server/.hg/pull_log.jsonl |
|
61 | 61 | \s*64 .* (re) |
|
62 | ||
|
63 | ||
|
64 | Test log rotation when reaching some size threshold | |
|
65 | ||
|
66 | $ cat >> $HGRCPATH << EOF | |
|
67 | > [pull-logger] | |
|
68 | > rotate-size = 1kb | |
|
69 | > EOF | |
|
70 | ||
|
71 | $ rm -f server/.hg/pull_log.jsonl | |
|
72 | $ for i in $($TESTDIR/seq.py 10); do | |
|
73 | > hg -R client pull --rev 1 | |
|
74 | > done > /dev/null | |
|
75 | $ wc -l server/.hg/pull_log.jsonl | |
|
76 | \s*3 .* (re) | |
|
77 | $ wc -l server/.hg/pull_log.jsonl.rotated | |
|
78 | \s*7 .* (re) |
General Comments 0
You need to be logged in to leave comments.
Login now