Merge lp:~salgado/launchpad/nuke-debug-references into lp:launchpad
- nuke-debug-references
- Merge into devel
Proposed by
Guilherme Salgado
Status: | Merged |
---|---|
Merged at revision: | not available |
Proposed branch: | lp:~salgado/launchpad/nuke-debug-references |
Merge into: | lp:launchpad |
Diff against target: |
376 lines (+1/-305) 4 files modified
lib/canonical/config/schema-lazr.conf (+0/-16) lib/canonical/launchpad/webapp/configure.zcml (+0/-6) lib/canonical/launchpad/webapp/publication.py (+1/-98) lib/lp/bugs/doc/memory-debug.txt (+0/-185) |
To merge this branch: | bzr merge lp:~salgado/launchpad/nuke-debug-references |
Related bugs: |
Reviewer | Review Type | Date Requested | Status |
---|---|---|---|
Francis J. Lacoste (community) | Approve | ||
Review via email: mp+21673@code.launchpad.net |
Commit message
Description of the change
Remove debugReferences
To post a comment you must log in.
Preview Diff
[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1 | === modified file 'lib/canonical/config/schema-lazr.conf' |
2 | --- lib/canonical/config/schema-lazr.conf 2010-03-10 01:52:56 +0000 |
3 | +++ lib/canonical/config/schema-lazr.conf 2010-03-18 19:34:18 +0000 |
4 | @@ -601,22 +601,6 @@ |
5 | # datatype: integer |
6 | storm_cache_size: 500 |
7 | |
8 | - |
9 | -[debug] |
10 | -# Set this to true to compare memory and reference leaking |
11 | -# from one request to the next. Turning this to true without |
12 | -# setting the number of threads to 1 will give not-so-useful |
13 | -# results. |
14 | -references: False |
15 | - |
16 | -# File to keep the reference count into. |
17 | -references_scoreboard_file: /tmp/refcounts-scoreboard.txt |
18 | - |
19 | -# Log file where leaks will be reported. Actually, this log will contain |
20 | -# an entry for each request containing the time, the pageid and the increase |
21 | -# in refcounts and memory. |
22 | -references_leak_log: /tmp/references-leak.log |
23 | - |
24 | [diff] |
25 | # The maximum size in bytes to read from the librarian to make available in |
26 | # the web UI. 512k == 524288 bytes. |
27 | |
28 | === modified file 'lib/canonical/launchpad/webapp/configure.zcml' |
29 | --- lib/canonical/launchpad/webapp/configure.zcml 2010-03-16 05:08:47 +0000 |
30 | +++ lib/canonical/launchpad/webapp/configure.zcml 2010-03-18 19:34:18 +0000 |
31 | @@ -753,12 +753,6 @@ |
32 | handler="canonical.launchpad.webapp.adapter.break_main_thread_db_access" |
33 | /> |
34 | |
35 | - <!-- Make sure that the config is sane for references debugging. --> |
36 | - <subscriber |
37 | - for="zope.app.appsetup.IProcessStartingEvent" |
38 | - handler="canonical.launchpad.webapp.publication.debug_references_startup_check" |
39 | - /> |
40 | - |
41 | <!-- Set the default timeout function. --> |
42 | <subscriber |
43 | for="zope.app.appsetup.IProcessStartingEvent" |
44 | |
45 | === modified file 'lib/canonical/launchpad/webapp/publication.py' |
46 | --- lib/canonical/launchpad/webapp/publication.py 2010-03-04 22:42:07 +0000 |
47 | +++ lib/canonical/launchpad/webapp/publication.py 2010-03-18 19:34:18 +0000 |
48 | @@ -7,7 +7,6 @@ |
49 | 'LaunchpadBrowserPublication', |
50 | ] |
51 | |
52 | -import gc |
53 | import os |
54 | import re |
55 | import sys |
56 | @@ -18,7 +17,6 @@ |
57 | |
58 | from cProfile import Profile |
59 | from datetime import datetime |
60 | -from time import strftime |
61 | |
62 | import tickcount |
63 | import transaction |
64 | @@ -47,9 +45,7 @@ |
65 | import canonical.launchpad.webapp.adapter as da |
66 | |
67 | from canonical.config import config, dbconfig |
68 | -from canonical.mem import ( |
69 | - countsByType, deltaCounts, memory, mostRefs, printCounts, readCounts, |
70 | - resident) |
71 | +from canonical.mem import memory, resident |
72 | from canonical.launchpad.interfaces.launchpad import ILaunchpadCelebrities |
73 | from canonical.launchpad.readonly import is_read_only |
74 | from lp.registry.interfaces.person import ( |
75 | @@ -608,9 +604,6 @@ |
76 | |
77 | da.clear_request_started() |
78 | |
79 | - if config.debug.references: |
80 | - self.debugReferencesLeak(request) |
81 | - |
82 | # Maintain operational statistics. |
83 | if getattr(request, '_wants_retry', False): |
84 | OpStats.stats['retries'] += 1 |
85 | @@ -719,101 +712,11 @@ |
86 | vss_start, rss_start, vss_end, rss_end)) |
87 | log.close() |
88 | |
89 | - def debugReferencesLeak(self, request): |
90 | - """See what kind of references are increasing. |
91 | - |
92 | - This logs the current RSS and references count by types in a |
93 | - scoreboard file. If that file exists, we compare the current stats |
94 | - with the previous one and logs the increase along the current page id. |
95 | - |
96 | - Note that this only provides reliable results when only one thread is |
97 | - processing requests. |
98 | - """ |
99 | - gc.collect() |
100 | - current_rss = resident() |
101 | - current_garbage_count = len(gc.garbage) |
102 | - # Convert type to string, because that's what we get when reading |
103 | - # the old scoreboard. |
104 | - current_refs = [ |
105 | - (count, str(ref_type)) for count, ref_type in mostRefs(n=0)] |
106 | - # Add G as prefix to types on the garbage list. |
107 | - current_garbage = [ |
108 | - (count, 'G%s' % str(ref_type)) |
109 | - for count, ref_type in countsByType(gc.garbage, n=0)] |
110 | - scoreboard_path = config.debug.references_scoreboard_file |
111 | - |
112 | - # Read in previous scoreboard if it exists. |
113 | - if os.path.exists(scoreboard_path): |
114 | - scoreboard = open(scoreboard_path, 'r') |
115 | - try: |
116 | - stats = scoreboard.readline().split() |
117 | - prev_rss = int(stats[0].strip()) |
118 | - prev_garbage_count = int(stats[1].strip()) |
119 | - prev_refs = readCounts(scoreboard, '=== GARBAGE ===\n') |
120 | - prev_garbage = readCounts(scoreboard) |
121 | - finally: |
122 | - scoreboard.close() |
123 | - mem_leak = current_rss - prev_rss |
124 | - garbage_leak = current_garbage_count - prev_garbage_count |
125 | - delta_refs = list(deltaCounts(prev_refs, current_refs)) |
126 | - delta_refs.extend(deltaCounts(prev_garbage, current_garbage)) |
127 | - self.logReferencesLeak(request, mem_leak, delta_refs) |
128 | - |
129 | - # Save the current scoreboard. |
130 | - scoreboard = open(scoreboard_path, 'w') |
131 | - try: |
132 | - scoreboard.write("%d %d\n" % (current_rss, current_garbage_count)) |
133 | - printCounts(current_refs, scoreboard) |
134 | - scoreboard.write('=== GARBAGE ===\n') |
135 | - printCounts(current_garbage, scoreboard) |
136 | - finally: |
137 | - scoreboard.close() |
138 | - |
139 | - def logReferencesLeak(self, request, mem_leak, delta_refs): |
140 | - """Log the time, pageid, increase in RSS and increase in references. |
141 | - """ |
142 | - log = open(config.debug.references_leak_log, 'a') |
143 | - try: |
144 | - pageid = request._orig_env.get('launchpad.pageid', 'Unknown') |
145 | - # It can happen that the pageid is ''?!? |
146 | - if pageid == '': |
147 | - pageid = 'Unknown' |
148 | - leak_in_mb = float(mem_leak) / (1024*1024) |
149 | - formatted_delta = "; ".join( |
150 | - "%s=%d" % (ref_type, count) |
151 | - for count, ref_type in delta_refs) |
152 | - log.write('%s %s %.2fMb %s\n' % ( |
153 | - strftime('%Y-%m-%d:%H:%M:%S'), |
154 | - pageid, |
155 | - leak_in_mb, |
156 | - formatted_delta)) |
157 | - finally: |
158 | - log.close() |
159 | - |
160 | |
161 | class InvalidThreadsConfiguration(Exception): |
162 | """Exception thrown when the number of threads isn't set correctly.""" |
163 | |
164 | |
165 | -def debug_references_startup_check(event): |
166 | - """Event handler for IProcessStartingEvent. |
167 | - |
168 | - If debug/references is set to True, we make sure that the number of |
169 | - threads is configured to 1. We also delete any previous scoreboard file. |
170 | - """ |
171 | - if not config.debug.references: |
172 | - return |
173 | - |
174 | - if config.threads != 1: |
175 | - raise InvalidThreadsConfiguration( |
176 | - "Number of threads should be one when debugging references.") |
177 | - |
178 | - # Remove any previous scoreboard, the content is meaningless once |
179 | - # the server is restarted. |
180 | - if os.path.exists(config.debug.references_scoreboard_file): |
181 | - os.remove(config.debug.references_scoreboard_file) |
182 | - |
183 | - |
184 | class DefaultPrimaryContext: |
185 | """The default primary context is the context.""" |
186 | |
187 | |
188 | === removed file 'lib/lp/bugs/doc/memory-debug.txt' |
189 | --- lib/lp/bugs/doc/memory-debug.txt 2009-06-12 16:36:02 +0000 |
190 | +++ lib/lp/bugs/doc/memory-debug.txt 1970-01-01 00:00:00 +0000 |
191 | @@ -1,185 +0,0 @@ |
192 | -= Memory debugging = |
193 | - |
194 | -Application server can leak references, and this is hard to track down. |
195 | -The LaunchpadBrowserPublication contains special purpose memory |
196 | -debugging helper to help diagnose such problems. |
197 | - |
198 | -The memory leaking diagnosis is invoked at endRequest() only when the |
199 | -debug.references variable is true. It is turned off by default. |
200 | - |
201 | - >>> from canonical.config import config |
202 | - >>> config.debug.references |
203 | - False |
204 | - |
205 | -Setting it to true, will save in endRequest() a dump of the current |
206 | -memory usage and counts in the file specified in |
207 | -config.debug.references_scoreboard_file. (We also set the |
208 | -config.debug.references_leak_log file which will contain the |
209 | -differential diagnostic.) |
210 | - |
211 | - >>> import os |
212 | - >>> import tempfile |
213 | - >>> from textwrap import dedent |
214 | - |
215 | - >>> tempdir = tempfile.mkdtemp(prefix='memory-debug') |
216 | - >>> scoreboard_path = os.path.join(tempdir, 'scoreboard.txt') |
217 | - >>> references_log_path = os.path.join(tempdir, 'references-leak.log') |
218 | - |
219 | - >>> config.push('debug-references', dedent("""\ |
220 | - ... [debug] |
221 | - ... references: True |
222 | - ... references_scoreboard_file: %s |
223 | - ... references_leak_log: %s |
224 | - ... """ % (scoreboard_path, references_log_path))) |
225 | - |
226 | -There is a debug_references_startup_check() that is called when the |
227 | -IProcessStartingEvent is fired. It raises an exception if the setting |
228 | -is on, but the number of threads is not 1. |
229 | - |
230 | - >>> from canonical.launchpad.webapp.publication import ( |
231 | - ... debug_references_startup_check) |
232 | - >>> orig_threads = config.threads |
233 | - >>> orig_threads > 1 |
234 | - True |
235 | - >>> from zope.app.appsetup import ProcessStarting |
236 | - |
237 | - # We don't use notify here, because we don't want to invoke the |
238 | - # other subscribers. |
239 | - >>> debug_references_startup_check(ProcessStarting()) |
240 | - Traceback (most recent call last): |
241 | - ... |
242 | - InvalidThreadsConfiguration: ... |
243 | - |
244 | -This handler also deletes any previous scoreboard file that might be |
245 | -present (left by a previous run.) |
246 | - |
247 | - >>> config.threads = 1 |
248 | - >>> open(scoreboard_path, 'w').close() |
249 | - >>> debug_references_startup_check(ProcessStarting()) |
250 | - >>> os.path.exists(scoreboard_path) |
251 | - False |
252 | - |
253 | -The memory monitoring code also watches the garbage list. Make sure that |
254 | -there is some available: |
255 | - |
256 | - >>> class garbage(object): |
257 | - ... """Uncollectable objects involved in a cycle.""" |
258 | - ... def __init__(self): |
259 | - ... self.cycle = self |
260 | - ... def __del__(self): |
261 | - ... """The presence of this method makes us garbage.""" |
262 | - >>> trash = garbage() |
263 | - >>> del trash |
264 | - |
265 | -So the first time endRequest() is called, the references count is dumped |
266 | -to the scoreboard file. |
267 | - |
268 | - >>> from canonical.launchpad.webapp.servers import LaunchpadTestRequest |
269 | - >>> from canonical.launchpad.webapp.adapter import set_request_started |
270 | - >>> def create_request(pageid='View:+template'): |
271 | - ... """Returns a LaunchpadTestRequest with appropriate fixture. |
272 | - ... |
273 | - ... Sets some attributes on the request expected by the |
274 | - ... publication, and that are usually set by previous publication |
275 | - ... steps. |
276 | - ... """ |
277 | - ... request = LaunchpadTestRequest() |
278 | - ... # Adds some expected requests variables by endRequest(). |
279 | - ... request._orig_env['launchpad.pageid'] = pageid |
280 | - ... request.oopsid = None |
281 | - ... # Prevents warnings when endRequest() is called. |
282 | - ... set_request_started() |
283 | - ... return request |
284 | - |
285 | - >>> from canonical.launchpad.webapp.publication import ( |
286 | - ... LaunchpadBrowserPublication) |
287 | - >>> publication = LaunchpadBrowserPublication(None) |
288 | - >>> publication.endRequest(create_request(), None) |
289 | - |
290 | -The first line of the scoreboard is the number of bytes of RSS used and |
291 | -the number of items on the garbage list. |
292 | - |
293 | - >>> import re |
294 | - >>> scoreboard = open(scoreboard_path, 'r') |
295 | - >>> lines = scoreboard.readlines() |
296 | - >>> re.match('\d+ \d+$', lines[0].strip()) is not None |
297 | - True |
298 | - |
299 | -Lines up to the '=== GARBAGE ===' marker contains a count and a type |
300 | -name. This is the number of references for that type. |
301 | - |
302 | - >>> re.match('\d+ <type.*>$', lines[1].strip()) is not None |
303 | - True |
304 | - |
305 | -After the '=== GARBAGE ===' marker, again we find a count and type name |
306 | -on each subsequent lines. |
307 | - |
308 | - >>> garbage_marker = lines.index('=== GARBAGE ===\n') |
309 | - >>> garbage_marker > 1 |
310 | - True |
311 | - >>> print "\n".join(lines[garbage_marker:]) |
312 | - === GARBAGE === |
313 | - ...1 G<class 'garbage'>... |
314 | - |
315 | -On the second request, the scoreboard will be compared to the previous |
316 | -one and differences will be reported in the references leak log file. |
317 | -The format is: |
318 | - |
319 | - date pageid increase_in_RSS increase_in_garbage type=increase; \ |
320 | - type=increase; G<type>=increase; ... |
321 | - |
322 | -Type names prefixed by G means that a number of instances of that type |
323 | -was added to the garbage list. |
324 | - |
325 | -Example: |
326 | - |
327 | - 2008-04-03:18:15:45 Question:+index 0.57Mb <type 'tuple'>=6419; |
328 | - <type 'dict'>=2744; <type 'list'>=1942; <type 'weakref'>=544; |
329 | - G<class 'garbage'>=1 |
330 | - |
331 | - >>> os.path.exists(references_log_path) |
332 | - False |
333 | - |
334 | -(Add some garbage) |
335 | - |
336 | - >>> trash = garbage() |
337 | - >>> del trash |
338 | - |
339 | - >>> publication.endRequest(create_request(), None) |
340 | - >>> references_log = open(references_log_path, 'r') |
341 | - >>> references_log.read() |
342 | - "... View:+template ...Mb... <type 'list'>=...; |
343 | - ...G<class 'garbage'>=1...\n" |
344 | - |
345 | -Of course when the tool is off, none of the above processing takes |
346 | -place: |
347 | - |
348 | - >>> config.push('turn-off-references-debug', dedent("""\ |
349 | - ... [debug] |
350 | - ... references: False""")) |
351 | - >>> scoreboard.close() |
352 | - >>> references_log.close() |
353 | - >>> os.remove(scoreboard_path) |
354 | - >>> os.remove(references_log_path) |
355 | - |
356 | - >>> publication.endRequest(create_request(), None) |
357 | - >>> os.path.exists(config.debug.references_scoreboard_file) |
358 | - False |
359 | - >>> os.path.exists(config.debug.references_leak_log) |
360 | - False |
361 | - |
362 | -(Clean up) |
363 | - |
364 | - >>> ignored = config.pop('debug-references') |
365 | - >>> config.threads = orig_threads |
366 | - |
367 | - >>> import gc |
368 | - >>> new_garbage = [] |
369 | - >>> for g in gc.garbage: |
370 | - ... # We only know how to clean our own garbage. |
371 | - ... if isinstance(g, garbage): |
372 | - ... del g.cycle |
373 | - ... else: |
374 | - ... new_garbage.append(g) |
375 | - >>> gc.garbage[:] = new_garbage |
376 | - |
Nuke, nuke, nuke!