def test_detects_arm_Oops_successfully(self): oops_line = 'Internal error: Oops - SP/PC alignment exception: 8a000000 [#1] SMP\n' with open(self.console_log, 'w') as f: f.write(oops_line) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(oops_line)) self.assert_panic_detected('Oops ')
def test_power_commands_are_not_run_twice(self): # We will make the dummy power script sleep for this long: power_sleep = 4 # To reproduce this bug, we need to queue up three commands for the # same system (so they are run in sequence by beaker-provision), where # the commands take enough time that the second one will still be # running on the next iteration of the polling loop. The third command # will be run twice. assert power_sleep < get_conf().get("SLEEP_TIME") assert 2 * power_sleep > get_conf().get("SLEEP_TIME") with session.begin(): system = data_setup.create_system(lab_controller=self.get_lc()) system.power.power_type = PowerType.lazy_create(name=u"dummy") system.power.power_id = power_sleep system.action_power(action=u"off", service=u"testdata") system.action_power(action=u"off", service=u"testdata") system.action_power(action=u"off", service=u"testdata") def _commands_completed(): with session.begin(): session.expire_all() return system.command_queue[0].status == CommandStatus.completed wait_for_condition(_commands_completed, timeout=5 * power_sleep) with session.begin(): session.expire_all() self.assertEquals(system.command_queue[0].status, CommandStatus.completed) self.assertEquals(system.command_queue[1].status, CommandStatus.completed) self.assertEquals(system.command_queue[2].status, CommandStatus.completed) # The bug manifests as two "Completed" records for the power # command which ran twice self.assertEquals(system.dyn_activity.filter_by(field_name=u"Power", new_value=u"Completed").count(), 3)
def delete_note(self, note): b = self.browser b.find_element_by_link_text('Notes').click() delete_and_confirm(b, '//tr[td/p/text()="%s"]' % note) # Test that it is hidden wait_for_condition(lambda: not b.find_element_by_xpath( '//tr[td/p/text()="%s"]' % note).is_displayed())
def test_control_characters_are_substituted(self): raw_line = 'Here is some badness: \x00\x07\x08\x7f.\n' substituted_line = 'Here is some badness: .\n' open(self.console_log, 'w').write(raw_line) wait_for_condition(self.check_console_log_registered) wait_for_condition( lambda: self.check_cached_log_contents(substituted_line))
def test_kernel_install_options_propagated_provision(self): b = self.browser login(b, user=self.user.user_name, password='******') b.get(get_server_base() + 'view/%s' % self.system.fqdn) # provision tab b.find_element_by_link_text('Provision').click() # select the distro Select(b.find_element_by_name('prov_install'))\ .select_by_visible_text(unicode(self.distro_tree)) def provision_koptions_populated(): if b.find_element_by_xpath("//input[@id='provision_koptions']").\ get_attribute('value') == \ u'key1=value1 key1=value2 key2=value key3 noverifyssl': return True wait_for_condition(provision_koptions_populated) # provision b.find_element_by_xpath("//form[@name='provision']//button[text()='Provision']").click() self.assert_(b.find_element_by_class_name('flash').text.startswith('Success')) # check self.assertEquals(self.system.command_queue[1].action, u'configure_netboot') self.assert_(u'key1=value1 key1=value2 key2=value key3' in \ self.system.command_queue[1].kernel_options)
def wait_for_commands_to_finish(system, timeout): def _commands_finished(): with session.begin(): session.expire_all() return system.command_queue[0].status in \ (CommandStatus.completed, CommandStatus.failed) wait_for_condition(_commands_finished, timeout=timeout)
def test_utf8_not_mangled(self): # The characters we really care about are the box drawing ones used by # Anaconda, but the bug actually affects a wide range of characters, so # we test an assortment of ones that might appear. line = u'┌───┤ Uničode röcks! аяяй 幸せ\n'.encode('utf8') open(self.console_log, 'w').write(line) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(line))
def wait_for_command_to_finish(command, timeout): def _command_completed(): with session.begin(): session.refresh(command) return command.status in (CommandStatus.completed, CommandStatus.failed) wait_for_condition(_command_completed, timeout=timeout)
def test_report_panic_with_nonascii_whiteboard(self): with session.begin(): self.recipe.recipeset.job.whiteboard = u'fat\u3000space' panic = 'Kernel panic - not syncing: Fatal exception in interrupt\n' with open(self.console_log, 'w') as f: f.write(panic) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(panic)) self.assert_panic_detected(u'Kernel panic')
def test_can_show_deleted_notes(self): b = self.browser login(b) note = self.add_note() self.delete_note(note) # Test that we have acreated a new element to toggle the notes b.find_element_by_link_text("Toggle deleted notes").click() # Test that it reappears when toggled wait_for_condition(lambda: b.find_element_by_xpath('//tr[td/p/text()="%s"]' % note).is_displayed())
def test_stores_guest_console_logs(self): # Verify Guest recipe handled well and host logfile present. self.assert_(self.monitor.console_watch.logfiles) self.assert_(not self.monitor_guest.console_watch.logfiles) wait_for_condition(self.check_console_log_registered) wait_for_condition( lambda: self.check_cached_log_contents(self.first_line))
def test_panic_across_chunk_boundaries_is_detected(self): # Write some junk followed by a panic string. The panic string will be # split across the chunk boundary. junk = 'z' * (ConsoleWatchFile.blocksize - 10) + '\n' panic = 'Kernel panic - not syncing: Fatal exception in interrupt\n' with open(self.console_log, 'w') as f: f.write(junk + panic) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(junk + panic)) self.assert_panic_detected(u'Kernel panic')
def test_recipe_is_aborted_on_script_failure(self): # If the external watchdog script exits non-zero, # beaker-watchdog ignores its output and aborts the recipe. with session.begin(): system = data_setup.create_system(lab_controller=self.get_lc(), fqdn='watchdog.script.please.crash') job = data_setup.create_running_job(system=system) self.addCleanup(self.cleanup_job, job) recipe = job.recipesets[0].recipes[0] recipe.extend(-1) wait_for_condition(lambda: self.check_watchdog_expiry(recipe))
def test_recipe_is_extended(self): # The external watchdog script is supposed to print the number of seconds # by which the watchdog timer should be extended. with session.begin(): system = data_setup.create_system(lab_controller=self.get_lc(), fqdn='watchdog.script.please.extend.600') job = data_setup.create_running_job(system=system) self.addCleanup(self.cleanup_job, job) recipe = job.recipesets[0].recipes[0] recipe.extend(-1) wait_for_condition(lambda: self.check_watchdog_extended(recipe, 600))
def test_multiple_hidden_notes(self): b = self.browser login(b) note = self.add_note() self.delete_note(note) # Add another note, delete it, and then toggle to make sure # both of the deleted notes display together, and are hidden together note_2 = self.add_note() self.delete_note(note_2) b.find_element_by_link_text("Toggle deleted notes").click() wait_for_condition(lambda: b.find_element_by_xpath('//tr[td/p/text()="%s"]' % note).is_displayed()) wait_for_condition(lambda: b.find_element_by_xpath('//tr[td/p/text()="%s"]' % note_2).is_displayed())
def test_install_failure_is_detected(self): anaconda_failure = "Press 'OK' to reboot your system.\n" open(self.console_log, 'w').write(anaconda_failure) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(anaconda_failure)) with session.begin(): task = self.recipe.tasks[0] session.refresh(task) self.assertEquals(task.status, TaskStatus.aborted) self.assertEquals(len(task.results), 2) # first one is the install failure message self.assertEquals(task.results[0].result, TaskResult.fail) self.assertEquals(task.results[0].log, anaconda_failure.strip()) # second one is the abort message which is added to all tasks self.assertEquals(task.results[1].result, TaskResult.warn) self.assertEquals(task.results[1].log, 'Installation failed')
def test_incomplete_lines_not_buffered_forever(self): # The panic detection is only applied to complete lines (terminated # with \n) but if for some reason we get a huge amount of output with # no newlines we need to give up at some point and check the incomplete # line. Otherwise in pathological cases we will end up consuming large # amounts of memory. # The actual breakpoint used in the code (2*blocksize) is arbitrary, # not chosen for any particularly good reason. long_panic_line = 'z' * (ConsoleWatchFile.blocksize - 10) + \ 'Kernel panic - not syncing: Fatal exception in interrupt ' + \ 'y' * (ConsoleWatchFile.blocksize + 100) with open(self.console_log, 'w') as f: f.write(long_panic_line) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(long_panic_line)) self.assert_panic_detected(u'Kernel panic')
def assert_command_is_delayed(command, min_delay, timeout): """ Asserts that the given command is not run for at least *min_delay* seconds, and also completes within *timeout* seconds after the delay has elapsed. """ def _command_completed(): with session.begin(): session.refresh(command) return command.status == CommandStatus.completed assert not _command_completed(), 'Command should not be completed initially' log.info('Command %s is not completed initially', command.id) time.sleep(min_delay) assert not _command_completed(), 'Command should still not be completed after delay' log.info('Command %s is still not completed after delay', command.id) wait_for_condition(_command_completed, timeout=timeout) log.info('Command %s is completed', command.id)
def test_stops_collecting_console_log_when_recipe_aborted(self): first_line = 'Here is the first line of the log file.\n' open(self.console_log, 'w').write(first_line) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(first_line)) # Abort the recipe with session.begin(): data_setup.mark_recipe_complete(self.recipe, only=True) # Wait for the watchdog to determine recipe aborted # Give beaker-watchdog a chance to notice time.sleep(get_conf().get('SLEEP_TIME') * 2) second_line = 'Here is the second line of the log file. FNORD FNORD FNORD\n' open(self.console_log, 'a').write(second_line) time.sleep(get_conf().get('SLEEP_TIME') * 2) self.assertTrue(self.check_cached_log_contents(first_line), "Log should just contain first log line")
def test_console_log_not_recreated_after_removed(self): # The scenario for this bug is: # 1. beaker-watchdog writes the console log # 2. recipe finishes (but beaker-watchdog hasn't noticed yet) # 3. beaker-transfer tranfers the logs and removes the local copies # 4. beaker-watchdog writes more to the end of the console log (in the # process re-registering the log file, and leaving the start of the # file filled with zeroes) # 5. beaker-transfer tranfers the logs again # This test checks that step 4 is prevented -- the console log updates # are silently discarded instead. # Step 1: beaker-watchdog writes the console log existing_data = 'Existing data\n' open(self.console_log, 'w').write(existing_data) wait_for_condition(self.check_console_log_registered) wait_for_condition( lambda: self.check_cached_log_contents(existing_data)) # Step 2: the recipe "finishes" # Don't actually mark it as finished in the database though, to ensure # the watchdog keeps monitoring the console log. # Step 3: beaker-transfer tranfers the logs and removes the local copies with session.begin(): LogRecipe.query.filter_by( parent=self.recipe, filename=u'console.log').one().server = u'http://elsewhere' os.remove(self.cached_console_log) # Step 4: beaker-watchdog tries to write more to the end of the console log open(self.console_log, 'a').write('More console output, after the recipe has finished\n') # Give beaker-watchdog a chance to notice time.sleep(get_conf().get('SLEEP_TIME') * 2) self.assert_(not os.path.exists(self.cached_console_log)) with session.begin(): self.assertEquals( LogRecipe.query.filter_by( parent=self.recipe, filename=u'console.log').one().server, u'http://elsewhere')
def test_panic_not_doubly_detected(self): # Write a panic string to the console log and wait for panic. oops_line = 'Oops: 0002 [#1] PREEMPT SMP\n' open(self.console_log, 'w').write(oops_line) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(oops_line)) self.assert_panic_detected(u'Oops: ') # Now check our kill_time session.expire_all() with session.begin(): kill_time1 = self.recipe.watchdog.kill_time # Add another panic entry open(self.console_log, 'a+').write(oops_line) wait_for_condition( lambda: self.check_cached_log_contents(oops_line * 2)) session.expire_all() with session.begin(): # Ensure that there are no new panic results self.assertEquals(len(self.recipe.tasks[0].results), 1) # Ensure that our kill time has not been extended again! kill_time2 = self.recipe.watchdog.kill_time self.assertEquals(kill_time1, kill_time2)
def test_console_log_not_recreated_after_removed(self): # The scenario for this bug is: # 1. beaker-watchdog writes the console log # 2. recipe finishes (but beaker-watchdog hasn't noticed yet) # 3. beaker-transfer tranfers the logs and removes the local copies # 4. beaker-watchdog writes more to the end of the console log (in the # process re-registering the log file, and leaving the start of the # file filled with zeroes) # 5. beaker-transfer tranfers the logs again # This test checks that step 4 is prevented -- the console log updates # are silently discarded instead. # Step 1: beaker-watchdog writes the console log existing_data = 'Existing data\n' open(self.console_log, 'w').write(existing_data) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(existing_data)) # Step 2: the recipe "finishes" # Don't actually mark it as finished in the database though, to ensure # the watchdog keeps monitoring the console log. # Step 3: beaker-transfer tranfers the logs and removes the local copies with session.begin(): LogRecipe.query.filter_by(parent=self.recipe, filename=u'console.log').one().server = u'http://elsewhere' os.remove(self.cached_console_log) # Step 4: beaker-watchdog tries to write more to the end of the console log open(self.console_log, 'a').write( 'More console output, after the recipe has finished\n') # Give beaker-watchdog a chance to notice time.sleep(get_conf().get('SLEEP_TIME') * 2) self.assert_(not os.path.exists(self.cached_console_log)) with session.begin(): self.assertEquals(LogRecipe.query.filter_by(parent=self.recipe, filename=u'console.log').one().server, u'http://elsewhere')
def test_report_problem(self): b = self.browser # Test can send problem report succesfully b.get(get_server_base() + 'view/%s' % self.system.fqdn) b.find_element_by_xpath('//button[text()="Report problem"]').click() b.find_element_by_name('message').send_keys('testing problem') b.find_element_by_xpath('//button[text()="Report"]').click() # Wait for our success box b.find_element_by_xpath('//div[contains(@class, "alert-success")]' '/h4[text()="Report sent"]') # Check the email was sent wait_for_condition(lambda: len(self.mail_capture.captured_mails) == 1) sender, rcpts, raw_msg = self.mail_capture.captured_mails[0] payload = 'A Beaker user has reported a problem with system \n' \ '%s <%sview/%s>.\n\n' \ 'Reported by: %s\n\n' \ 'Problem description:\n' \ 'testing problem' \ % (self.system_fqdn, get_server_base(), self.system_fqdn, self.problem_reporter.display_name) self._std_check_mail(sender, rcpts, raw_msg, 'system-problem', payload, 'Problem reported for %s' % self.system.fqdn)
def test_loan_request(self): b = self.browser # Test can send loan request succesfully b.get(get_server_base() + 'view/%s' % self.system.fqdn) b.find_element_by_link_text('Loan').click() b.find_element_by_xpath('//button[text()="Request Loan"]').click() b.find_element_by_name('message').send_keys('request loan') b.find_element_by_xpath('//button[text()="Request"]').click() # Wait for our success box b.find_element_by_xpath('//div[contains(@class, "alert-success")]' '/h4[text()="Request sent"]') # Check the email was sent wait_for_condition(lambda: len(self.mail_capture.captured_mails) == 1) sender, rcpts, raw_msg = self.mail_capture.captured_mails[0] payload = 'A Beaker user has requested you loan them the system\n' \ '%s <%sview/%s>.\n' \ 'Here is a copy of their request:\n' \ 'request loan\n Requested by: %s' \ % (self.system_fqdn, get_server_base(), self.system_fqdn, self.problem_reporter.display_name) self._std_check_mail(sender, rcpts, raw_msg, 'loan-request', payload, 'Loan request for %s' % self.system.fqdn)
def test_stores_second_console_log(self): first_line = 'Here is the first line of the second log file.\n' open(self.console_log_2, 'w').write(first_line) wait_for_condition(self.check_console_log2_registered) wait_for_condition(lambda: self.check_cached_log2_contents(first_line)) second_line = 'Here is the second line of the BMC log file. FNORD FNORD FNORD\n' open(self.console_log_2, 'a').write(second_line) wait_for_condition( lambda: self.check_cached_log2_contents(first_line + second_line))
def test_stores_console_log(self): first_line = 'Here is the first line of the log file.\n' open(self.console_log, 'w').write(first_line) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(first_line)) second_line = 'Here is the second line of the log file. FNORD FNORD FNORD\n' open(self.console_log, 'a').write(second_line) wait_for_condition(lambda: self.check_cached_log_contents( first_line + second_line))
def test_install_failure_is_not_reported_after_installation_is_finished(self): anaconda_success = 'blah blah installing... done\n' open(self.console_log, 'w').write(anaconda_success) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(anaconda_success)) with session.begin(): data_setup.mark_recipe_installation_finished(self.recipe) anaconda_failure = "Press 'OK' to reboot your system.\n" open(self.console_log, 'a').write(anaconda_failure) wait_for_condition(lambda: self.check_cached_log_contents( anaconda_success + anaconda_failure)) with session.begin(): task = self.recipe.tasks[0] session.refresh(task) self.assertEquals(task.status, TaskStatus.running)
def test_install_failure_is_not_reported_after_installation_is_finished(self): anaconda_success = 'blah blah installing... done\n' open(self.console_log, 'w').write(anaconda_success) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(anaconda_success)) with session.begin(): data_setup.mark_recipe_installation_finished(self.recipe) data_setup.mark_recipe_running(self.recipe, only=True) anaconda_failure = "Press 'OK' to reboot your system.\n" open(self.console_log, 'a').write(anaconda_failure) wait_for_condition(lambda: self.check_cached_log_contents( anaconda_success + anaconda_failure)) with session.begin(): task = self.recipe.tasks[0] session.refresh(task) self.assertEquals(task.status, TaskStatus.running)
def test_kernel_install_options_propagated_view(self): with session.begin(): self.system.provisions[self.distro_tree.arch] = \ Provision(arch=self.distro_tree.arch, ks_meta = u'key1=value1 key1=value2 key2=value key3', kernel_options=u'key1=value1 key1=value2 key2=value key3', kernel_options_post=u'key1=value1 key1=value2 key2=value key3') b = self.browser login(b) b.get(get_server_base() + 'view/%s' % self.system.fqdn) # provision tab b.find_element_by_link_text('Provision').click() # select the distro Select(b.find_element_by_name('prov_install'))\ .select_by_visible_text(unicode(self.distro_tree)) # check the kernel install options field def provision_ks_meta_populated(): if b.find_element_by_xpath("//input[@id='provision_ks_meta']")\ .get_attribute('value') == \ u'key1=value1 key1=value2 key2=value key3': return True # check the kernel install options field def provision_koptions_populated(): if b.find_element_by_xpath("//input[@id='provision_koptions']")\ .get_attribute('value') == \ u'key1=value1 key1=value2 key2=value key3 noverifyssl': return True # check the kernel post install options field def provision_koptions_post_populated(): if b.find_element_by_xpath("//input[@id='provision_koptions_post']")\ .get_attribute('value') == \ 'key1=value1 key1=value2 key2=value key3': return True wait_for_condition(provision_ks_meta_populated) wait_for_condition(provision_koptions_populated) wait_for_condition(provision_koptions_post_populated)
def test_panic_not_doubly_detected(self): # Write a panic string to the console log and wait for panic. oops_line = 'Oops: 0002 [#1] PREEMPT SMP\n' open(self.console_log, 'w').write(oops_line) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(oops_line)) self.assert_panic_detected(u'Oops: ') # Now check our kill_time session.expire_all() with session.begin(): kill_time1 = self.recipe.watchdog.kill_time # Add another panic entry open(self.console_log, 'a+').write(oops_line) wait_for_condition(lambda: self.check_cached_log_contents(oops_line * 2)) session.expire_all() with session.begin(): # Ensure that there are no new panic results self.assertEquals(len(self.recipe.tasks[0].results), 1) # Ensure that our kill time has not been extended again! kill_time2 = self.recipe.watchdog.kill_time self.assertEquals(kill_time1, kill_time2)
def test_control_characters_are_substituted(self): raw_line = 'Here is some badness: \x00\x07\x08\x7f.\n' substituted_line = 'Here is some badness: .\n' open(self.console_log, 'w').write(raw_line) wait_for_condition(self.check_console_log_registered) wait_for_condition(lambda: self.check_cached_log_contents(substituted_line))
def wait_for_commands_completed(system, timeout): def _commands_completed(): with session.begin(): session.expire_all() return system.command_queue[0].status == CommandStatus.completed wait_for_condition(_commands_completed, timeout=timeout)
def wait_for_condition(cls, cond, wait_time=30): wait_for_condition(cond, timeout=wait_time)