Mercurial > public > mercurial-scm > hg
comparison tests/testlib/persistent-nodemap-race-ext.py @ 48038:52018f8ef020 stable
persistent-nodemap: introduce a test to highlight possible race
Weakness in the current file caching of the changelog means that a writer can
end up using an outdated docket. This might result in "committed"
persistent-nodemap data from a previous writer to be overwritten by a later
writer. This break the strong "append only" assumption of the persistent nodemap
and can result in confused reader.
The race windows are quite narrow. See the test documentation for details.
The issues is fixed in the next changeset.
Differential Revision: https://phab.mercurial-scm.org/D11481
author | Pierre-Yves David <pierre-yves.david@octobus.net> |
---|---|
date | Tue, 21 Sep 2021 21:18:50 +0200 |
parents | |
children | 6000f5b25c9b |
comparison
equal
deleted
inserted
replaced
48037:016081cca1fb | 48038:52018f8ef020 |
---|---|
1 """Create the race condition for issue6554 | |
2 | |
3 The persistent nodemap issues had an issue where a second writer could | |
4 overwrite the data that a previous write just wrote. The would break the append | |
5 only garantee of the persistent nodemap and could confuse reader. This | |
6 extensions create all the necessary synchronisation point to the race condition | |
7 to happen. | |
8 | |
9 It involves 3 process <LEFT> (a writer) <RIGHT> (a writer) and <READER> | |
10 | |
11 [1] <LEFT> take the lock and start a transaction | |
12 [2] <LEFT> updated `00changelog.i` with the new data | |
13 [3] <RIGHT> reads: | |
14 - the new changelog index `00changelog.i` | |
15 - the old `00changelog.n` | |
16 [4] <LEFT> update the persistent nodemap: | |
17 - writing new data from the last valid offset | |
18 - updating the docket (00changelog.n) | |
19 [5] <LEFT> release the lock | |
20 [6] <RIGHT> grab the lock and run `repo.invalidate` | |
21 [7] <READER> reads: | |
22 - the changelog index after <LEFT> write | |
23 - the nodemap docket after <LEFT> write | |
24 [8] <RIGHT> reload the changelog since `00changelog.n` changed | |
25 /!\ This is the faulty part in issue 6554, the outdated docket is kept | |
26 [9] <RIGHT> write: | |
27 - the changelog index (00changelog.i) | |
28 - the nodemap data (00changelog*.nd) | |
29 /!\ if the outdated docket is used, the write starts from the same ofset | |
30 /!\ as in [4], overwriting data that <LEFT> wrote in step [4]. | |
31 - the nodemap docket (00changelog.n) | |
32 [10] <READER> reads the nodemap data from `00changelog*.nd` | |
33 /!\ if step [9] was wrong, the data matching the docket that <READER> | |
34 /!\ loaded have been overwritten and the expected root-nodes is no longer | |
35 /!\ valid. | |
36 """ | |
37 | |
38 from __future__ import print_function | |
39 | |
40 import os | |
41 | |
42 from mercurial.revlogutils.constants import KIND_CHANGELOG | |
43 | |
44 from mercurial import ( | |
45 changelog, | |
46 encoding, | |
47 extensions, | |
48 localrepo, | |
49 node, | |
50 pycompat, | |
51 registrar, | |
52 testing, | |
53 util, | |
54 ) | |
55 | |
56 from mercurial.revlogutils import ( | |
57 nodemap as nodemaputil, | |
58 ) | |
59 | |
60 configtable = {} | |
61 configitem = registrar.configitem(configtable) | |
62 | |
63 configitem(b'devel', b'nodemap-race.role', default=None) | |
64 | |
65 cmdtable = {} | |
66 command = registrar.command(cmdtable) | |
67 | |
68 LEFT = b'left' | |
69 RIGHT = b'right' | |
70 READER = b'reader' | |
71 | |
72 SYNC_DIR = os.path.join(encoding.environ[b'TESTTMP'], b'sync-files') | |
73 | |
74 # mark the end of step [1] | |
75 FILE_LEFT_LOCKED = os.path.join(SYNC_DIR, b'left-locked') | |
76 # mark that step [3] is ready to run. | |
77 FILE_RIGHT_READY_TO_LOCK = os.path.join(SYNC_DIR, b'right-ready-to-lock') | |
78 | |
79 # mark the end of step [2] | |
80 FILE_LEFT_CL_DATA_WRITE = os.path.join(SYNC_DIR, b'left-data') | |
81 # mark the end of step [4] | |
82 FILE_LEFT_CL_NODEMAP_WRITE = os.path.join(SYNC_DIR, b'left-nodemap') | |
83 # mark the end of step [3] | |
84 FILE_RIGHT_CL_NODEMAP_READ = os.path.join(SYNC_DIR, b'right-nodemap') | |
85 # mark that step [9] is read to run | |
86 FILE_RIGHT_CL_NODEMAP_PRE_WRITE = os.path.join( | |
87 SYNC_DIR, b'right-pre-nodemap-write' | |
88 ) | |
89 # mark that step [9] has run. | |
90 FILE_RIGHT_CL_NODEMAP_POST_WRITE = os.path.join( | |
91 SYNC_DIR, b'right-post-nodemap-write' | |
92 ) | |
93 # mark that step [7] is ready to run | |
94 FILE_READER_READY = os.path.join(SYNC_DIR, b'reader-ready') | |
95 # mark that step [7] has run | |
96 FILE_READER_READ_DOCKET = os.path.join(SYNC_DIR, b'reader-read-docket') | |
97 | |
98 | |
99 def _print(*args, **kwargs): | |
100 print(*args, **kwargs) | |
101 | |
102 | |
103 def _role(repo): | |
104 """find the role associated with the process""" | |
105 return repo.ui.config(b'devel', b'nodemap-race.role') | |
106 | |
107 | |
108 def wrap_changelog_finalize(orig, cl, tr): | |
109 """wrap the update of `00changelog.i` during transaction finalization | |
110 | |
111 This is useful for synchronisation before or after the file is updated on disk. | |
112 """ | |
113 role = getattr(tr, '_race_role', None) | |
114 if role == RIGHT: | |
115 print('right ready to write, waiting for reader') | |
116 testing.wait_file(FILE_READER_READY) | |
117 testing.write_file(FILE_RIGHT_CL_NODEMAP_PRE_WRITE) | |
118 testing.wait_file(FILE_READER_READ_DOCKET) | |
119 print('right proceeding with writing its changelog index and nodemap') | |
120 ret = orig(cl, tr) | |
121 print("finalized changelog write") | |
122 if role == LEFT: | |
123 testing.write_file(FILE_LEFT_CL_DATA_WRITE) | |
124 return ret | |
125 | |
126 | |
127 def wrap_persist_nodemap(orig, tr, revlog, *args, **kwargs): | |
128 """wrap the update of `00changelog.n` and `*.nd` during tr finalization | |
129 | |
130 This is useful for synchronisation before or after the files are updated on | |
131 disk. | |
132 """ | |
133 is_cl = revlog.target[0] == KIND_CHANGELOG | |
134 role = getattr(tr, '_race_role', None) | |
135 if is_cl: | |
136 if role == LEFT: | |
137 testing.wait_file(FILE_RIGHT_CL_NODEMAP_READ) | |
138 if is_cl: | |
139 print("persisting changelog nodemap") | |
140 print(" new data start at", revlog._nodemap_docket.data_length) | |
141 ret = orig(tr, revlog, *args, **kwargs) | |
142 if is_cl: | |
143 print("persisted changelog nodemap") | |
144 print_nodemap_details(revlog) | |
145 if role == LEFT: | |
146 testing.write_file(FILE_LEFT_CL_NODEMAP_WRITE) | |
147 elif role == RIGHT: | |
148 testing.write_file(FILE_RIGHT_CL_NODEMAP_POST_WRITE) | |
149 return ret | |
150 | |
151 | |
152 def print_nodemap_details(cl): | |
153 """print relevant information about the nodemap docket currently in memory""" | |
154 dkt = cl._nodemap_docket | |
155 print('docket-details:') | |
156 if dkt is None: | |
157 print(' <no-docket>') | |
158 return | |
159 print(' uid: ', pycompat.sysstr(dkt.uid)) | |
160 print(' actual-tip: ', cl.tiprev()) | |
161 print(' tip-rev: ', dkt.tip_rev) | |
162 print(' data-length:', dkt.data_length) | |
163 | |
164 | |
165 def wrap_persisted_data(orig, revlog): | |
166 """print some information about the nodemap information we just read | |
167 | |
168 Used by the <READER> process only. | |
169 """ | |
170 ret = orig(revlog) | |
171 if ret is not None: | |
172 docket, data = ret | |
173 file_path = nodemaputil._rawdata_filepath(revlog, docket) | |
174 file_path = revlog.opener.join(file_path) | |
175 file_size = os.path.getsize(file_path) | |
176 print('record-data-length:', docket.data_length) | |
177 print('actual-data-length:', len(data)) | |
178 print('file-actual-length:', file_size) | |
179 return ret | |
180 | |
181 | |
182 def sync_read(orig): | |
183 """used by <READER> to force the race window | |
184 | |
185 This make sure we read the docker from <LEFT> while reading the datafile | |
186 after <RIGHT> write. | |
187 """ | |
188 orig() | |
189 testing.write_file(FILE_READER_READ_DOCKET) | |
190 print('reader: nodemap docket read') | |
191 testing.wait_file(FILE_RIGHT_CL_NODEMAP_POST_WRITE) | |
192 | |
193 | |
194 def uisetup(ui): | |
195 class RacedRepo(localrepo.localrepository): | |
196 def lock(self, wait=True): | |
197 # make sure <RIGHT> as the "Wrong" information in memory before | |
198 # grabbing the lock | |
199 newlock = self._currentlock(self._lockref) is None | |
200 if newlock and _role(self) == LEFT: | |
201 cl = self.unfiltered().changelog | |
202 print_nodemap_details(cl) | |
203 elif newlock and _role(self) == RIGHT: | |
204 testing.write_file(FILE_RIGHT_READY_TO_LOCK) | |
205 print('nodemap-race: right side start of the locking sequence') | |
206 testing.wait_file(FILE_LEFT_LOCKED) | |
207 testing.wait_file(FILE_LEFT_CL_DATA_WRITE) | |
208 self.invalidate(clearfilecache=True) | |
209 print('nodemap-race: right side reading changelog') | |
210 cl = self.unfiltered().changelog | |
211 tiprev = cl.tiprev() | |
212 tip = cl.node(tiprev) | |
213 tiprev2 = cl.rev(tip) | |
214 if tiprev != tiprev2: | |
215 raise RuntimeError( | |
216 'bad tip -round-trip %d %d' % (tiprev, tiprev2) | |
217 ) | |
218 testing.write_file(FILE_RIGHT_CL_NODEMAP_READ) | |
219 print('nodemap-race: right side reading of changelog is done') | |
220 print_nodemap_details(cl) | |
221 testing.wait_file(FILE_LEFT_CL_NODEMAP_WRITE) | |
222 print('nodemap-race: right side ready to wait for the lock') | |
223 ret = super(RacedRepo, self).lock(wait=wait) | |
224 if newlock and _role(self) == LEFT: | |
225 print('nodemap-race: left side locked and ready to commit') | |
226 testing.write_file(FILE_LEFT_LOCKED) | |
227 testing.wait_file(FILE_RIGHT_READY_TO_LOCK) | |
228 cl = self.unfiltered().changelog | |
229 print_nodemap_details(cl) | |
230 elif newlock and _role(self) == RIGHT: | |
231 print('nodemap-race: right side locked and ready to commit') | |
232 cl = self.unfiltered().changelog | |
233 print_nodemap_details(cl) | |
234 return ret | |
235 | |
236 def transaction(self, *args, **kwargs): | |
237 # duck punch the role on the transaction to help other pieces of code | |
238 tr = super(RacedRepo, self).transaction(*args, **kwargs) | |
239 tr._race_role = _role(self) | |
240 return tr | |
241 | |
242 localrepo.localrepository = RacedRepo | |
243 | |
244 extensions.wrapfunction( | |
245 nodemaputil, 'persist_nodemap', wrap_persist_nodemap | |
246 ) | |
247 extensions.wrapfunction( | |
248 changelog.changelog, '_finalize', wrap_changelog_finalize | |
249 ) | |
250 | |
251 | |
252 def reposetup(ui, repo): | |
253 if _role(repo) == READER: | |
254 extensions.wrapfunction( | |
255 nodemaputil, 'persisted_data', wrap_persisted_data | |
256 ) | |
257 extensions.wrapfunction(nodemaputil, 'test_race_hook_1', sync_read) | |
258 | |
259 class ReaderRepo(repo.__class__): | |
260 @util.propertycache | |
261 def changelog(self): | |
262 print('reader ready to read the changelog, waiting for right') | |
263 testing.write_file(FILE_READER_READY) | |
264 testing.wait_file(FILE_RIGHT_CL_NODEMAP_PRE_WRITE) | |
265 return super(ReaderRepo, self).changelog | |
266 | |
267 repo.__class__ = ReaderRepo | |
268 | |
269 | |
270 @command(b'check-nodemap-race') | |
271 def cmd_check_nodemap_race(ui, repo): | |
272 """Run proper <READER> access in the race Windows and check nodemap content""" | |
273 repo = repo.unfiltered() | |
274 print('reader: reading changelog') | |
275 cl = repo.changelog | |
276 print('reader: changelog read') | |
277 print_nodemap_details(cl) | |
278 tip_rev = cl.tiprev() | |
279 tip_node = cl.node(tip_rev) | |
280 print('tip-rev: ', tip_rev) | |
281 print('tip-node:', node.short(tip_node).decode('ascii')) | |
282 print('node-rev:', cl.rev(tip_node)) | |
283 for r in cl.revs(): | |
284 n = cl.node(r) | |
285 try: | |
286 r2 = cl.rev(n) | |
287 except ValueError as exc: | |
288 print('error while checking revision:', r) | |
289 print(' ', exc) | |
290 return 1 | |
291 else: | |
292 if r2 != r: | |
293 print('revision %d is missing from the nodemap' % r) | |
294 return 1 |