Skip to content

P
pytensor
提交 de65febb authored 作者: nouiz's avatar nouiz
浏览文件
操作

Merge pull request #768 from larseeri/time_nose_tests

addition of time-profiling mode to unittest processing apparatus theano-nose --profile
上级 1ae48129 29f4647d
隐藏空白字符变更
内嵌 并排
正在显示 包含 334 行增加 和 71 行删除
bin/theano-nose
浏览文件 @ de65febb
#!/usr/bin/env python #!/usr/bin/env python
__authors__ = "Olivier Delalleau, Pascal Lamblin" __authors__ = "Olivier Delalleau, Pascal Lamblin, Eric Larsen"
__contact__ = "delallea@iro" __contact__ = "delallea@iro"
""" """
...@@ -13,10 +13,20 @@ It is also used to load the KnownFailure plugin, in order to hide ...@@ -13,10 +13,20 @@ It is also used to load the KnownFailure plugin, in order to hide
KnownFailureTests error messages. Use --without-knownfailure to KnownFailureTests error messages. Use --without-knownfailure to
disable that plugin. disable that plugin.
If the --batch option is used, it will call `run_tests_in_batch.py`, There are two additional local options: '--batch[=n]' and '--time-profile'.
in order to run the tests by batches, not all at the same time.
`run_tests_in_batch.py` will in turn call back this script in another If '--batch[=n]' is used without '--time-profile', this script will call
process. run_tests_in_batch.py` in order to run the tests by batches, not all at the
same time. The batches will comprise 100 elements each by default and
'n' elements if the option '=n' is specified.
If the '--time-profile' option is used, it will call `run_tests_in_batch.py`
with the option time_profile=True to conduct time-profiling of the tests.
(See 'help' function below for details.) If also specified, '--batch[=n]'
option will be interpreted as an indication of the number of tests to be run
between notifications of progress to standard output.
`run_tests_in_batch.py` will in turn call back this script in another process.
""" """
import logging import logging
...@@ -26,14 +36,14 @@ _logger.setLevel(logging.WARN) ...@@ -26,14 +36,14 @@ _logger.setLevel(logging.WARN)
import nose import nose
import textwrap import textwrap
import sys import sys
from nose.plugins import Plugin
def main(): def main():
# Handle --batch[=n] arguments # Handle --batch[=n] arguments
batch_args = [arg for arg in sys.argv if arg.startswith('--batch')] batch_args = [arg for arg in sys.argv if arg.startswith('--batch')]
for arg in batch_args: for arg in batch_args:
sys.argv.remove(arg) sys.argv.remove(arg)
batch_size = None
if len(batch_args): if len(batch_args):
if len(batch_args) > 1: if len(batch_args) > 1:
_logger.warn( _logger.warn(
...@@ -44,12 +54,17 @@ def main(): ...@@ -44,12 +54,17 @@ def main():
elems = batch_arg.split('=', 1) elems = batch_arg.split('=', 1)
if len(elems) == 2: if len(elems) == 2:
batch_size = int(elems[1]) batch_size = int(elems[1])
else:
# Use run_tests_in_batch's default
batch_size = None
# Handle --time_prof arguments
time_prof_args = [arg for arg in sys.argv if arg=='--time-profile']
for arg in time_prof_args:
sys.argv.remove(arg)
# Time-profiling and batch modes
if len(time_prof_args) or len(batch_args):
from theano.tests import run_tests_in_batch from theano.tests import run_tests_in_batch
return run_tests_in_batch.main(batch_size=batch_size) return run_tests_in_batch.main(batch_size=batch_size,
time_profile=len(time_prof_args) > 0)
# Non-batch mode. # Non-batch mode.
addplugins = [] addplugins = []
...@@ -65,6 +80,13 @@ def main(): ...@@ -65,6 +80,13 @@ def main():
'Use --without-knownfailure to disable this warning.') 'Use --without-knownfailure to disable this warning.')
else: else:
sys.argv.remove('--without-knownfailure') sys.argv.remove('--without-knownfailure')
# When 'theano-nose' is called-back under the time-profile option, an
# instance of the custom Nosetests plugin class 'DisabDocString' (see
# below) is loaded. The latter ensures that the test name will not be
# replaced in display by the first line of the documentation string.
if '--disabdocstring' in sys.argv:
addplugins.append(DisabDocString())
return nose.main(addplugins=addplugins) return nose.main(addplugins=addplugins)
...@@ -77,12 +99,40 @@ def help(): ...@@ -77,12 +99,40 @@ def help():
KnownFailure plugin, in order to hide KnownFailureTests error KnownFailure plugin, in order to hide KnownFailureTests error
messages. It also supports executing tests by batches. messages. It also supports executing tests by batches.
Options: Local options:
--batch[=n]: Do not run all the tests in one run, but split --batch[=n]:
the execution in batches of `n` tests each. If specified without option '--time-profile', do not run all
Default n is 100. the tests in one run, but split the execution in batches of
`n` tests each. Default n is 100.
--time-profile:
Each test will be run and timed separately and the results will
be deposited in the files 'timeprof_sort', 'timeprof_nosort'
and 'timeprof_rawlog' in the current directory. If the
'--batch[=n]' option is also specified, notification of the
progresses will be made to standard output after every group of
n tests. Otherwise, notification will occur after every group
of 100 tests.
The files 'timeprof_sort' and 'timeprof_nosort' both contain one
record for each test and comprise the following fields:
- test running-time
- nosetests sequential test number
- test name
- name of class to which test belongs (if any), otherwise full
information is contained in test name
- test outcome ('OK', 'SKIPPED TEST', 'FAILED TEST' or
'FAILED PARSING')
In 'timeprof_sort', test records are sorted according to
running-time whereas in 'timeprof_nosort' records are reported
according to sequential number. The former classification is the
main information source for time-profiling. Since tests belonging
to same or close classes and files have close sequential, the
latter may be used to identify duration patterns among the tests
numbers. A full log is also saved as 'timeprof_rawlog'.
--help, -h: Displays this help. --help, -h: Displays this help.
--without-knownfailure: Do not load the KnownFailure plugin. --without-knownfailure: Do not load the KnownFailure plugin.
...@@ -93,6 +143,63 @@ def help(): ...@@ -93,6 +143,63 @@ def help():
print textwrap.dedent(help_msg) print textwrap.dedent(help_msg)
class DisabDocString(Plugin):
"""
When activated, a custom Nosetests plugin created through this class
will preclude automatic replacement in display of the name of the test
by the first line in its documentation string.
Sources:
http://nose.readthedocs.org/en/latest/developing.html
http://nose.readthedocs.org/en/latest/further_reading.html
http://www.siafoo.net/article/54
https://github.com/nose-devs/nose/issues/294
http://python-nose.googlecode.com/svn/trunk/nose/plugins/base.py
Nat Williams:
https://github.com/Merino/nose-description-fixer-plugin/commit/
df94596f29c04fea8001713dd9b04bf3720aebf4
"""
enabled = False # plugin disabled by default
score = 2000 # high score ensures priority over other plugins
def __init__(self):
# 'super.__init__(self):' would have achieved exactly the same
if self.name is None:
self.name = self.__class__.__name__.lower()
if self.enableOpt is None:
self.enableOpt = ("enable_plugin_%s"
% self.name.replace('-', '_'))
def options(self, parser, env):
env_opt = 'NOSE_WITH_%s' % self.name.upper()
# latter expression to be used if plugin called from the command line
parser.add_option("--%s" % self.name,
# will be called with Nosetests 'main' or 'run'
# function's' argument '--disabdocstring'
action="store_true",
dest=self.enableOpt,
# the latter entails that the boolean self.enableOpt
# is set to 'True' when plugin is called through a
# function's argument
default=env.get(env_opt),
# entails that plugin will be enabled when command
# line trigger 'env_opt' will be activated
help="Enable plugin %s: %s [%s]" %
(self.__class__.__name__,
self.help(), env_opt))
def configure(self, options, conf):
self.conf = conf
# plugin will be enabled when called through argument
self.enabled = getattr(options, self.enableOpt)
def describeTest(self, test):
# 'describeTest' is also called when the test result in Nosetests calls
# 'test.shortDescription()' and can thus be used to alter the display.
return False
if __name__ == '__main__': if __name__ == '__main__':
if '--help' in sys.argv or '-h' in sys.argv: if '--help' in sys.argv or '-h' in sys.argv:
help() help()
......
theano/tests/run_tests_in_batch.py
浏览文件 @ de65febb
#!/usr/bin/env python #!/usr/bin/env python
__authors__ = "Olivier Delalleau, Eric Larsen"
__authors__ = "Olivier Delalleau" __contact__ = "delallea@iro"
__contact__ = "delallea@iro"
""" """
Run this script to run tests in small batches rather than all at the same time. Run this script to run tests in small batches rather than all at the same time
or to conduct time-profiling.
If no argument is provided, then the whole Theano test-suite is run. If no argument is provided, then the whole Theano test-suite is run.
Otherwise, only tests found in the directory given as argument are run. Otherwise, only tests found in the directory given as argument are run.
This script performs three tasks: If 'time_profile=False', this script performs three tasks:
1. Run `nosetests --collect-only --with-id` to collect test IDs 1. Run `nosetests --collect-only --with-id` to collect test IDs
2. Run `nosetests --with-id i1 ... iN` with batches of N indices, until all 2. Run `nosetests --with-id i1 ... iN` with batches of 'batch_size'
tests have been run (currently N=100). indices, until all tests have been run (currently batch_size=100 by
default).
3. Run `nosetests --failed` to re-run only tests that failed 3. Run `nosetests --failed` to re-run only tests that failed
=> The output of this 3rd step is the one you should care about => The output of this 3rd step is the one you should care about
If 'time_profile=True', this script conducts time-profiling of the tests:
1. Run `nosetests --collect-only --with-id` to collect test IDs
2. Run `nosetests --with-id i`, one test with ID 'i' at a time, collecting
timing information and displaying progresses on standard output after
every group of 'batch_size' (100 by default), until all tests have
been run.
The results are deposited in the files 'timeprof_sort' and
'timeprof_nosort' in the current directory. Both contain one record for
each test and comprise the following fields:
- test running-time
- nosetests sequential test number
- test name
- name of class to which test belongs (if any), otherwise full
information is contained in test name
- test outcome ('OK', 'SKIPPED TESTS', 'FAILED TEST' or 'FAILED PARSING')
In 'timeprof_sort', test records are sorted according to run-time
whereas in 'timeprof_nosort' records are reported according to
sequential number. The former classification is the main information
source for time-profiling. Since tests belonging to same or close
classes and files have close sequential numbers, the latter may be used
to identify duration patterns among the tests. A full log is also saved
as 'timeprof_rawlog'.
One reason to use this script is if you are a Windows user, and see errors like One reason to use this script is if you are a Windows user, and see errors like
"Not enough storage is available to process this command" when trying to simply "Not enough storage is available to process this command" when trying to simply
...@@ -31,12 +54,16 @@ nosetests. ...@@ -31,12 +54,16 @@ nosetests.
""" """
import cPickle, os, subprocess, sys import cPickle
import os
import subprocess
import sys
import datetime
import theano import theano
def main(stdout=None, stderr=None, argv=None, theano_nose=None, batch_size=None): def main(stdout=None, stderr=None, argv=None, theano_nose=None,
batch_size=None, time_profile=False):
""" """
Run tests with optional output redirection. Run tests with optional output redirection.
...@@ -51,6 +78,7 @@ def main(stdout=None, stderr=None, argv=None, theano_nose=None, batch_size=None) ...@@ -51,6 +78,7 @@ def main(stdout=None, stderr=None, argv=None, theano_nose=None, batch_size=None)
If batch_size is None, we use a default value of 100. If batch_size is None, we use a default value of 100.
""" """
if stdout is None: if stdout is None:
stdout = sys.stdout stdout = sys.stdout
if stderr is None: if stderr is None:
...@@ -58,7 +86,8 @@ def main(stdout=None, stderr=None, argv=None, theano_nose=None, batch_size=None) ...@@ -58,7 +86,8 @@ def main(stdout=None, stderr=None, argv=None, theano_nose=None, batch_size=None)
if argv is None: if argv is None:
argv = sys.argv argv = sys.argv
if theano_nose is None: if theano_nose is None:
theano_nose = os.path.join(theano.__path__[0], '..', 'bin', 'theano-nose') theano_nose = os.path.join(theano.__path__[0], '..',
'bin', 'theano-nose')
if batch_size is None: if batch_size is None:
batch_size = 100 batch_size = 100
stdout_backup = sys.stdout stdout_backup = sys.stdout
...@@ -66,12 +95,16 @@ def main(stdout=None, stderr=None, argv=None, theano_nose=None, batch_size=None) ...@@ -66,12 +95,16 @@ def main(stdout=None, stderr=None, argv=None, theano_nose=None, batch_size=None)
try: try:
sys.stdout = stdout sys.stdout = stdout
sys.stderr = stderr sys.stderr = stderr
run(stdout, stderr, argv, theano_nose, batch_size) run(stdout, stderr, argv, theano_nose, batch_size, time_profile)
finally: finally:
sys.stdout = stdout_backup sys.stdout = stdout_backup
sys.stderr = stderr_backup sys.stderr = stderr_backup
def run(stdout, stderr, argv, theano_nose, batch_size):
def run(stdout, stderr, argv, theano_nose, batch_size, time_profile):
# Setting aside current working directory for later saving
sav_dir = os.getcwd()
if len(argv) == 1: if len(argv) == 1:
tests_dir = theano.__path__[0] tests_dir = theano.__path__[0]
other_args = [] other_args = []
...@@ -84,6 +117,7 @@ def run(stdout, stderr, argv, theano_nose, batch_size): ...@@ -84,6 +117,7 @@ def run(stdout, stderr, argv, theano_nose, batch_size):
# It seems safer to fully regenerate the list of tests on each call. # It seems safer to fully regenerate the list of tests on each call.
if os.path.isfile('.noseids'): if os.path.isfile('.noseids'):
os.remove('.noseids') os.remove('.noseids')
# Collect test IDs. # Collect test IDs.
print """\ print """\
#################### ####################
...@@ -97,11 +131,11 @@ def run(stdout, stderr, argv, theano_nose, batch_size): ...@@ -97,11 +131,11 @@ def run(stdout, stderr, argv, theano_nose, batch_size):
# Using sys.executable, so that the same Python version is used. # Using sys.executable, so that the same Python version is used.
python = sys.executable python = sys.executable
rval = subprocess.call( rval = subprocess.call(
([python, theano_nose, '--collect-only', '--with-id'] ([python, theano_nose, '--collect-only', '--with-id']
+ other_args), + other_args),
stdin=dummy_in.fileno(), stdin=dummy_in.fileno(),
stdout=stdout.fileno(), stdout=stdout.fileno(),
stderr=stderr.fileno()) stderr=stderr.fileno())
stdout.flush() stdout.flush()
stderr.flush() stderr.flush()
assert rval == 0 assert rval == 0
...@@ -110,59 +144,181 @@ def run(stdout, stderr, argv, theano_nose, batch_size): ...@@ -110,59 +144,181 @@ def run(stdout, stderr, argv, theano_nose, batch_size):
ids = data['ids'] ids = data['ids']
n_tests = len(ids) n_tests = len(ids)
assert n_tests == max(ids) assert n_tests == max(ids)
# Run tests.
failed = set() # Standard batch testing is called for
print """\ if not time_profile:
failed = set()
print """\
################################### ###################################
# RUNNING TESTS IN BATCHES OF %s # # RUNNING TESTS IN BATCHES OF %s #
###################################""" % batch_size ###################################""" % batch_size
for test_id in xrange(1, n_tests + 1, batch_size): # We suppress all output because we want the user to focus only on
stdout.flush() # the failed tests, which are re-run (with output) below.
stderr.flush()
test_range = range(test_id, min(test_id + batch_size, n_tests + 1))
# We suppress all output because we want the user to focus only on the
# failed tests, which are re-run (with output) below.
dummy_out = open(os.devnull, 'w') dummy_out = open(os.devnull, 'w')
rval = subprocess.call( for test_id in xrange(1, n_tests + 1, batch_size):
stdout.flush()
stderr.flush()
test_range = range(test_id, min(test_id + batch_size, n_tests + 1))
rval = subprocess.call(
([python, theano_nose, '-q', '--with-id'] ([python, theano_nose, '-q', '--with-id']
+ map(str, test_range) + map(str, test_range)
+ other_args), + other_args),
stdout=dummy_out.fileno(), stdout=dummy_out.fileno(),
stderr=dummy_out.fileno(), stderr=dummy_out.fileno(),
stdin=dummy_in.fileno()) stdin=dummy_in.fileno())
# Recover failed test indices from the 'failed' field of the '.noseids' # Recover failed test indices from the 'failed' field of the
# file. We need to do it after each batch because otherwise this field # '.noseids' file. We need to do it after each batch because
# may get erased. We use a set because it seems like it is not # otherwise this field may get erased. We use a set because it
# systematically erased though, and we want to avoid duplicates. # seems like it is not systematically erased though, and we want
failed = failed.union(cPickle.load(open(noseids_file, 'rb'))['failed']) # to avoid duplicates.
print '%s%% done (failed: %s)' % ((test_range[-1] * 100) // n_tests, failed = failed.union(cPickle.load(open(noseids_file, 'rb'))
len(failed)) ['failed'])
# Sort for cosmetic purpose only. print '%s%% done (failed: %s)' % ((test_range[-1] * 100) //
failed = sorted(failed) n_tests, len(failed))
if failed: # Sort for cosmetic purpose only.
# Re-run only failed tests failed = sorted(failed)
print """\ if failed:
# Re-run only failed tests
print """\
################################ ################################
# RE-RUNNING FAILED TESTS ONLY # # RE-RUNNING FAILED TESTS ONLY #
################################""" ################################"""
stdout.flush() stdout.flush()
stderr.flush() stderr.flush()
subprocess.call( subprocess.call(
([python, theano_nose, '-v', '--with-id'] ([python, theano_nose, '-v', '--with-id']
+ failed + failed
+ other_args), + other_args),
stdin=dummy_in.fileno(), stdin=dummy_in.fileno(),
stdout=stdout.fileno(), stdout=stdout.fileno(),
stderr=stderr.fileno()) stderr=stderr.fileno())
stdout.flush() stdout.flush()
stderr.flush() stderr.flush()
return 0 return 0
else: else:
print """\ print """\
#################### ####################
# ALL TESTS PASSED # # ALL TESTS PASSED #
####################""" ####################"""
# Time-profiling is called for
else:
print """\
########################################
# RUNNING TESTS IN TIME-PROFILING MODE #
########################################"""
# finds first word of list l containing string s
def getIndexOfFirst(l, s):
for pos, word in enumerate(l):
if s in word:
return pos
# finds last word of list l containing string s
def getIndexOfLast(l, s):
for pos, word in enumerate(reversed(l)):
if s in word:
return (len(l) - pos - 1)
# iterating through tests
# initializing master profiling list and raw log
prof_master_nosort = []
prof_rawlog = []
dummy_out = open(os.devnull, 'w')
for test_floor in xrange(1, n_tests + 1, batch_size):
for test_id in xrange(test_floor, min(test_floor + batch_size,
n_tests + 1)):
proc = subprocess.Popen(
([python, theano_nose, '-v', '--with-id']
+ [str(test_id)] + other_args +
['--disabdocstring']),
# the previous option calls a custom Nosetests plugin
# precluding automatic sustitution of doc. string for
# test name in display
# (see class 'DisabDocString' in file theano-nose)
stderr=subprocess.PIPE,
stdout=dummy_out.fileno(),
stdin=dummy_in.fileno())
# recovering and processing data from pipe
err = proc.stderr.read()
# building the raw log
prof_rawlog.append(err)
# parsing the output
l_err = err.split()
try:
pos_id = getIndexOfFirst(l_err, '#')
prof_id = l_err[pos_id]
pos_dot = getIndexOfFirst(l_err, '...')
prof_test = ''
for s in l_err[pos_id + 1: pos_dot]:
prof_test += s + ' '
if 'OK' in err:
pos_ok = getIndexOfLast(l_err, 'OK')
if len(l_err) == pos_ok + 1:
prof_time = float(l_err[pos_ok - 1][0:-1])
prof_pass = 'OK'
elif 'SKIP' in l_err[pos_ok + 1]:
prof_time = 0.
prof_pass = 'SKIPPED TEST'
elif 'KNOWNFAIL' in l_err[pos_ok + 1]:
prof_time = float(l_err[pos_ok - 1][0:-1])
prof_pass = 'OK'
else:
prof_time = 0.
prof_pass = 'FAILED TEST'
else:
prof_time = 0.
prof_pass = 'FAILED TEST'
except Exception:
prof_time = 0
prof_id = '#' + str(test_id)
prof_test = ('FAILED PARSING, see raw log for details'
' on test')
prof_pass = ''
prof_tuple = (prof_time, prof_id, prof_test, prof_pass)
# appending tuple to master list
prof_master_nosort.append(prof_tuple)
print '%s%% time-profiled' % ((test_id * 100) // n_tests)
# sorting tests according to running-time
prof_master_sort = sorted(prof_master_nosort,
key=lambda test: test[0], reverse=True)
# saving results to readable files
path_nosort = os.path.join(sav_dir, 'timeprof_nosort')
path_sort = os.path.join(sav_dir, 'timeprof_sort')
path_rawlog = os.path.join(sav_dir, 'timeprof_rawlog')
f_nosort = open(path_nosort, 'w')
f_sort = open(path_sort, 'w')
f_rawlog = open(path_rawlog, 'w')
stamp = str(datetime.datetime.now()) + '\n\n'
fields = ('Fields: computation time; nosetests sequential id;'
' test name; parent class (if any); outcome\n\n')
f_nosort.write('TIME-PROFILING OF THEANO\'S NOSETESTS'
' (by sequential id)\n\n' + stamp + fields)
f_sort.write('TIME-PROFILING OF THEANO\'S NOSETESTS'
' (sorted by computation time)\n\n' + stamp + fields)
for i in xrange(len(prof_master_nosort)):
s_nosort = ((str(prof_master_nosort[i][0]) + 's').ljust(10) +
" " + prof_master_nosort[i][1].ljust(7) + " " +
prof_master_nosort[i][2] + prof_master_nosort[i][3] +
"\n")
f_nosort.write(s_nosort)
s_sort = ((str(prof_master_sort[i][0]) + 's').ljust(10) +
" " + prof_master_sort[i][1].ljust(7) + " " +
prof_master_sort[i][2] + prof_master_sort[i][3] +
"\n")
f_sort.write(s_sort)
f_nosort.close()
f_sort.close()
f_rawlog.write('TIME-PROFILING OF THEANO\'S NOSETESTS'
' (raw log)\n\n' + stamp)
for i in xrange(len(prof_rawlog)):
f_rawlog.write(prof_rawlog[i])
f_rawlog.close()
if __name__ == '__main__': if __name__ == '__main__':
sys.exit(main()) sys.exit(main())
Markdown 格式
0% 或
您添加了 0 人 到此讨论。请谨慎行事。
请先完成此评论的编辑！
请 注册 或者 后发表评论