commit 2ce89fc1331b6eec44599639a79f7a34e5c7a6e6 Author: Arturo Filastò <art@fuffa.org> Date: Tue Nov 27 16:55:45 2012 +0100 Always write report to file * Do not write to backend reporter if report creation fails * More robust error handling * Improve debug log output --- ooni/__init__.py | 1 + ooni/config.py | 8 ++--- ooni/reporter.py | 53 +++++++++++++++++++++----------------- ooni/runner.py | 73 +++++++++++++++++++++++++++++++++++------------------ 4 files changed, 81 insertions(+), 54 deletions(-) diff --git a/ooni/__init__.py b/ooni/__init__.py index 2763b16..bf98e16 100644 --- a/ooni/__init__.py +++ b/ooni/__init__.py @@ -1,4 +1,5 @@ # -*- encoding: utf-8 -*- + from . import config from . import inputunit from . import kit diff --git a/ooni/config.py b/ooni/config.py index 1c40b32..bc255be 100644 --- a/ooni/config.py +++ b/ooni/config.py @@ -96,11 +96,9 @@ def generateReportFilenames(): raise TestFilenameNotSet test_name = '.'.join(test_filename.split(".")[:-1]) - base_filename = "%s_%s_"+otime.timestamp()+".%s" - reports.yamloo = base_filename % (test_name, "report", "yamloo") - print "Setting yamloo to %s" % reports.yamloo - reports.pcap = base_filename % (test_name, "packets", "pcap") - print "Setting pcap to %s" % reports.pcap + frm_str = "report_%s_"+otime.timestamp()+".%s" + reports.yamloo = frm_str % (test_name, "yamloo") + reports.pcap = frm_str % (test_name, "pcap") if not basic: # Here we make sure that we instance the config file attributes only once diff --git a/ooni/reporter.py b/ooni/reporter.py index 8e4eede..abbd9c9 100644 --- a/ooni/reporter.py +++ b/ooni/reporter.py @@ -7,6 +7,7 @@ # :authors: Arturo Filastò, Isis Lovecruft # :license: see included LICENSE file +import traceback import itertools import logging import sys @@ -14,7 +15,6 @@ import os import time import yaml import json -import traceback from yaml.representer import * from yaml.emitter import * @@ -115,7 +115,6 @@ def getTestDetails(options): from ooni import __version__ as software_version client_geodata = {} - if config.privacy.includeip or \ config.privacy.includeasn or \ config.privacy.includecountry or \ @@ -224,7 +223,6 @@ class YAMLReporter(OReporter): self._write('---\n') self._write(safe_dump(entry)) self._write('...\n') - return @defer.inlineCallbacks def createReport(self, options): @@ -242,18 +240,22 @@ class YAMLReporter(OReporter): self._stream.close() -class OONIBReportUpdateFailed(Exception): +class OONIBReportError(Exception): + pass + +class OONIBReportUpdateError(OONIBReportError): pass -class OONIBReportCreationFailed(Exception): +class OONIBReportCreationError(OONIBReportError): pass -class OONIBTestDetailsLookupFailed(Exception): +class OONIBTestDetailsLookupError(OONIBReportError): pass class OONIBReporter(OReporter): def __init__(self, cmd_line_options): self.backend_url = cmd_line_options['collector'] + self.report_id = None from ooni.utils.txagentwithsocks import Agent from twisted.internet import reactor @@ -287,15 +289,10 @@ class OONIBReporter(OReporter): response = yield self.agent.request("PUT", url, bodyProducer=bodyProducer) except: - # XXX we must trap this in the runner and make sure to report the data later. + # XXX we must trap this in the runner and make sure to report the + # data later. log.err("Error in writing report entry") - raise OONIBReportUpdateFailed - - #parsed_response = json.loads(backend_response) - #self.report_id = parsed_response['report_id'] - #self.backend_version = parsed_response['backend_version'] - #log.debug("Created report with id %s" % parsed_response['report_id']) - + raise OONIBReportUpdateError @defer.inlineCallbacks def createReport(self, options): @@ -305,39 +302,47 @@ class OONIBReporter(OReporter): test_name = options['name'] test_version = options['version'] - log.debug("Creating report with OONIB Reporter") url = self.backend_url + '/report/new' - software_version = '0.0.1' - test_details = yield getTestDetails(options) + try: + test_details = yield getTestDetails(options) + except Exception, e: + log.exception(e) + test_details['options'] = self.cmd_line_options + log.debug("Obtained test_details: %s" % test_details) + content = '---\n' content += safe_dump(test_details) content += '...\n' - request = {'software_name': 'ooniprobe', - 'software_version': software_version, + request = {'software_name': test_details['software_name'], + 'software_version': test_details['software_version'], 'test_name': test_name, 'test_version': test_version, - 'progress': 0, 'content': content } - log.debug("Creating report via url %s" % url) + + log.msg("Reporting %s" % url) request_json = json.dumps(request) log.debug("Sending %s" % request_json) bodyProducer = StringProducer(json.dumps(request)) + log.msg("Creating report with OONIB Reporter. Please be patient.") + log.msg("This may take up to 1-2 minutes...") + try: response = yield self.agent.request("POST", url, bodyProducer=bodyProducer) except ConnectionRefusedError: log.err("Connection to reporting backend failed (ConnectionRefusedError)") - raise OONIBReportCreationFailed + raise OONIBReportCreationError + except Exception, e: log.exception(e) - raise OONIBReportCreationFailed + raise OONIBReportCreationError # This is a little trix to allow us to unspool the response. We create # a deferred and call yield on it. @@ -350,7 +355,7 @@ class OONIBReporter(OReporter): parsed_response = json.loads(backend_response) except Exception, e: log.exception(e) - raise OONIBReportCreationFailed + raise OONIBReportCreationError self.report_id = parsed_response['report_id'] self.backend_version = parsed_response['backend_version'] diff --git a/ooni/runner.py b/ooni/runner.py index 97d4d7e..5fa80ae 100644 --- a/ooni/runner.py +++ b/ooni/runner.py @@ -26,8 +26,7 @@ from txtorcon import TorState, launch_tor from ooni import config -from ooni.reporter import OONIBReporter, YAMLReporter -from ooni.reporter import OONIBReportCreationFailed +from ooni.reporter import OONIBReporter, YAMLReporter, OONIBReportError from ooni.inputunit import InputUnitFactory from ooni.nettest import NetTestCase, NoPostProcessor @@ -154,25 +153,45 @@ def loadTestsAndOptions(classes, cmd_line_options): return test_cases, options -def runTestCasesWithInput(test_cases, test_input, oreporter): +def runTestCasesWithInput(test_cases, test_input, yaml_reporter, + oonib_reporter=None): """ Runs in parallel all the test methods that are inside of the specified test case. Reporting happens every time a Test Method has concluded running. Once all the test methods have been called we check to see if the postProcessing class method returns something. If it does return something we will write this as another entry inside of the report called post_processing. + + Args: + + test_cases (list): A list of tuples containing the test_class (a + class) and the test_method (a string) + + test_input (instance): Any instance that will be passed as input to + the test. + + yaml_reporter: An instance of :class:ooni.reporter.YAMLReporter + + oonib_reporter: An instance of :class:ooni.reporter.OONIBReporter. If + this is set to none then we will only report to the YAML reporter. + """ # This is used to store a copy of all the test reports tests_report = {} def test_done(result, test_instance, test_name): - log.debug("runTestWithInput: concluded %s" % test_name) + log.msg("Successfully finished running %s" % test_name) + log.debug("Deferred callback result: %s" % result) tests_report[test_name] = dict(test_instance.report) - return oreporter.testDone(test_instance, test_name) + if not oonib_reporter: + return yaml_reporter.testDone(test_instance, test_name) + d1 = oonib_reporter.testDone(test_instance, test_name) + d2 = yaml_reporter.testDone(test_instance, test_name) + return defer.DeferredList([d1, d2]) def test_error(failure, test_instance, test_name): - log.err("run Test Cases With Input problem") + log.err("Error in running %s" % test_name) log.exception(failure) return @@ -184,7 +203,11 @@ def runTestCasesWithInput(test_cases, test_input, oreporter): post = getattr(test_instance, 'postProcessor') try: post_processing = post(tests_report) - return oreporter.testDone(test_instance, 'summary') + if not oonib_reporter: + return yaml_reporter.testDone(test_instance, 'summary') + d1 = oonib_reporter.testDone(test_instance, 'summary') + d2 = yaml_reporter.testDone(test_instance, 'summary') + return defer.DeferredList([d1, d2]) except NoPostProcessor: log.debug("No post processor configured") return @@ -195,12 +218,11 @@ def runTestCasesWithInput(test_cases, test_input, oreporter): test_class = test_case[0] test_method = test_case[1] - log.msg("Running %s with %s" % (test_method, test_input)) + log.msg("Running %s with %s..." % (test_method, test_input)) test_instance = test_class() test_instance.input = test_input test_instance.report = {} - log.msg("Processing %s" % test_instance.name) # use this to keep track of the test runtime test_instance._start_time = time.time() # call setups on the test @@ -351,7 +373,7 @@ def updateProgressMeters(test_filename, input_unit_factory, config.state[test_filename].per_item_average = 2.0 input_unit_idx = float(config.stateDict[test_filename]) - input_unit_items = float(len(input_unit_factory) + 1) + input_unit_items = float(len(input_unit_factory)) test_case_number = float(test_case_number) total_iterations = input_unit_items * test_case_number current_iteration = input_unit_idx * test_case_number @@ -382,23 +404,23 @@ def runTestCases(test_cases, options, cmd_line_options): test_inputs = options['inputs'] + oonib_reporter = OONIBReporter(cmd_line_options) + yaml_reporter = YAMLReporter(cmd_line_options) + if cmd_line_options['collector']: log.msg("Using remote collector, please be patient while we create the report.") - oreporter = OONIBReporter(cmd_line_options) - else: - log.msg("Reporting to file %s" % config.reports.yamloo) - oreporter = YAMLReporter(cmd_line_options) + try: + yield oonib_reporter.createReport(options) + except OONIBReportError: + log.err("Error in creating new report") + log.msg("We will only create reports to a file") + oonib_reporter = None - try: - input_unit_factory = InputUnitFactory(test_inputs) - except Exception, e: - log.exception(e) + yield yaml_reporter.createReport(options) + log.msg("Reporting to file %s" % config.reports.yamloo) try: - yield oreporter.createReport(options) - except OONIBReportCreationFailed: - log.err("Error in creating new report") - raise + input_unit_factory = InputUnitFactory(test_inputs) except Exception, e: log.exception(e) @@ -425,7 +447,8 @@ def runTestCases(test_cases, options, cmd_line_options): log.debug("Running %s with input unit %s" % (test_filename, input_unit)) yield runTestCasesWithInputUnit(test_cases, input_unit, - oreporter) + yaml_reporter, oonib_reporter) + yield increaseInputUnitIdx(test_filename) updateProgressMeters(test_filename, input_unit_factory, len(test_cases)) @@ -518,8 +541,8 @@ def loadTest(cmd_line_options): config.generateReportFilenames() if cmd_line_options['reportfile']: - config.reports.yamloo = cmd_line_options['reportfile'] - config.reports.pcap = config.reports.yamloo+".pcap" + config.reports.yamloo = cmd_line_options['reportfile']+'.yamloo' + config.reports.pcap = config.reports.yamloo+'.pcap' if os.path.exists(config.reports.pcap): print "Report PCAP already exists with filename %s" % config.reports.pcap