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