experiment_runner_unittest.py revision 8b06f631ad7b4b3c75438f58a8292eae7e444566 
1#!/usr/bin/python2
2#
3# Copyright 2014 Google Inc. All Rights Reserved
4"""Tests for the experiment runner module."""
5
6from __future__ import print_function
7
8import StringIO
9import getpass
10import os
11
12import mock
13import unittest
14
15import experiment_runner
16import experiment_status
17import machine_manager
18import config
19import test_flag
20from experiment_file import ExperimentFile
21from experiment_factory import ExperimentFactory
22from results_report import TextResultsReport
23from results_report import HTMLResultsReport
24from results_cache import Result
25
26from cros_utils import command_executer
27from cros_utils.email_sender import EmailSender
28from cros_utils.file_utils import FileUtils
29
30EXPERIMENT_FILE_1 = """
31  board: parrot
32  remote: chromeos-parrot1.cros chromreos-parrot2.cros
33
34  benchmark: kraken {
35    suite: telemetry_Crosperf
36    iterations: 3
37  }
38
39  image1 {
40    chromeos_root: /usr/local/google/chromeos
41    chromeos_image: /usr/local/google/chromeos/src/build/images/parrot/latest/cros_image1.bin
42  }
43
44  image2 {
45    chromeos_image: /usr/local/google/chromeos/src/build/imaages/parrot/latest/cros_image2.bin
46  }
47  """
48
49# pylint: disable=protected-access
50
51
52class FakeLogger(object):
53  """Fake logger for tests."""
54
55  def __init__(self):
56    self.LogOutputCount = 0
57    self.LogErrorCount = 0
58    self.output_msgs = []
59    self.error_msgs = []
60    self.dot_count = 0
61    self.LogStartDotsCount = 0
62    self.LogEndDotsCount = 0
63    self.LogAppendDotCount = 0
64
65  def LogOutput(self, msg):
66    self.LogOutputCount += 1
67    self.output_msgs.append(msg)
68
69  def LogError(self, msg):
70    self.LogErrorCount += 1
71    self.error_msgs.append(msg)
72
73  def LogStartDots(self):
74    self.LogStartDotsCount += 1
75    self.dot_count += 1
76
77  def LogAppendDot(self):
78    self.LogAppendDotCount += 1
79    self.dot_count += 1
80
81  def LogEndDots(self):
82    self.LogEndDotsCount += 1
83
84  def Reset(self):
85    self.LogOutputCount = 0
86    self.LogErrorCount = 0
87    self.output_msgs = []
88    self.error_msgs = []
89    self.dot_count = 0
90    self.LogStartDotsCount = 0
91    self.LogEndDotsCount = 0
92    self.LogAppendDotCount = 0
93
94
95class ExperimentRunnerTest(unittest.TestCase):
96  """Test for experiment runner class."""
97
98  run_count = 0
99  is_complete_count = 0
100  mock_logger = FakeLogger()
101  mock_cmd_exec = mock.Mock(spec=command_executer.CommandExecuter)
102
103  def make_fake_experiment(self):
104    test_flag.SetTestMode(True)
105    experiment_file = ExperimentFile(StringIO.StringIO(EXPERIMENT_FILE_1))
106    experiment = ExperimentFactory().GetExperiment(experiment_file,
107                                                   working_directory='',
108                                                   log_dir='')
109    return experiment
110
111  @mock.patch.object(machine_manager.MachineManager, 'AddMachine')
112  @mock.patch.object(os.path, 'isfile')
113
114  # pylint: disable=arguments-differ
115  def setUp(self, mock_isfile, _mock_addmachine):
116    mock_isfile.return_value = True
117    self.exp = self.make_fake_experiment()
118
119  def test_init(self):
120    er = experiment_runner.ExperimentRunner(self.exp,
121                                            json_report=False,
122                                            using_schedv2=False,
123                                            log=self.mock_logger,
124                                            cmd_exec=self.mock_cmd_exec)
125    self.assertFalse(er._terminated)
126    self.assertEqual(er.STATUS_TIME_DELAY, 10)
127
128    self.exp.log_level = 'verbose'
129    er = experiment_runner.ExperimentRunner(self.exp,
130                                            json_report=False,
131                                            using_schedv2=False,
132                                            log=self.mock_logger,
133                                            cmd_exec=self.mock_cmd_exec)
134    self.assertEqual(er.STATUS_TIME_DELAY, 30)
135
136  @mock.patch.object(experiment_status.ExperimentStatus, 'GetStatusString')
137  @mock.patch.object(experiment_status.ExperimentStatus, 'GetProgressString')
138  def test_run(self, mock_progress_string, mock_status_string):
139
140    self.run_count = 0
141    self.is_complete_count = 0
142
143    def reset():
144      self.run_count = 0
145      self.is_complete_count = 0
146
147    def FakeRun():
148      self.run_count += 1
149      return 0
150
151    def FakeIsComplete():
152      self.is_complete_count += 1
153      if self.is_complete_count < 3:
154        return False
155      else:
156        return True
157
158    self.mock_logger.Reset()
159    self.exp.Run = FakeRun
160    self.exp.IsComplete = FakeIsComplete
161
162    # Test 1: log_level == "quiet"
163    self.exp.log_level = 'quiet'
164    er = experiment_runner.ExperimentRunner(self.exp,
165                                            json_report=False,
166                                            using_schedv2=False,
167                                            log=self.mock_logger,
168                                            cmd_exec=self.mock_cmd_exec)
169    er.STATUS_TIME_DELAY = 2
170    mock_status_string.return_value = 'Fake status string'
171    er._Run(self.exp)
172    self.assertEqual(self.run_count, 1)
173    self.assertTrue(self.is_complete_count > 0)
174    self.assertEqual(self.mock_logger.LogStartDotsCount, 1)
175    self.assertEqual(self.mock_logger.LogAppendDotCount, 1)
176    self.assertEqual(self.mock_logger.LogEndDotsCount, 1)
177    self.assertEqual(self.mock_logger.dot_count, 2)
178    self.assertEqual(mock_progress_string.call_count, 0)
179    self.assertEqual(mock_status_string.call_count, 2)
180    self.assertEqual(self.mock_logger.output_msgs,
181                     ['==============================', 'Fake status string',
182                      '=============================='])
183    self.assertEqual(len(self.mock_logger.error_msgs), 0)
184
185    # Test 2: log_level == "average"
186    self.mock_logger.Reset()
187    reset()
188    self.exp.log_level = 'average'
189    mock_status_string.call_count = 0
190    er = experiment_runner.ExperimentRunner(self.exp,
191                                            json_report=False,
192                                            using_schedv2=False,
193                                            log=self.mock_logger,
194                                            cmd_exec=self.mock_cmd_exec)
195    er.STATUS_TIME_DELAY = 2
196    mock_status_string.return_value = 'Fake status string'
197    er._Run(self.exp)
198    self.assertEqual(self.run_count, 1)
199    self.assertTrue(self.is_complete_count > 0)
200    self.assertEqual(self.mock_logger.LogStartDotsCount, 1)
201    self.assertEqual(self.mock_logger.LogAppendDotCount, 1)
202    self.assertEqual(self.mock_logger.LogEndDotsCount, 1)
203    self.assertEqual(self.mock_logger.dot_count, 2)
204    self.assertEqual(mock_progress_string.call_count, 0)
205    self.assertEqual(mock_status_string.call_count, 2)
206    self.assertEqual(self.mock_logger.output_msgs,
207                     ['==============================', 'Fake status string',
208                      '=============================='])
209    self.assertEqual(len(self.mock_logger.error_msgs), 0)
210
211    # Test 3: log_level == "verbose"
212    self.mock_logger.Reset()
213    reset()
214    self.exp.log_level = 'verbose'
215    mock_status_string.call_count = 0
216    er = experiment_runner.ExperimentRunner(self.exp,
217                                            json_report=False,
218                                            using_schedv2=False,
219                                            log=self.mock_logger,
220                                            cmd_exec=self.mock_cmd_exec)
221    er.STATUS_TIME_DELAY = 2
222    mock_status_string.return_value = 'Fake status string'
223    mock_progress_string.return_value = 'Fake progress string'
224    er._Run(self.exp)
225    self.assertEqual(self.run_count, 1)
226    self.assertTrue(self.is_complete_count > 0)
227    self.assertEqual(self.mock_logger.LogStartDotsCount, 0)
228    self.assertEqual(self.mock_logger.LogAppendDotCount, 0)
229    self.assertEqual(self.mock_logger.LogEndDotsCount, 0)
230    self.assertEqual(self.mock_logger.dot_count, 0)
231    self.assertEqual(mock_progress_string.call_count, 2)
232    self.assertEqual(mock_status_string.call_count, 2)
233    self.assertEqual(self.mock_logger.output_msgs,
234                     ['==============================', 'Fake progress string',
235                      'Fake status string', '==============================',
236                      '==============================', 'Fake progress string',
237                      'Fake status string', '=============================='])
238    self.assertEqual(len(self.mock_logger.error_msgs), 0)
239
240  @mock.patch.object(TextResultsReport, 'GetReport')
241  def test_print_table(self, mock_report):
242    self.mock_logger.Reset()
243    mock_report.return_value = 'This is a fake experiment report.'
244    er = experiment_runner.ExperimentRunner(self.exp,
245                                            json_report=False,
246                                            using_schedv2=False,
247                                            log=self.mock_logger,
248                                            cmd_exec=self.mock_cmd_exec)
249    er._PrintTable(self.exp)
250    self.assertEqual(mock_report.call_count, 1)
251    self.assertEqual(self.mock_logger.output_msgs,
252                     ['This is a fake experiment report.'])
253
254  @mock.patch.object(HTMLResultsReport, 'GetReport')
255  @mock.patch.object(TextResultsReport, 'GetReport')
256  @mock.patch.object(EmailSender, 'Attachment')
257  @mock.patch.object(EmailSender, 'SendEmail')
258  @mock.patch.object(getpass, 'getuser')
259  def test_email(self, mock_getuser, mock_emailer, mock_attachment,
260                 mock_text_report, mock_html_report):
261
262    mock_getuser.return_value = 'john.smith@google.com'
263    mock_text_report.return_value = 'This is a fake text report.'
264    mock_html_report.return_value = 'This is a fake html report.'
265
266    self.mock_logger.Reset()
267    config.AddConfig('no_email', True)
268    self.exp.email_to = ['jane.doe@google.com']
269    er = experiment_runner.ExperimentRunner(self.exp,
270                                            json_report=False,
271                                            using_schedv2=False,
272                                            log=self.mock_logger,
273                                            cmd_exec=self.mock_cmd_exec)
274    # Test 1. Config:no_email; exp.email_to set ==> no email sent
275    er._Email(self.exp)
276    self.assertEqual(mock_getuser.call_count, 0)
277    self.assertEqual(mock_emailer.call_count, 0)
278    self.assertEqual(mock_attachment.call_count, 0)
279    self.assertEqual(mock_text_report.call_count, 0)
280    self.assertEqual(mock_html_report.call_count, 0)
281
282    # Test 2. Config: email. exp.email_to set; cache hit.  => send email
283    self.mock_logger.Reset()
284    config.AddConfig('no_email', False)
285    for r in self.exp.benchmark_runs:
286      r.cache_hit = True
287    er._Email(self.exp)
288    self.assertEqual(mock_getuser.call_count, 1)
289    self.assertEqual(mock_emailer.call_count, 1)
290    self.assertEqual(mock_attachment.call_count, 1)
291    self.assertEqual(mock_text_report.call_count, 1)
292    self.assertEqual(mock_html_report.call_count, 1)
293    self.assertEqual(len(mock_emailer.call_args), 2)
294    self.assertEqual(mock_emailer.call_args[0],
295                     (['jane.doe@google.com', 'john.smith@google.com'],
296                      ': image1 vs. image2',
297                      "<pre style='font-size: 13px'>This is a fake text "
298                      'report.\nResults are stored in _results.\n</pre>'))
299    self.assertTrue(type(mock_emailer.call_args[1]) is dict)
300    self.assertEqual(len(mock_emailer.call_args[1]), 2)
301    self.assertTrue('attachments' in mock_emailer.call_args[1].keys())
302    self.assertEqual(mock_emailer.call_args[1]['msg_type'], 'html')
303
304    mock_attachment.assert_called_with('report.html',
305                                       'This is a fake html report.')
306
307    # Test 3. Config: email; exp.mail_to set; no cache hit.  => send email
308    self.mock_logger.Reset()
309    mock_getuser.reset_mock()
310    mock_emailer.reset_mock()
311    mock_attachment.reset_mock()
312    mock_text_report.reset_mock()
313    mock_html_report.reset_mock()
314    config.AddConfig('no_email', False)
315    for r in self.exp.benchmark_runs:
316      r.cache_hit = False
317    er._Email(self.exp)
318    self.assertEqual(mock_getuser.call_count, 1)
319    self.assertEqual(mock_emailer.call_count, 1)
320    self.assertEqual(mock_attachment.call_count, 1)
321    self.assertEqual(mock_text_report.call_count, 1)
322    self.assertEqual(mock_html_report.call_count, 1)
323    self.assertEqual(len(mock_emailer.call_args), 2)
324    self.assertEqual(mock_emailer.call_args[0],
325                     (['jane.doe@google.com', 'john.smith@google.com',
326                       'john.smith@google.com'], ': image1 vs. image2',
327                      "<pre style='font-size: 13px'>This is a fake text "
328                      'report.\nResults are stored in _results.\n</pre>'))
329    self.assertTrue(type(mock_emailer.call_args[1]) is dict)
330    self.assertEqual(len(mock_emailer.call_args[1]), 2)
331    self.assertTrue('attachments' in mock_emailer.call_args[1].keys())
332    self.assertEqual(mock_emailer.call_args[1]['msg_type'], 'html')
333
334    mock_attachment.assert_called_with('report.html',
335                                       'This is a fake html report.')
336
337    # Test 4. Config: email; exp.mail_to = None; no cache hit. => send email
338    self.mock_logger.Reset()
339    mock_getuser.reset_mock()
340    mock_emailer.reset_mock()
341    mock_attachment.reset_mock()
342    mock_text_report.reset_mock()
343    mock_html_report.reset_mock()
344    self.exp.email_to = []
345    er._Email(self.exp)
346    self.assertEqual(mock_getuser.call_count, 1)
347    self.assertEqual(mock_emailer.call_count, 1)
348    self.assertEqual(mock_attachment.call_count, 1)
349    self.assertEqual(mock_text_report.call_count, 1)
350    self.assertEqual(mock_html_report.call_count, 1)
351    self.assertEqual(len(mock_emailer.call_args), 2)
352    self.assertEqual(mock_emailer.call_args[0],
353                     (['john.smith@google.com'], ': image1 vs. image2',
354                      "<pre style='font-size: 13px'>This is a fake text "
355                      'report.\nResults are stored in _results.\n</pre>'))
356    self.assertTrue(type(mock_emailer.call_args[1]) is dict)
357    self.assertEqual(len(mock_emailer.call_args[1]), 2)
358    self.assertTrue('attachments' in mock_emailer.call_args[1].keys())
359    self.assertEqual(mock_emailer.call_args[1]['msg_type'], 'html')
360
361    mock_attachment.assert_called_with('report.html',
362                                       'This is a fake html report.')
363
364    # Test 5. Config: email; exp.mail_to = None; cache hit => no email sent
365    self.mock_logger.Reset()
366    mock_getuser.reset_mock()
367    mock_emailer.reset_mock()
368    mock_attachment.reset_mock()
369    mock_text_report.reset_mock()
370    mock_html_report.reset_mock()
371    for r in self.exp.benchmark_runs:
372      r.cache_hit = True
373    er._Email(self.exp)
374    self.assertEqual(mock_getuser.call_count, 0)
375    self.assertEqual(mock_emailer.call_count, 0)
376    self.assertEqual(mock_attachment.call_count, 0)
377    self.assertEqual(mock_text_report.call_count, 0)
378    self.assertEqual(mock_html_report.call_count, 0)
379
380  @mock.patch.object(FileUtils, 'RmDir')
381  @mock.patch.object(FileUtils, 'MkDirP')
382  @mock.patch.object(FileUtils, 'WriteFile')
383  @mock.patch.object(HTMLResultsReport, 'GetReport')
384  @mock.patch.object(TextResultsReport, 'GetReport')
385  @mock.patch.object(Result, 'CopyResultsTo')
386  @mock.patch.object(Result, 'CleanUp')
387  def test_store_results(self, mock_cleanup, mock_copy, _mock_text_report,
388                         mock_report, mock_writefile, mock_mkdir, mock_rmdir):
389
390    self.mock_logger.Reset()
391    self.exp.results_directory = '/usr/local/crosperf-results'
392    bench_run = self.exp.benchmark_runs[5]
393    bench_path = '/usr/local/crosperf-results/' + filter(str.isalnum,
394                                                         bench_run.name)
395    self.assertEqual(len(self.exp.benchmark_runs), 6)
396
397    er = experiment_runner.ExperimentRunner(self.exp,
398                                            json_report=False,
399                                            using_schedv2=False,
400                                            log=self.mock_logger,
401                                            cmd_exec=self.mock_cmd_exec)
402
403    # Test 1. Make sure nothing is done if _terminated is true.
404    er._terminated = True
405    er._StoreResults(self.exp)
406    self.assertEqual(mock_cleanup.call_count, 0)
407    self.assertEqual(mock_copy.call_count, 0)
408    self.assertEqual(mock_report.call_count, 0)
409    self.assertEqual(mock_writefile.call_count, 0)
410    self.assertEqual(mock_mkdir.call_count, 0)
411    self.assertEqual(mock_rmdir.call_count, 0)
412    self.assertEqual(self.mock_logger.LogOutputCount, 0)
413
414    # Test 2. _terminated is false; everything works properly.
415    fake_result = Result(self.mock_logger, self.exp.labels[0], 'average',
416                         'daisy1')
417    for r in self.exp.benchmark_runs:
418      r.result = fake_result
419    er._terminated = False
420    er._StoreResults(self.exp)
421    self.assertEqual(mock_cleanup.call_count, 6)
422    mock_cleanup.called_with(bench_run.benchmark.rm_chroot_tmp)
423    self.assertEqual(mock_copy.call_count, 6)
424    mock_copy.called_with(bench_path)
425    self.assertEqual(mock_writefile.call_count, 3)
426    self.assertEqual(len(mock_writefile.call_args_list), 3)
427    first_args = mock_writefile.call_args_list[0]
428    second_args = mock_writefile.call_args_list[1]
429    self.assertEqual(first_args[0][0],
430                     '/usr/local/crosperf-results/experiment.exp')
431    self.assertEqual(second_args[0][0],
432                     '/usr/local/crosperf-results/results.html')
433    self.assertEqual(mock_mkdir.call_count, 1)
434    mock_mkdir.called_with('/usr/local/crosperf-results')
435    self.assertEqual(mock_rmdir.call_count, 1)
436    mock_rmdir.called_with('/usr/local/crosperf-results')
437    self.assertEqual(self.mock_logger.LogOutputCount, 4)
438    self.assertEqual(
439        self.mock_logger.output_msgs,
440        ['Storing experiment file in /usr/local/crosperf-results.',
441         'Storing results report in /usr/local/crosperf-results.',
442         'Storing email message body in /usr/local/crosperf-results.',
443         'Storing results of each benchmark run.'])
444
445
446if __name__ == '__main__':
447  unittest.main()
448