def simulate(self): self.simulation = self.simulation_cfg.bootstrap(self.sync_callback, boot_controllers=boot_mock_controllers) connect_to_mock_controllers(self.simulation) # Reproduce the routing table state. for next_event in self.event_list: msg.success("Injecting %r" % next_event) next_event.manually_inject(self.simulation) # now filter out all flow_mods that don't correspond to an entry in the # final routing table. Do that by walking backwards through the flow_mods, # and checking if they match the flow table. If so, add it to list, and # remove all flow entries that currently match it to filter overlapping # flow_mods from earlier in the event_list. relevent_flow_mods = [] all_flow_mods = [e for e in self.event_list if type(e.get_packet()) == ofp_flow_mod] for last_event in reversed(all_flow_mods): switch = self.simulation.topology.get_switch(last_event.dpid) if switch.table.matching_entries(last_event.get_packet().match) != []: relevent_flow_mods.append(last_event) switch.table.remove_matching_entries(last_event.get_packet().match) # Now print them in the forward direction. msg.interactive("Filtered flow mods:") for next_event in reversed(relevent_flow_mods): print "%r" % next_event return self.simulation
def do_invariant_check(): if self.log_invariant_checks: self._log_input_event(CheckInvariants(invariant_check=self.invariant_check, fail_on_error=self.halt_on_violation)) controllers_with_violations = self.invariant_check(self.simulation) if controllers_with_violations != []: msg.fail("The following controllers had correctness violations!: %s" % str(controllers_with_violations)) self._log_input_event(InvariantViolation(controllers_with_violations)) if self.halt_on_violation: return True else: msg.interactive("No correctness violations!")
def proceed(self, simulation): try: violations = self.invariant_check(simulation) except NameError as e: raise ValueError('''Closures are unsupported for invariant check ''' '''functions.\n Use dynamic imports inside of your ''' '''invariant check code and define all globals ''' '''locally.\n NameError: %s''' % str(e)) if violations != []: msg.fail("The following controllers had correctness violations!: %s" % str(violations)) if self.fail_on_error: msg.fail("Exiting: fail_on_error=True") exit(5) else: msg.interactive("No correctness violations!") return True
def do_invariant_check(): if self.log_invariant_checks: self._log_input_event( CheckInvariants(invariant_check=self.invariant_check, fail_on_error=self.halt_on_violation)) controllers_with_violations = self.invariant_check( self.simulation) if controllers_with_violations != []: msg.fail( "The following controllers had correctness violations!: %s" % str(controllers_with_violations)) self._log_input_event( InvariantViolation(controllers_with_violations)) if self.halt_on_violation: return True else: msg.interactive("No correctness violations!")
def simulate(self, check_reproducability=True): if self._runtime_stats is not None: self._runtime_stats["total_inputs"] = len(self.dag.input_events) self._runtime_stats["total_events"] = len(self.dag) # inject domain knowledge into the dag self.dag.mark_invalid_input_sequences() self.dag = self.dag.filter_unsupported_input_types() if len(self.dag) == 0: raise RuntimeError("No supported input types?") if check_reproducability: # First, run through without pruning to verify that the violation exists if self._runtime_stats is not None: self._runtime_stats["replay_start_epoch"] = time.time() violations = self.replay(self.dag) if self._runtime_stats is not None: self._runtime_stats["replay_end_epoch"] = time.time() if violations == []: self.log("Unable to reproduce correctness violation!") sys.exit(5) self.log("Violation reproduced successfully! Proceeding with pruning") if self._runtime_stats is not None: self._runtime_stats["prune_start_epoch"] = time.time() self._ddmin(2) if self._runtime_stats is not None: self._runtime_stats["prune_end_epoch"] = time.time() self._dump_runtime_stats() msg.interactive("Final MCS (%d elements): %s" % (len(self.dag.input_events),str(self.dag.input_events))) if self.mcs_trace_path is not None: self._dump_mcs_trace() return self.dag.events
def interrupt(sgn, frame): msg.interactive("Interrupting fuzzer, dropping to console (press ^C again to terminate)") signal.signal(signal.SIGINT, self.old_interrupt) self.old_interrupt = None self.interrupted = True raise KeyboardInterrupt()
def show_flow_tables(simulation): for switch in simulation.topology.switches: msg.interactive("Switch %s" % switch.dpid) switch.show_flow_table()
def show_flow_tables(simulation): for switch in simulation.topology.switches: msg.interactive("Switch %s" % switch.dpid) switch.show_flow_table()
def __init__(self, simulation_cfg, superlog_path_or_dag, invariant_check_name=None, transform_dag=None, end_wait_seconds=0.5, mcs_trace_path=None, extra_log=None, runtime_stats_path=None, wait_on_deterministic_values=False, no_violation_verification_runs=1, optimized_filtering=False, forker=LocalForker(), replay_final_trace=True, strict_assertion_checking=False, delay_flow_mods=False, **kwargs): super(MCSFinder, self).__init__(simulation_cfg) # number of subsequences delta debugging has examined so far, for # distingushing runtime stats from different intermediate runs. self.subsequence_id = 0 self.mcs_log_tracker = None self.replay_log_tracker = None self.mcs_trace_path = mcs_trace_path self.sync_callback = None self._log = logging.getLogger("mcs_finder") if invariant_check_name is None: raise ValueError("Must specify invariant check") if invariant_check_name not in name_to_invariant_check: raise ValueError( '''Unknown invariant check %s.\n''' '''Invariant check name must be defined in config.invariant_checks''', invariant_check_name) self.invariant_check = name_to_invariant_check[invariant_check_name] if type(superlog_path_or_dag) == str: self.superlog_path = superlog_path_or_dag # The dag is codefied as a list, where each element has # a list of its dependents self.dag = EventDag(log_parser.parse_path(self.superlog_path)) else: self.dag = superlog_path_or_dag last_invariant_violation = self.dag.get_last_invariant_violation() if last_invariant_violation is None: raise ValueError("No invariant violation found in dag...") violations = last_invariant_violation.violations if len(violations) > 1: self.bug_signature = None while self.bug_signature is None: msg.interactive( "\n------------------------------------------\n") msg.interactive( "Multiple violations detected! Choose one for MCS Finding:" ) for i, violation in enumerate(violations): msg.interactive(" [%d] %s" % (i + 1, violation)) violation_index = msg.raw_input("> ") if re.match("^\d+$", violation_index) is None or\ int(violation_index) < 1 or\ int(violation_index) > len(violations): msg.fail("Must provide an integer between 1 and %d!" % len(violations)) continue self.bug_signature = violations[int(violation_index) - 1] else: self.bug_signature = violations[0] msg.success( "\nBug signature to match is %s. Proceeding with MCS finding!\n" % self.bug_signature) self.transform_dag = transform_dag # A second log with just our MCS progress log messages self._extra_log = extra_log self.kwargs = kwargs self.end_wait_seconds = end_wait_seconds self.wait_on_deterministic_values = wait_on_deterministic_values # `no' means "number" self.no_violation_verification_runs = no_violation_verification_runs self._runtime_stats = RuntimeStats( self.subsequence_id, runtime_stats_path=runtime_stats_path) # Whether to try alternate trace splitting techiques besides splitting by time. self.optimized_filtering = optimized_filtering self.forker = forker self.replay_final_trace = replay_final_trace self.strict_assertion_checking = strict_assertion_checking self.delay_flow_mods = delay_flow_mods
def __init__(self, simulation_cfg, superlog_path_or_dag, invariant_check_name=None, transform_dag=None, end_wait_seconds=0.5, mcs_trace_path=None, extra_log=None, runtime_stats_path=None, wait_on_deterministic_values=False, no_violation_verification_runs=1, optimized_filtering=False, forker=LocalForker(), replay_final_trace=True, strict_assertion_checking=False, **kwargs): super(MCSFinder, self).__init__(simulation_cfg) # number of subsequences delta debugging has examined so far, for # distingushing runtime stats from different intermediate runs. self.subsequence_id = 0 self.mcs_log_tracker = None self.replay_log_tracker = None self.mcs_trace_path = mcs_trace_path self.sync_callback = None self._log = logging.getLogger("mcs_finder") if invariant_check_name is None: raise ValueError("Must specify invariant check") if invariant_check_name not in name_to_invariant_check: raise ValueError('''Unknown invariant check %s.\n''' '''Invariant check name must be defined in config.invariant_checks''', invariant_check_name) self.invariant_check = name_to_invariant_check[invariant_check_name] if type(superlog_path_or_dag) == str: self.superlog_path = superlog_path_or_dag # The dag is codefied as a list, where each element has # a list of its dependents self.dag = EventDag(log_parser.parse_path(self.superlog_path)) else: self.dag = superlog_path_or_dag last_invariant_violation = self.dag.get_last_invariant_violation() if last_invariant_violation is None: raise ValueError("No invariant violation found in dag...") violations = last_invariant_violation.violations if len(violations) > 1: self.bug_signature = None while self.bug_signature is None: msg.interactive("\n------------------------------------------\n") msg.interactive("Multiple violations detected! Choose one for MCS Finding:") for i, violation in enumerate(violations): msg.interactive(" [%d] %s" % (i+1, violation)) violation_index = msg.raw_input("> ") if re.match("^\d+$", violation_index) is None or\ int(violation_index) < 1 or\ int(violation_index) > len(violations): msg.fail("Must provide an integer between 1 and %d!" % len(violations)) continue self.bug_signature = violations[int(violation_index)-1] else: self.bug_signature = violations[0] msg.success("\nBug signature to match is %s. Proceeding with MCS finding!\n" % self.bug_signature) self.transform_dag = transform_dag # A second log with just our MCS progress log messages self._extra_log = extra_log self.kwargs = kwargs self.end_wait_seconds = end_wait_seconds self.wait_on_deterministic_values = wait_on_deterministic_values # `no' means "number" self.no_violation_verification_runs = no_violation_verification_runs self._runtime_stats = RuntimeStats(self.subsequence_id, runtime_stats_path=runtime_stats_path) # Whether to try alternate trace splitting techiques besides splitting by time. self.optimized_filtering = optimized_filtering self.forker = forker self.replay_final_trace = replay_final_trace self.strict_assertion_checking = strict_assertion_checking
def replay(self, new_dag, label, ignore_runtime_stats=False): # Run the simulation forward if self.transform_dag: new_dag = self.transform_dag(new_dag) self._runtime_stats.record_replay_stats(len(new_dag.input_events)) # N.B. this function is run as a child process. def play_forward(results_dir, subsequence_id): # TODO(cs): need to serialize the parameters to Replayer rather than # wrapping them in a closure... otherwise, can't use RemoteForker # TODO(aw): MCSFinder needs to configure Simulation to always let DataplaneEvents pass through create_clean_python_dir(results_dir) # Copy stdout and stderr to a file "replay.out" tee = Tee(open(os.path.join(results_dir, "replay.out"), "w")) tee.tee_stdout() tee.tee_stderr() # Set up replayer. input_logger = InputLogger() replayer = Replayer(self.simulation_cfg, new_dag, wait_on_deterministic_values=self.wait_on_deterministic_values, input_logger=input_logger, allow_unexpected_messages=False, pass_through_whitelisted_messages=True, **self.kwargs) replayer.init_results(results_dir) self._runtime_stats = RuntimeStats(subsequence_id) violations = [] simulation = None try: simulation = replayer.simulate() self._track_new_internal_events(simulation, replayer) # Wait a bit in case the bug takes awhile to happen self.log("Sleeping %d seconds after run" % self.end_wait_seconds) time.sleep(self.end_wait_seconds) violations = self.invariant_check(simulation) if violations != []: input_logger.log_input_event(InvariantViolation(violations)) except SystemExit: # One of the invariant checks bailed early. Oddly, this is not an # error for us, it just means that there were no violations... # [this logic is arguably broken] # Return no violations, and let Forker handle system exit for us. violations = [] finally: input_logger.close(replayer, self.simulation_cfg, skip_mcs_cfg=True) if simulation is not None: simulation.clean_up() tee.close() if self.strict_assertion_checking: test_serialize_response(violations, self._runtime_stats.client_dict()) timed_out_internal = [ e.label for e in new_dag.events if e.timed_out ] return (violations, self._runtime_stats.client_dict(), timed_out_internal) # TODO(cs): once play_forward() is no longer a closure, register it only once self.forker.register_task("play_forward", play_forward) results_dir = self.replay_log_tracker.get_replay_logger_dir(label) self.subsequence_id += 1 (violations, client_runtime_stats, timed_out_internal) = self.forker.fork("play_forward", results_dir, self.subsequence_id) new_dag.set_events_as_timed_out(timed_out_internal) bug_found = False if violations != []: msg.fail("Violations: %s" % str(violations)) if self.bug_signature in violations: bug_found = True else: msg.fail("Bug does not match initial violation fingerprint!") else: msg.interactive("No correctness violations!") if not ignore_runtime_stats: self._runtime_stats.merge_client_dict(client_runtime_stats) return bug_found
def invariant_check_prompt(self): answer = msg.raw_input('Check Invariants? [Ny]') if answer != '' and answer.lower() != 'n': msg.interactive("Which one?") msg.interactive(" 'o' - omega") msg.interactive(" 'c' - connectivity") msg.interactive(" 'lo' - loops") msg.interactive(" 'li' - controller liveness") answer = msg.raw_input("> ") result = None message = "" if answer.lower() == 'o': self._log_input_event( CheckInvariants( invariant_check=InvariantChecker.check_correspondence)) result = InvariantChecker.check_correspondence(self.simulation) message = "Controllers with miscorrepondence: " elif answer.lower() == 'c': self._log_input_event( CheckInvariants( invariant_check=InvariantChecker.check_connectivity)) result = self.invariant_checker.check_connectivity( self.simulation) message = "Disconnected host pairs: " elif answer.lower() == 'lo': self._log_input_event( CheckInvariants( invariant_check=InvariantChecker.check_loops)) result = self.invariant_checker.check_loops(self.simulation) message = "Loops: " elif answer.lower() == 'li': self._log_input_event( CheckInvariants( invariant_check=InvariantChecker.check_liveness)) result = self.invariant_checker.check_loops(self.simulation) message = "Crashed controllers: " else: log.warn("Unknown input...") if result is None: return else: msg.interactive("%s: %s" % (message, str(result)))
def __init__(self, simulation_cfg, superlog_path_or_dag, invariant_check_name="", bug_signature="", transform_dag=None, mcs_trace_path=None, extra_log=None, runtime_stats_path=None, max_replays_per_subsequence=1, optimized_filtering=False, forker=LocalForker(), replay_final_trace=True, strict_assertion_checking=False, no_violation_verification_runs=None, **kwargs): ''' Note that you may pass in any keyword argument for Replayer to MCSFinder, except 'bug_signature' and 'invariant_check_name' ''' super(MCSFinder, self).__init__(simulation_cfg) # number of subsequences delta debugging has examined so far, for # distingushing runtime stats from different intermediate runs. self.subsequence_id = 0 self.mcs_log_tracker = None self.replay_log_tracker = None self.mcs_trace_path = mcs_trace_path self.sync_callback = None self._log = logging.getLogger("mcs_finder") if invariant_check_name == "": raise ValueError("Must specify invariant check") if invariant_check_name not in name_to_invariant_check: raise ValueError('''Unknown invariant check %s.\n''' '''Invariant check name must be defined in config.invariant_checks''', invariant_check_name) self.invariant_check_name = invariant_check_name self.invariant_check = name_to_invariant_check[invariant_check_name] if type(superlog_path_or_dag) == str: self.superlog_path = superlog_path_or_dag # The dag is codefied as a list, where each element has # a list of its dependents self.dag = EventDag(log_parser.parse_path(self.superlog_path)) else: self.dag = superlog_path_or_dag if self.simulation_cfg.ignore_interposition: filtered_events = [e for e in self.dag.events if type(e) not in all_internal_events] self.dag = EventDag(filtered_events) last_invariant_violation = self.dag.get_last_invariant_violation() if last_invariant_violation is None: raise ValueError("No invariant violation found in dag...") violations = last_invariant_violation.violations self.bug_signature = bug_signature if len(violations) > 1: while self.bug_signature == "": msg.interactive("\n------------------------------------------\n") msg.interactive("Multiple violations detected! Choose one for MCS Finding:") for i, violation in enumerate(violations): msg.interactive(" [%d] %s" % (i+1, violation)) violation_index = msg.raw_input("> ") if re.match("^\d+$", violation_index) is None or\ int(violation_index) < 1 or\ int(violation_index) > len(violations): msg.fail("Must provide an integer between 1 and %d!" % len(violations)) continue self.bug_signature = violations[int(violation_index)-1] if self.bug_signature == "": self.bug_signature = violations[0] msg.success("\nBug signature to match is %s. Proceeding with MCS finding!\n" % self.bug_signature) self.transform_dag = transform_dag # A second log with just our MCS progress log messages self._extra_log = extra_log self.kwargs = kwargs unknown_kwargs = [ k for k in kwargs.keys() if k not in Replayer.kwargs ] if unknown_kwargs != []: raise ValueError("Unknown kwargs %s" % str(unknown_kwargs)) if no_violation_verification_runs is not None: raise ValueError('''no_violation_verification_runs parameter is deprecated. ''' '''Use max_replays_per_subsequence.''') self.max_replays_per_subsequence = max_replays_per_subsequence self._runtime_stats = RuntimeStats(self.subsequence_id, runtime_stats_path=runtime_stats_path) # Whether to try alternate trace splitting techiques besides splitting by time. self.optimized_filtering = optimized_filtering self.forker = forker self.replay_final_trace = replay_final_trace self.strict_assertion_checking = strict_assertion_checking
def invariant_check_prompt(self): answer = msg.raw_input('Check Invariants? [Ny]') if answer != '' and answer.lower() != 'n': msg.interactive("Which one?") msg.interactive(" 'o' - omega") msg.interactive(" 'c' - connectivity") msg.interactive(" 'lo' - loops") msg.interactive(" 'li' - controller liveness") answer = msg.raw_input("> ") result = None message = "" if answer.lower() == 'o': self._log_input_event(CheckInvariants(invariant_check=InvariantChecker.check_correspondence)) result = InvariantChecker.check_correspondence(self.simulation) message = "Controllers with miscorrepondence: " elif answer.lower() == 'c': self._log_input_event(CheckInvariants(invariant_check=InvariantChecker.check_connectivity)) result = self.invariant_checker.check_connectivity(self.simulation) message = "Disconnected host pairs: " elif answer.lower() == 'lo': self._log_input_event(CheckInvariants(invariant_check=InvariantChecker.check_loops)) result = self.invariant_checker.check_loops(self.simulation) message = "Loops: " elif answer.lower() == 'li': self._log_input_event(CheckInvariants(invariant_check=InvariantChecker.check_liveness)) result = self.invariant_checker.check_loops(self.simulation) message = "Crashed controllers: " else: log.warn("Unknown input...") if result is None: return else: msg.interactive("%s: %s" % (message, str(result)))