October 2016 - tor-commits - lists.torproject.org

[ooni-probe/master] Fix one of the reasons of stuck scheduler lockfile for RunDeck task, see #612
by art＠torproject.org 14 Oct '16

14 Oct '16

commit 877a2873a39641d2f0b6e56d8f40ead91c426e03 Author: Leonid Evdokimov <leon(a)darkk.net.ru> Date: Fri Sep 30 15:02:30 2016 +0300 Fix one of the reasons of stuck scheduler lockfile for RunDeck task, see #612 --- ooni/nettest.py | 18 +++++++++++++----- ooni/nettests/blocking/web_connectivity.py | 5 ++++- 2 files changed, 17 insertions(+), 6 deletions(-) diff --git a/ooni/nettest.py b/ooni/nettest.py index d6784f4..7a2afc8 100644 --- a/ooni/nettest.py +++ b/ooni/nettest.py @@ -6,7 +6,7 @@ import sys from twisted.internet import defer from twisted.python.filepath import FilePath from twisted.trial.runner import filenameToModule -from twisted.python import usage, reflect +from twisted.python import failure, usage, reflect from ooni import __version__ as ooniprobe_version, errors from ooni import otime @@ -578,6 +578,9 @@ class NetTest(object): """ This is a generator that yields measurements and registers the callbacks for when a measurement is successful or has failed. + + FIXME: If this generator throws exception TaskManager scheduler is + irreversibly damaged. """ for test_class, test_methods in self.testCases: @@ -591,11 +594,16 @@ class NetTest(object): test_instance._setUp() test_instance.summary = self.summary for method in test_methods: + try: + measurement = self.makeMeasurement( + test_instance, + method, + test_input) + except Exception: + log.exception(failure.Failure()) + log.err('Failed to run %s %s %s' % (test_instance, method, test_input)) + continue # it's better to skip single measurement... log.debug("Running %s %s" % (test_instance, method)) - measurement = self.makeMeasurement( - test_instance, - method, - test_input) measurements.append(measurement.done) self.state.taskCreated() yield measurement diff --git a/ooni/nettests/blocking/web_connectivity.py b/ooni/nettests/blocking/web_connectivity.py index d8d539f..1d1b742 100644 --- a/ooni/nettests/blocking/web_connectivity.py +++ b/ooni/nettests/blocking/web_connectivity.py @@ -29,6 +29,9 @@ from ooni.common.http_utils import REQUEST_HEADERS class InvalidControlResponse(Exception): pass +class AbsentHostname(Exception): + pass + class UsageOptions(usage.Options): optParameters = [ ['url', 'u', None, 'Specify a single URL to test'], @@ -175,7 +178,7 @@ class WebConnectivityTest(httpt.HTTPTest, dnst.DNSTest): self.hostname = urlparse(self.input).netloc if not self.hostname: - raise Exception("Invalid input") + raise AbsentHostname('No hostname', self.input) self.control = { 'tcp_connect': {},

1 0

[ooni-probe/master] The correct name for cloudfront based backends is "cloudfront" (#620)
by art＠torproject.org 14 Oct '16

14 Oct '16

commit 73b934ca05330d7c746e904f3f486e81b2ffcf12 Author: Arturo Filastò <arturo(a)filasto.net> Date: Tue Oct 11 13:05:28 2016 +0200 The correct name for cloudfront based backends is "cloudfront" (#620) --- ooni/ui/cli.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/ooni/ui/cli.py b/ooni/ui/cli.py index e7a0d88..c16173b 100644 --- a/ooni/ui/cli.py +++ b/ooni/ui/cli.py @@ -210,13 +210,13 @@ def initializeOoniprobe(global_options): include_country = False answer = raw_input('How would you like reports to be uploaded? (onion, ' - 'https, cloudfronted) ') + 'https, cloudfront) ') preferred_backend = 'onion' if answer.lower().startswith("https"): preferred_backend = 'https' - elif answer.lower().startswith("cloudfronted"): - preferred_backend = 'cloudfronted' + elif answer.lower().startswith("cloudfront"): + preferred_backend = 'cloudfront' config.create_config_file(include_ip=include_ip, include_asn=include_asn,

1 0

[ooni-probe/master] The https backend bouncer was still the testing one (#627)
by art＠torproject.org 14 Oct '16

14 Oct '16

commit 9799f1d2e602cf29478c922447643b178ed47557 Author: Arturo Filastò <arturo(a)filasto.net> Date: Wed Oct 12 16:13:30 2016 +0200 The https backend bouncer was still the testing one (#627) :8 --- ooni/constants.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/ooni/constants.py b/ooni/constants.py index 38f85b4..6efa52e 100644 --- a/ooni/constants.py +++ b/ooni/constants.py @@ -1,7 +1,5 @@ CANONICAL_BOUNCER_ONION = 'httpo://nkvphnp3p6agi5qq.onion' -# XXX Change these two to the production ones once the release is made. -# CANONICAL_BOUNCER_HTTPS = 'https://bouncer.ooni.io' -CANONICAL_BOUNCER_HTTPS = 'https://bouncer.test.ooni.io' +CANONICAL_BOUNCER_HTTPS = 'https://bouncer.ooni.io' CANONICAL_BOUNCER_CLOUDFRONT = ( 'https://d3kr4emv7f56qa.cloudfront.net/', 'a0.awsstatic.com'

1 0

[ooni-probe/master] Replace 32 bit GPG keyids with full ids, see https://evil32.com/ for a reason
by art＠torproject.org 14 Oct '16

14 Oct '16

commit 7e3401223fb7f838e576c8ba0b9f299477000c38 Author: Leonid Evdokimov <leon(a)darkk.net.ru> Date: Thu Sep 29 12:39:48 2016 +0300 Replace 32 bit GPG keyids with full ids, see https://evil32.com/ for a reason Remember that old gnupg version did not use full id even when it was given full id: https://bugs.gnupg.org/gnupg/issue1579 --- Vagrantfile | 4 ++-- scripts/setup-dependencies.sh | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/Vagrantfile b/Vagrantfile index 71f7c7a..744246b 100644 --- a/Vagrantfile +++ b/Vagrantfile @@ -5,7 +5,7 @@ $setup_ooniprobe = <<SCRIPT echo "deb http://deb.torproject.org/torproject.org jessie main" >> /etc/apt/sources.list # Install deb.torproject.org key -gpg --keyserver keys.gnupg.net --recv 886DDD89 +gpg --keyserver keys.gnupg.net --recv A3C4F0F979CAA22CDBA8F512EE8CBC9E886DDD89 gpg --export A3C4F0F979CAA22CDBA8F512EE8CBC9E886DDD89 | apt-key add - apt-get update @@ -30,7 +30,7 @@ echo "Installing Tor..." echo "deb http://deb.torproject.org/torproject.org jessie main" >> /etc/apt/sources.list -gpg --keyserver keys.gnupg.net --recv 886DDD89 +gpg --keyserver keys.gnupg.net --recv A3C4F0F979CAA22CDBA8F512EE8CBC9E886DDD89 gpg --export A3C4F0F979CAA22CDBA8F512EE8CBC9E886DDD89 | apt-key add - apt-get update diff --git a/scripts/setup-dependencies.sh b/scripts/setup-dependencies.sh index d96f2cf..e5fdf84 100755 --- a/scripts/setup-dependencies.sh +++ b/scripts/setup-dependencies.sh @@ -882,7 +882,7 @@ case $DISTRO_VERSION in echo "${DSTUFFT_PUB_KEY}" > ${DSTUFFT_KEY_FILE} # Import the Tor public key - DO "sudo gpg --homedir /root --no-default-keyring --keyring $TMP_KEYRING --keyserver x-hkp://pool.sks-keyservers.net --recv-keys 0x886DDD89" "0" + DO "sudo gpg --homedir /root --no-default-keyring --keyring $TMP_KEYRING --keyserver x-hkp://pool.sks-keyservers.net --recv-keys 0xA3C4F0F979CAA22CDBA8F512EE8CBC9E886DDD89" "0" sudo gpg --homedir /root --no-default-keyring --keyring $TMP_KEYRING --export A3C4F0F979CAA22CDBA8F512EE8CBC9E886DDD89 | sudo apt-key add - HAVE_TOR_REPO="`grep deb.torproject.org/torproject.org /etc/apt/sources.list /etc/apt/sources.list.d/* 2>&1|grep torproject|head -n 1`";

1 0

[ooni-probe/master] Comment update
by art＠torproject.org 14 Oct '16

14 Oct '16

commit 9c08df08a1a682f6a93826c3ca73045dfd2d5b32 Author: Leonid Evdokimov <leon(a)darkk.net.ru> Date: Tue Oct 11 18:01:21 2016 +0300 Comment update --- ooni/agent/scheduler.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/ooni/agent/scheduler.py b/ooni/agent/scheduler.py index 969602a..3e93d25 100644 --- a/ooni/agent/scheduler.py +++ b/ooni/agent/scheduler.py @@ -31,8 +31,8 @@ class FileSystemlockAndMutex(object): concurrently the mutex lock will block before the filesystem lock is acquired. - It's a way to support concurrent usage of the DeferredFilesystemLock - without races. + It's a way to support concurrent usage of the DeferredFilesystemLock from + different stacks (threads/fibers) within the same process without races. """ def __init__(self, file_path): self._fs_lock = defer.DeferredFilesystemLock(file_path)

1 0

[ooni-probe/master] Merge pull request #608 from TheTorProject/fix/606
by art＠torproject.org 14 Oct '16

14 Oct '16

commit ae465de52e18e084d465de3290c5888fd1a59e0a Merge: 4d79ff9 7f078c6 Author: Arturo Filastò <arturo(a)filasto.net> Date: Wed Sep 28 21:02:35 2016 +0200 Merge pull request #608 from TheTorProject/fix/606 On first run of the UpdateInputsAndResources task fetch the resources… ooni/__init__.py | 2 +- ooni/agent/scheduler.py | 11 +++++++++++ ooni/deck/store.py | 5 ++++- ooni/geoip.py | 1 + 4 files changed, 17 insertions(+), 2 deletions(-)

1 0

[ooni-probe/master] Fix #612 deadlock confirmed by TestScheduler.test_thundering_herd
by art＠torproject.org 14 Oct '16

14 Oct '16

commit 15bfb0312030a79c1985564dcbf7ee18101388b4 Author: Leonid Evdokimov <leon(a)darkk.net.ru> Date: Mon Oct 10 23:06:50 2016 +0300 Fix #612 deadlock confirmed by TestScheduler.test_thundering_herd The trivial fix makes sense as current SchedulerService ticks every 30 seconds and imprecise scheduling is acceptable. --- ooni/agent/scheduler.py | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/ooni/agent/scheduler.py b/ooni/agent/scheduler.py index f6b52b7..969602a 100644 --- a/ooni/agent/scheduler.py +++ b/ooni/agent/scheduler.py @@ -61,6 +61,11 @@ class DidNotRun(Exception): class ScheduledTask(object): + """ + Two ScheduledTask instances with same identifier are not permited to run + concurrently. There should be no ScheduledTask queue waiting for the lock + as SchedulerService ticks quite often. + """ _time_format = "%Y-%m-%dT%H:%M:%SZ" schedule = None identifier = None @@ -117,6 +122,9 @@ class ScheduledTask(object): @defer.inlineCallbacks def run(self): + if self._last_run_lock.locked: + # do not allow the queue to grow forever + raise DidNotRun yield self._last_run_lock.acquire() if not self.should_run: self._last_run_lock.release()

1 0

[ooni-probe/master] Add some more debug level messages
by art＠torproject.org 14 Oct '16

14 Oct '16

commit ea311bbc6fd19700e6179e128a8e9abfd5fc84e2 Author: Arturo Filastò <arturo(a)filasto.net> Date: Thu Sep 22 16:07:52 2016 +0200 Add some more debug level messages --- ooni/agent/scheduler.py | 3 +++ ooni/deck/store.py | 4 +++- ooni/geoip.py | 1 + 3 files changed, 7 insertions(+), 1 deletion(-) diff --git a/ooni/agent/scheduler.py b/ooni/agent/scheduler.py index cc71ee4..f6b52b7 100644 --- a/ooni/agent/scheduler.py +++ b/ooni/agent/scheduler.py @@ -123,6 +123,7 @@ class ScheduledTask(object): raise DidNotRun try: if self.last_run == CANARY_DATE: + log.debug("Detected first run") yield defer.maybeDeferred(self.first_run) last_run_time = datetime.utcnow() yield self.task() @@ -149,6 +150,8 @@ class UpdateInputsAndResources(ScheduledTask): def task(self): log.debug("Updating the inputs") yield probe_ip.lookup() + log.debug("Updating the inputs for country %s" % + probe_ip.geodata['countrycode']) yield resources.check_for_update(probe_ip.geodata['countrycode']) yield input_store.update(probe_ip.geodata['countrycode']) yield probe_ip.resolveGeodata() diff --git a/ooni/deck/store.py b/ooni/deck/store.py index d88f5d5..1e4785e 100644 --- a/ooni/deck/store.py +++ b/ooni/deck/store.py @@ -6,7 +6,7 @@ from copy import deepcopy from twisted.internet import defer from twisted.python.filepath import FilePath -from ooni.utils import mkdir_p +from ooni.utils import mkdir_p, log from ooni.deck.deck import NGDeck from ooni.otime import timestampNowISO8601UTC from ooni.resources import check_for_update @@ -41,6 +41,8 @@ class InputStore(object): yield check_for_update(country_code) if not in_file.exists(): + log.msg("Could not find input for country " + "{0} in {1}".format(cc, in_file.path)) continue # XXX maybe move this to some utility function. diff --git a/ooni/geoip.py b/ooni/geoip.py index 5e6b275..9148e34 100644 --- a/ooni/geoip.py +++ b/ooni/geoip.py @@ -215,6 +215,7 @@ class ProbeIP(object): self.address = None if self.address: + self.resolveGeodata(include_ip, include_asn, include_country) defer.returnValue(self.address) else: self._state = IN_PROGRESS

1 0

[ooni-probe/master] Add microsecond-precise logging to have more info to debug timing issues
by art＠torproject.org 14 Oct '16

14 Oct '16

commit e00072738e08dd0fccd09b8b48a7ed38b7a094ae Author: Leonid Evdokimov <leon(a)darkk.net.ru> Date: Thu Sep 29 13:58:03 2016 +0300 Add microsecond-precise logging to have more info to debug timing issues --- ooni/utils/log.py | 34 ++++++++++++++++++++++++++++------ 1 file changed, 28 insertions(+), 6 deletions(-) diff --git a/ooni/utils/log.py b/ooni/utils/log.py index f20fdce..b4136be 100644 --- a/ooni/utils/log.py +++ b/ooni/utils/log.py @@ -3,6 +3,7 @@ import sys import errno import codecs import logging +from datetime import datetime from twisted.python import log as tw_log from twisted.python.logfile import DailyLogFile @@ -100,6 +101,27 @@ class StdoutStderrObserver(LogLevelObserver): self.write(text + "\n") self.flush() +class MsecLogObserver(tw_log.FileLogObserver): + def formatTime(self, when): + """ + Code from Twisted==16.4.1 modified to log microseconds. Although this + logging subsystem is legacy: http://twistedmatrix.com/trac/ticket/7596 + Also, `timeFormat` is not used as `%z` is broken. + """ + tzOffset = -self.getTimezoneOffset(when) + when = datetime.utcfromtimestamp(when + tzOffset) + tzHour = abs(int(tzOffset / 60 / 60)) + tzMin = abs(int(tzOffset / 60 % 60)) + if tzOffset < 0: + tzSign = '-' + else: + tzSign = '+' + return '%d-%02d-%02d %02d:%02d:%02d,%06d%s%02d%02d' % ( + when.year, when.month, when.day, + when.hour, when.minute, when.second, + when.microsecond, + tzSign, tzHour, tzMin) + class OONILogger(object): def msg(self, msg, *arg, **kw): text = log_encode(msg) @@ -152,18 +174,18 @@ class OONILogger(object): daily_logfile = DailyLogFile(log_filename, log_folder) - tw_log.msg("Starting %s on %s (%s UTC)" % (application_name, - otime.prettyDateNow(), - otime.prettyDateNowUTC())) - - self.fileObserver = LogLevelObserver(daily_logfile, - log_level=file_log_level) + self.fileObserver = MsecLogObserver(LogLevelObserver(daily_logfile, + log_level=file_log_level)) self.stdoutObserver = StdoutStderrObserver(sys.stdout, log_level=stdout_log_level) tw_log.startLoggingWithObserver(self.fileObserver.emit) tw_log.addObserver(self.stdoutObserver.emit) + tw_log.msg("Starting %s on %s (%s UTC)" % (application_name, + otime.prettyDateNow(), + otime.prettyDateNowUTC())) + def stop(self): self.stdoutObserver.stop() self.fileObserver.stop()

1 0

[ooni-probe/master] Change to scheduler and deck_store to better support unittesting
by art＠torproject.org 14 Oct '16

14 Oct '16

commit c0b9626242ba7627286da6512a8522f519d76556 Author: Arturo Filastò <arturo(a)filasto.net> Date: Tue Oct 11 18:01:58 2016 +0200 Change to scheduler and deck_store to better support unittesting --- ooni/agent/scheduler.py | 11 ++++++++--- ooni/deck/store.py | 7 ++++--- ooni/utils/__init__.py | 11 ++++++++++- 3 files changed, 22 insertions(+), 7 deletions(-) diff --git a/ooni/agent/scheduler.py b/ooni/agent/scheduler.py index 3e93d25..bda8510 100644 --- a/ooni/agent/scheduler.py +++ b/ooni/agent/scheduler.py @@ -5,7 +5,7 @@ from hashlib import md5 from datetime import datetime from twisted.application import service -from twisted.internet import defer +from twisted.internet import defer, reactor from twisted.internet.task import LoopingCall from twisted.python.filepath import FilePath @@ -71,7 +71,9 @@ class ScheduledTask(object): identifier = None def __init__(self, schedule=None, identifier=None, - scheduler_directory=config.scheduler_directory): + scheduler_directory=None): + if scheduler_directory is None: + scheduler_directory = config.scheduler_directory if schedule is not None: self.schedule = schedule if identifier is not None: @@ -346,11 +348,14 @@ class SchedulerService(service.MultiService): """ This service is responsible for running the periodic tasks. """ - def __init__(self, director, interval=30): + def __init__(self, director, interval=30, _reactor=reactor): service.MultiService.__init__(self) self.director = director self.interval = interval + self._looping_call = LoopingCall(self._should_run) + self._looping_call.clock = _reactor + self._scheduled_tasks = [] def schedule(self, task): diff --git a/ooni/deck/store.py b/ooni/deck/store.py index 1e4785e..8fdb856 100644 --- a/ooni/deck/store.py +++ b/ooni/deck/store.py @@ -130,9 +130,10 @@ class InputStore(object): class DeckStore(object): - def __init__(self): - self.enabled_directory = FilePath(config.decks_enabled_directory) - self.available_directory = FilePath(config.decks_available_directory) + def __init__(self, enabled_directory=config.decks_enabled_directory, + available_directory=config.decks_available_directory): + self.enabled_directory = FilePath(enabled_directory) + self.available_directory = FilePath(available_directory) self._cache = {} self._cache_stale = True diff --git a/ooni/utils/__init__.py b/ooni/utils/__init__.py index 99f1985..def533a 100644 --- a/ooni/utils/__init__.py +++ b/ooni/utils/__init__.py @@ -6,7 +6,7 @@ import errno import gzip import os -from datetime import datetime +from datetime import datetime, timedelta from zipfile import ZipFile from twisted.python.filepath import FilePath @@ -91,6 +91,15 @@ def randomStr(length, num=True): chars += string.digits return ''.join(random.choice(chars) for x in range(length)) +def randomDate(start, end): + """ + From: http://stackoverflow.com/a/553448 + """ + delta = end - start + int_delta = (delta.days * 24 * 60 * 60) + random_second = random.randrange(int_delta) + return start + timedelta(seconds=random_second) + LONG_DATE = "%Y-%m-%d %H:%M:%S" SHORT_DATE = "%Y%m%dT%H%M%SZ"

1 0