Launchpad itself

Merge lp:~jml/launchpad/split-mail-and-summary into lp:launchpad

  1. split-mail-and-summary
  2. Merge into devel
Proposed by Jonathan Lange
Status: Merged
Approved by: Robert Collins
Approved revision: no longer in the source branch.
Merged at revision: 11596
Proposed branch: lp:~jml/launchpad/split-mail-and-summary
Merge into: lp:launchpad
Diff against target: 551 lines (+259/-46)
3 files modified
lib/devscripts/ec2test/remote.py (+87/-15)
lib/devscripts/ec2test/tests/test_remote.py (+168/-30)
lib/lp/services/job/tests/test_runner.py (+4/-1)
To merge this branch: bzr merge lp:~jml/launchpad/split-mail-and-summary
Reviewer Review Type Date Requested Status
Robert Collins (community) Approve
Review via email: mp+36111@code.launchpad.net

Commit message

Improve the email sent by ec2 test.

Description of the change

Hello,

This branch changes the email sent by ec2 test. Rather than being a mere lump of stuff that we have collected as summary, it's a custom built message derived from the test results.

Examples:
  * http://paste.ubuntu.com/497557/
  * http://paste.ubuntu.com/497555/

Implementation-wise, the main trick is to change EC2Tester, the object responsible for running tests and gathering results, to send its TestResult object back to the logger, rather than a simple boolean. The Logger was then changed to use the new format_result method to compose the result email, rather than simply dumping the summary.

The details:
  * If the test child process exits with a non-zero code and we have no test results, we raise an error, since it's likely to be something weird.

  * Included in the diff are changes from a merge proposal that I should have applied before landing my previous branch. Mostly stylistic.

  * Some tests were incorrect. They used a dictionary to fake an email message, but had the subject stored under the wrong key ("Subject:" rather than "Subject").

I look forward to your review.

jml

To post a comment you must log in.
Revision history for this message
Robert Collins (lifeless) wrote :

This is nice.

A few thoughts for now, or later, or never.

Perhaps testrepository would make this a lot smaller? Like tiny?

Perhaps Fixtures would make some of the test machinery a little cleaner. (we can use them in LP).

review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'lib/devscripts/ec2test/remote.py'
2--- lib/devscripts/ec2test/remote.py 2010-08-27 14:27:22 +0000
3+++ lib/devscripts/ec2test/remote.py 2010-09-22 13:36:00 +0000
4@@ -28,6 +28,7 @@
5 import optparse
6 import os
7 import pickle
8+from StringIO import StringIO
9 import subprocess
10 import sys
11 import tempfile
12@@ -49,6 +50,15 @@
13 import subunit
14
15
16+class NonZeroExitCode(Exception):
17+ """Raised when the child process exits with a non-zero exit code."""
18+
19+ def __init__(self, retcode):
20+ super(NonZeroExitCode, self).__init__(
21+ 'Test process died with exit code %r, but no tests failed.'
22+ % (retcode,))
23+
24+
25 class SummaryResult(unittest.TestResult):
26 """Test result object used to generate the summary."""
27
28@@ -271,12 +281,16 @@
29 self._logger.prepare()
30 try:
31 popen = self._spawn_test_process()
32- self._gather_test_output(popen.stdout, self._logger)
33- exit_status = popen.wait()
34+ result = self._gather_test_output(popen.stdout, self._logger)
35+ retcode = popen.wait()
36+ # The process could have an error not indicated by an actual test
37+ # result nor by a raised exception
38+ if result.wasSuccessful() and retcode:
39+ raise NonZeroExitCode(retcode)
40 except:
41 self._logger.error_in_testrunner(sys.exc_info())
42 else:
43- self._logger.got_result(not exit_status)
44+ self._logger.got_result(result)
45
46 def _gather_test_output(self, input_stream, logger):
47 """Write the testrunner output to the logs."""
48@@ -287,6 +301,7 @@
49 subunit_server.lineReceived(line)
50 logger.got_line(line)
51 summary_stream.flush()
52+ return result
53
54
55 class Request:
56@@ -327,6 +342,57 @@
57 """Actually send 'message'."""
58 self._smtp_connection.send_email(message)
59
60+ def _format_test_list(self, header, tests):
61+ if not tests:
62+ return []
63+ tests = [' ' + test.id() for test, error in tests]
64+ return [header, '-' * len(header)] + tests + ['']
65+
66+ def format_result(self, result, start_time, end_time):
67+ duration = end_time - start_time
68+ output = [
69+ 'Tests started at approximately %s' % start_time,
70+ ]
71+ source = self.get_source_details()
72+ if source:
73+ output.append('Source: %s r%s' % source)
74+ target = self.get_target_details()
75+ if target:
76+ output.append('Target: %s r%s' % target)
77+ output.extend([
78+ '',
79+ '%s tests run in %s, %s failures, %s errors' % (
80+ result.testsRun, duration, len(result.failures),
81+ len(result.errors)),
82+ '',
83+ ])
84+
85+ bad_tests = (
86+ self._format_test_list('Failing tests', result.failures) +
87+ self._format_test_list('Tests with errors', result.errors))
88+ output.extend(bad_tests)
89+
90+ if bad_tests:
91+ full_error_stream = StringIO()
92+ copy_result = SummaryResult(full_error_stream)
93+ for test, error in result.failures:
94+ full_error_stream.write(
95+ copy_result._formatError('FAILURE', test, error))
96+ for test, error in result.errors:
97+ full_error_stream.write(
98+ copy_result._formatError('ERROR', test, error))
99+ output.append(full_error_stream.getvalue())
100+
101+ subject = self._get_pqm_subject()
102+ if subject:
103+ if result.wasSuccessful():
104+ output.append('SUBMITTED TO PQM:')
105+ else:
106+ output.append('**NOT** submitted to PQM:')
107+ output.extend([subject, ''])
108+ output.extend(['(See the attached file for the complete log)', ''])
109+ return '\n'.join(output)
110+
111 def get_target_details(self):
112 """Return (branch_url, revno) for trunk."""
113 branch = bzrlib.branch.Branch.open(self._local_branch_path)
114@@ -449,12 +515,15 @@
115 continue
116 yield name, branch.get_parent(), branch.revno()
117
118+ def _get_pqm_subject(self):
119+ if not self._pqm_message:
120+ return
121+ return self._pqm_message.get('Subject')
122+
123 def submit_to_pqm(self, successful):
124 """Submit this request to PQM, if successful & configured to do so."""
125- if not self._pqm_message:
126- return
127- subject = self._pqm_message.get('Subject')
128- if successful:
129+ subject = self._get_pqm_subject()
130+ if subject and successful:
131 self._send_email(self._pqm_message)
132 return subject
133
134@@ -491,6 +560,9 @@
135 self._index_filename = index_filename
136 self._request = request
137 self._echo_to_stdout = echo_to_stdout
138+ # Actually set by prepare(), but setting to a dummy value to make
139+ # testing easier.
140+ self._start_time = datetime.datetime.utcnow()
141
142 @classmethod
143 def make_in_directory(cls, www_dir, request, echo_to_stdout):
144@@ -558,16 +630,16 @@
145 if e.errno == errno.ENOENT:
146 return ''
147
148- def got_result(self, successful):
149+ def got_result(self, result):
150 """The tests are done and the results are known."""
151+ self._end_time = datetime.datetime.utcnow()
152+ successful = result.wasSuccessful()
153 self._handle_pqm_submission(successful)
154 if self._request.wants_email:
155- self._write_to_filename(
156- self._summary_filename,
157- '\n(See the attached file for the complete log)\n')
158- summary = self.get_summary_contents()
159+ email_text = self._request.format_result(
160+ result, self._start_time, self._end_time)
161 full_log_gz = gzip_data(self.get_full_log_contents())
162- self._request.send_report_email(successful, summary, full_log_gz)
163+ self._request.send_report_email(successful, email_text, full_log_gz)
164
165 def _handle_pqm_submission(self, successful):
166 subject = self._request.submit_to_pqm(successful)
167@@ -614,9 +686,9 @@
168 return self._write_to_filename(
169 self._index_filename, textwrap.dedent(html))
170
171+ self._start_time = datetime.datetime.utcnow()
172 msg = 'Tests started at approximately %(now)s UTC' % {
173- 'now': datetime.datetime.utcnow().strftime(
174- '%a, %d %b %Y %H:%M:%S')}
175+ 'now': self._start_time.strftime('%a, %d %b %Y %H:%M:%S')}
176 add_to_html('''\
177 <html>
178 <head>
179
180=== modified file 'lib/devscripts/ec2test/tests/test_remote.py'
181--- lib/devscripts/ec2test/tests/test_remote.py 2010-08-27 14:27:22 +0000
182+++ lib/devscripts/ec2test/tests/test_remote.py 2010-09-22 13:36:00 +0000
183@@ -5,6 +5,8 @@
184
185 __metaclass__ = type
186
187+from datetime import datetime, timedelta
188+import doctest
189 from email.mime.application import MIMEApplication
190 from email.mime.text import MIMEText
191 import gzip
192@@ -21,9 +23,10 @@
193 from bzrlib.config import GlobalConfig
194 from bzrlib.tests import TestCaseWithTransport
195
196-from testtools import TestCase
197+from testtools import TestCase, TestResult
198 from testtools.content import Content
199 from testtools.content_type import ContentType
200+from testtools.matchers import DocTestMatches
201
202 from devscripts.ec2test.remote import (
203 EC2Runner,
204@@ -75,7 +78,8 @@
205 """Make a request to test, specifying only things we care about.
206
207 Note that the returned request object will not ever send email, but
208- will instead log "sent" emails to `request.emails_sent`.
209+ will instead append "sent" emails to the list provided here as
210+ 'emails_sent'.
211 """
212 if trunk is None:
213 trunk = self.make_trunk()
214@@ -109,8 +113,6 @@
215 def make_tester(self, logger=None, test_directory=None, test_options=()):
216 if not logger:
217 logger = self.make_logger()
218- if not test_directory:
219- test_directory = 'unspecified-test-directory'
220 return LaunchpadTester(logger, test_directory, test_options)
221
222 def make_logger(self, request=None, echo_to_stdout=False):
223@@ -472,14 +474,14 @@
224 def test_submit_to_pqm_unsuccessful(self):
225 # submit_to_pqm returns the subject of the PQM mail even if it's
226 # handling a failed test run.
227- message = {'Subject:': 'My PQM message'}
228+ message = {'Subject': 'My PQM message'}
229 req = self.make_request(pqm_message=message)
230 subject = req.submit_to_pqm(successful=False)
231 self.assertIs(message.get('Subject'), subject)
232
233 def test_submit_to_pqm_unsuccessful_no_email(self):
234 # submit_to_pqm doesn't send any email if the run was unsuccessful.
235- message = {'Subject:': 'My PQM message'}
236+ message = {'Subject': 'My PQM message'}
237 log = []
238 req = self.make_request(pqm_message=message, emails_sent=log)
239 req.submit_to_pqm(successful=False)
240@@ -487,7 +489,7 @@
241
242 def test_submit_to_pqm_successful(self):
243 # submit_to_pqm returns the subject of the PQM mail.
244- message = {'Subject:': 'My PQM message'}
245+ message = {'Subject': 'My PQM message'}
246 log = []
247 req = self.make_request(pqm_message=message, emails_sent=log)
248 subject = req.submit_to_pqm(successful=True)
249@@ -558,6 +560,124 @@
250 self.assertEqual(
251 expected_part.get_payload(), observed_part.get_payload())
252
253+ def test_format_result_success(self):
254+ class SomeTest(TestCase):
255+ def test_a(self):
256+ pass
257+ def test_b(self):
258+ pass
259+ def test_c(self):
260+ pass
261+ test = unittest.TestSuite(map(SomeTest, ['test_' + x for x in 'abc']))
262+ result = TestResult()
263+ test.run(result)
264+ tree = self.make_trunk()
265+ # Fake a merge, giving silly revision ids.
266+ tree.add_pending_merge('foo', 'bar')
267+ req = self.make_request(
268+ branch_url='https://example.com/bzr/thing', revno=42, trunk=tree)
269+ source_branch, source_revno = req.get_source_details()
270+ target_branch, target_revno = req.get_target_details()
271+ start_time = datetime.utcnow()
272+ end_time = start_time + timedelta(hours=1)
273+ data = {
274+ 'source_branch': source_branch,
275+ 'source_revno': source_revno,
276+ 'target_branch': target_branch,
277+ 'target_revno': target_revno,
278+ 'start_time': str(start_time),
279+ 'duration': str(end_time - start_time),
280+ 'num_tests': result.testsRun,
281+ 'num_failures': len(result.failures),
282+ 'num_errors': len(result.errors),
283+ }
284+ result_text = req.format_result(result, start_time, end_time)
285+ self.assertThat(
286+ result_text, DocTestMatches("""\
287+Tests started at approximately %(start_time)s
288+Source: %(source_branch)s r%(source_revno)s
289+Target: %(target_branch)s r%(target_revno)s
290+<BLANKLINE>
291+%(num_tests)s tests run in %(duration)s, %(num_failures)s failures, %(num_errors)s errors
292+<BLANKLINE>
293+(See the attached file for the complete log)
294+""" % data, doctest.REPORT_NDIFF | doctest.ELLIPSIS))
295+
296+ def test_format_result_with_errors(self):
297+ class SomeTest(TestCase):
298+ def test_ok(self):
299+ pass
300+ def test_fail(self):
301+ self.fail("oh no")
302+ def test_error(self):
303+ 1/0
304+ fail_test = SomeTest('test_fail')
305+ error_test = SomeTest('test_error')
306+ test = unittest.TestSuite(
307+ [fail_test, error_test, SomeTest('test_ok')])
308+ result = TestResult()
309+ test.run(result)
310+ tree = self.make_trunk()
311+ # Fake a merge, giving silly revision ids.
312+ tree.add_pending_merge('foo', 'bar')
313+ req = self.make_request(
314+ branch_url='https://example.com/bzr/thing', revno=42, trunk=tree)
315+ source_branch, source_revno = req.get_source_details()
316+ target_branch, target_revno = req.get_target_details()
317+ start_time = datetime.utcnow()
318+ end_time = start_time + timedelta(hours=1)
319+ data = {
320+ 'source_branch': source_branch,
321+ 'source_revno': source_revno,
322+ 'target_branch': target_branch,
323+ 'target_revno': target_revno,
324+ 'start_time': str(start_time),
325+ 'duration': str(end_time - start_time),
326+ 'fail_id': fail_test.id(),
327+ 'error_id': error_test.id(),
328+ 'num_tests': result.testsRun,
329+ 'num_failures': len(result.failures),
330+ 'num_errors': len(result.errors),
331+ }
332+ result_text = req.format_result(result, start_time, end_time)
333+ self.assertThat(
334+ result_text, DocTestMatches("""\
335+Tests started at approximately %(start_time)s
336+Source: %(source_branch)s r%(source_revno)s
337+Target: %(target_branch)s r%(target_revno)s
338+<BLANKLINE>
339+%(num_tests)s tests run in %(duration)s, %(num_failures)s failures, %(num_errors)s errors
340+<BLANKLINE>
341+Failing tests
342+-------------
343+ %(fail_id)s
344+<BLANKLINE>
345+Tests with errors
346+-----------------
347+ %(error_id)s
348+<BLANKLINE>
349+======================================================================
350+FAILURE: test_fail...
351+----------------------------------------------------------------------
352+Text attachment: traceback
353+------------
354+Traceback (most recent call last):
355+...
356+------------
357+<BLANKLINE>
358+======================================================================
359+ERROR: test_error...
360+----------------------------------------------------------------------
361+Text attachment: traceback
362+------------
363+Traceback (most recent call last):
364+...
365+------------
366+<BLANKLINE>
367+<BLANKLINE>
368+(See the attached file for the complete log)
369+""" % data, doctest.REPORT_NDIFF | doctest.ELLIPSIS))
370+
371
372 class TestWebTestLogger(TestCaseWithTransport, RequestHelpers):
373
374@@ -672,11 +792,13 @@
375 False, "who-cares.pid", False, smtp_connection, emails=emails)
376
377 def test_run(self):
378+ # EC2Runner.run() runs the given function, passing through whatever
379+ # arguments and keyword arguments it has been given.
380 calls = []
381 runner = self.make_ec2runner()
382- runner.run(
383- "boring test method",
384- lambda *a, **kw: calls.append((a, kw)), "foo", "bar", baz="qux")
385+ def function(*args, **kwargs):
386+ calls.append((args, kwargs))
387+ runner.run("boring test method", function, "foo", "bar", baz="qux")
388 self.assertEqual([(("foo", "bar"), {'baz': 'qux'})], calls)
389
390 def test_email_on_failure_no_emails(self):
391@@ -688,7 +810,7 @@
392 self.assertEqual([], log)
393
394 def test_email_on_failure_some_emails(self):
395- # If no emails are specified, then no email is sent on failure.
396+ # If emails *are* specified, then an email is sent on failure.
397 log = []
398 runner = self.make_ec2runner(
399 email_log=log, emails=["foo@example.com"])
400@@ -701,6 +823,7 @@
401 self.assertIn('ZeroDivisionError', str(message))
402
403 def test_email_with_launchpad_tester_failure(self):
404+ # LaunchpadTester sends email on catastrophic failure.
405 email_log = []
406 to_emails = ['foo@example.com']
407 request = self.make_request(emails=to_emails, emails_sent=email_log)
408@@ -767,18 +890,37 @@
409 def get_body_text(self, email):
410 return email.get_payload()[0].get_payload()
411
412+ def make_empty_result(self):
413+ return TestResult()
414+
415+ def make_successful_result(self):
416+ result = self.make_empty_result()
417+ result.startTest(self)
418+ result.stopTest(self)
419+ return result
420+
421+ def make_failing_result(self):
422+ result = self.make_empty_result()
423+ result.startTest(self)
424+ try:
425+ 1/0
426+ except ZeroDivisionError:
427+ result.addError(self, sys.exc_info())
428+ result.stopTest(self)
429+ return result
430+
431 def test_success_no_emails(self):
432 log = []
433 request = self.make_request(emails=[], emails_sent=log)
434 logger = self.make_logger(request=request)
435- logger.got_result(True)
436+ logger.got_result(self.make_successful_result())
437 self.assertEqual([], log)
438
439 def test_failure_no_emails(self):
440 log = []
441 request = self.make_request(emails=[], emails_sent=log)
442 logger = self.make_logger(request=request)
443- logger.got_result(False)
444+ logger.got_result(self.make_failing_result())
445 self.assertEqual([], log)
446
447 def test_submits_to_pqm_on_success(self):
448@@ -787,7 +929,7 @@
449 request = self.make_request(
450 emails=[], pqm_message=message, emails_sent=log)
451 logger = self.make_logger(request=request)
452- logger.got_result(True)
453+ logger.got_result(self.make_successful_result())
454 self.assertEqual([message], log)
455
456 def test_records_pqm_submission_in_email(self):
457@@ -796,20 +938,20 @@
458 request = self.make_request(
459 emails=['foo@example.com'], pqm_message=message, emails_sent=log)
460 logger = self.make_logger(request=request)
461- logger.got_result(True)
462+ logger.got_result(self.make_successful_result())
463 [pqm_message, user_message] = log
464 self.assertEqual(message, pqm_message)
465 self.assertIn(
466 'SUBMITTED TO PQM:\n%s' % (message['Subject'],),
467 self.get_body_text(user_message))
468
469- def test_doesnt_submit_to_pqm_no_failure(self):
470+ def test_doesnt_submit_to_pqm_on_failure(self):
471 log = []
472 message = {'Subject': 'foo'}
473 request = self.make_request(
474 emails=[], pqm_message=message, emails_sent=log)
475 logger = self.make_logger(request=request)
476- logger.got_result(False)
477+ logger.got_result(self.make_failing_result())
478 self.assertEqual([], log)
479
480 def test_records_non_pqm_submission_in_email(self):
481@@ -818,7 +960,7 @@
482 request = self.make_request(
483 emails=['foo@example.com'], pqm_message=message, emails_sent=log)
484 logger = self.make_logger(request=request)
485- logger.got_result(False)
486+ logger.got_result(self.make_failing_result())
487 [user_message] = log
488 self.assertIn(
489 '**NOT** submitted to PQM:\n%s' % (message['Subject'],),
490@@ -829,29 +971,25 @@
491 request = self.make_request(
492 emails=['foo@example.com'], emails_sent=log)
493 logger = self.make_logger(request=request)
494- logger.got_result(False)
495+ logger.got_result(self.make_failing_result())
496 [user_message] = log
497 self.assertIn(
498 '(See the attached file for the complete log)\n',
499 self.get_body_text(user_message))
500
501- def test_email_body_is_summary(self):
502+ def test_email_body_is_format_result(self):
503 # The body of the email sent to the user is the summary file.
504- # XXX: JonathanLange 2010-08-17: We actually want to change this
505- # behaviour so that the summary log stays roughly the same as it is
506- # now and can vary independently from the contents of the sent
507- # email. We probably just want the contents of the email to be a list
508- # of failing tests.
509 log = []
510 request = self.make_request(
511 emails=['foo@example.com'], emails_sent=log)
512 logger = self.make_logger(request=request)
513- logger.get_summary_stream().write('bar\nbaz\nqux\n')
514- logger.got_result(False)
515+ result = self.make_failing_result()
516+ logger.got_result(result)
517 [user_message] = log
518 self.assertEqual(
519- 'bar\nbaz\nqux\n\n(See the attached file for the complete log)\n',
520- self.get_body_text(user_message))
521+ request.format_result(
522+ result, logger._start_time, logger._end_time),
523+ self.get_body_text(user_message).decode('quoted-printable'))
524
525 def test_gzip_of_full_log_attached(self):
526 # The full log is attached to the email.
527@@ -861,7 +999,7 @@
528 logger = self.make_logger(request=request)
529 logger.got_line("output from test process\n")
530 logger.got_line("more output\n")
531- logger.got_result(False)
532+ logger.got_result(self.make_successful_result())
533 [user_message] = log
534 [body, attachment] = user_message.get_payload()
535 self.assertEqual('application/x-gzip', attachment['Content-Type'])
536
537=== modified file 'lib/lp/services/job/tests/test_runner.py'
538--- lib/lp/services/job/tests/test_runner.py 2010-09-15 22:09:12 +0000
539+++ lib/lp/services/job/tests/test_runner.py 2010-09-22 13:36:00 +0000
540@@ -216,7 +216,10 @@
541 # aborted, it is None.
542 self.assertIs(None, job.job.log)
543
544- def test_runAll_mails_oopses(self):
545+ # XXX michaeln 2010-09-22 bug=644984
546+ # This is failing sometimes, but has not yet been reproduced
547+ # locally.
548+ def _disabled_test_runAll_mails_oopses(self):
549 """Email interested parties about OOPses."""
550 job_1, job_2 = self.makeTwoJobs()
551 def raiseError():