Fix parallel build

Author: rogerdahl

.travis.yml

@@ -13,19 +13,19 @@ before_install:
 install:
   - pip install --upgrade pip
   - pip install --upgrade setuptools
-  - pip install coverage pytest-cov pytest-django
+  #- pip install coverage pytest-cov pytest-django
 script:
   # Travis clones the project to $TRAVIS_BUILD_DIR and cds there before running
   # the scripts.
   - ./dev_tools/src/d1_dev/setup-all.py --root $TRAVIS_BUILD_DIR develop
   - ./dev_tools/src/d1_dev/syspath.py
   - pip freeze
   - pip check
-  - pytest --cov=. --cov-report=term --cov-report=xml
+  - pytest -n auto --cov=. --cov-report=term --cov-report=xml
 after_success:
   # Submit results to Coveralls.io.
   # Coveralls has a requirement for requests >= 1.0.0, so we install it after
   # our packages to prevent it from pulling in the latest version, which is
   # likely to conflict with the fixed version our packages pull in.
-  - pip install coveralls
+#  - pip install coveralls
   - coveralls

client_cli/src/d1_cli/tests/test_check_dependencies.py

@@ -33,9 +33,11 @@ def test_1000(self):
     """check_dependencies(): Returns True given modules known to be present"""
     assert d1_cli.impl.check_dependencies.are_modules_importable(['os', 'sys'])
 
-  def test_1010(self):
+  def test_1010(self, caplog):
     """check_dependencies(): Returns false and logs error on invalid module"""
-    with d1_test.d1_test_case.capture_log() as log_stream:
-      assert not d1_cli.impl.check_dependencies. \
-        are_modules_importable(['os', 'invalid_module'])
-    assert 'dependencies failed' in log_stream.getvalue()
+    assert not (
+      d1_cli.impl.check_dependencies.are_modules_importable(
+        ['os', 'invalid_module']
+      )
+    )
+    assert 'dependencies failed' in d1_test.d1_test_case.get_caplog_text(caplog)

conftest.py

@@ -24,11 +24,15 @@
 import logging
 import os
 import subprocess
+import tempfile
 
 import psycopg2
 import psycopg2.extensions
 import pytest
 
+import d1_gmn.app.sciobj_store
+
+import d1_test.instance_generator.random_data
 import d1_test.sample
 
 from d1_client.cnclient_1_2 import CoordinatingNodeClient_1_2 as cn_v1
@@ -102,7 +106,7 @@ def pytest_addoption(parser):
     '--skip-clear', action='store_true', help='Clear the list of passed tests'
   )
   parser.addoption(
-    '--skip-list', action='store_true', help='Print the list of passed tests'
+    '--skip-print', action='store_true', help='Print the list of passed tests'
   )
 
 
@@ -113,18 +117,20 @@ def pytest_sessionstart(session):
   """Called by pytest before calling session.main()"""
   if pytest.config.getoption('--sample-tidy'):
     d1_test.sample.start_tidy()
+    pytest.exit('Tidy started. Run complete to complete')
   if pytest.config.getoption('--skip-clear'):
     _clear_skip_list()
-  if pytest.config.getoption('--skip-list'):
+  if pytest.config.getoption('--skip-print'):
     _print_skip_list()
 
 
 def pytest_sessionfinish(session, exitstatus):
   """Called by pytest after the test session ends"""
   # if exitstatus != 2:
-  skipped_count = pytest.config.cache.get(D1_SKIP_COUNT, 0)
-  if skipped_count:
-    logging.warn('Skipped {} previously passed tests'.format(skipped_count))
+  if pytest.config.getoption('--skip'):
+    skipped_count = pytest.config.cache.get(D1_SKIP_COUNT, 0)
+    if skipped_count:
+      logging.warn('Skipped {} previously passed tests'.format(skipped_count))
 
 
 @pytest.hookimpl(tryfirst=True, hookwrapper=True)
@@ -298,20 +304,34 @@ def mn_client_v1_v2(request):
   yield request.param(MOCK_BASE_URL)
 
 
+# Settings
+
+
+@pytest.fixture(scope='session', autouse=True)
+def set_unique_sciobj_store_path(request):
+  tmp_store_path = os.path.join(
+    tempfile.gettempdir(), 'gmn_test_obj_store_{}{}'.format(
+      d1_test.instance_generator.random_data.random_lower_ascii(
+        min_len=12, max_len=12
+      ), get_xdist_suffix(request)
+    )
+  )
+  django.conf.settings.OBJECT_STORE_PATH = tmp_store_path
+  d1_gmn.app.sciobj_store.create_clean_tmp_store()
+
+
 # DB fixtures
 
 
 @pytest.yield_fixture(scope='session')
 def django_db_setup(request, django_db_blocker):
   """Set up DB fixture
   """
-  xdist_suffix = getattr(request.config, 'slaveinput', {}).get('slaveid', '')
-
   logging.info('Setting up DB fixture')
 
   test_db_key = 'default'
   test_db_name = django.conf.settings.DATABASES[test_db_key]['NAME']
-  test_db_name += xdist_suffix
+  test_db_name += get_xdist_suffix(request)
   django.conf.settings.DATABASES[test_db_key]['NAME'] = test_db_name
 
   template_db_key = 'template'
@@ -339,6 +359,15 @@ def django_db_setup(request, django_db_blocker):
     yield
 
 
+def get_xdist_suffix(request):
+  """When running in parallel with xdist, each thread gets a different suffix.
+  - In parallel run, return '_gw1', etc.
+  - In single run, return ''.
+  """
+  s = getattr(request.config, 'slaveinput', {}).get('slaveid')
+  return '_{}'.format(s) if s is not None else ''
+
+
 def create_db_from_template(test_db_name, template_db_name):
   logging.info(
     'Creating test DB from template. test_db="{}" template_db="{}"'.

gmn/src/d1_gmn/tests/test_mgmt_cert.py

@@ -32,38 +32,37 @@
 
 
 class TestCmdCert(d1_gmn.tests.gmn_test_case.GMNTestCase):
-  def _cert_whitelist(self):
+  def _cert_whitelist(self, caplog):
     cert_path = self.sample.get_path(
       'cert_cn_ucsb_1_dataone_org_20150709_180838.pem'
     )
     with self.mock.disable_management_command_logging():
-      with d1_test.d1_test_case.capture_log() as log_stream:
-        with d1_test.d1_test_case.disable_debug_level_logging():
-          django.core.management.call_command('cert', 'whitelist', cert_path)
-          django.core.management.call_command('whitelist', 'view', cert_path)
-      return log_stream.getvalue()
+      with d1_test.d1_test_case.disable_debug_level_logging():
+        django.core.management.call_command('cert', 'whitelist', cert_path)
+        django.core.management.call_command('whitelist', 'view', cert_path)
+      return d1_test.d1_test_case.get_caplog_text(caplog)
 
-  def test_1000(self):
+  def test_1000(self, caplog):
     """cert view <pem>: Lists subjects from DN and SubjectInfo
     """
-    # print (logging.Logger.manager.loggerDict.keys())
     cert_path = self.sample.get_path('cert_with_full_subject_info.pem')
-    with d1_test.d1_test_case.capture_log() as log_stream:
-      with self.mock.disable_management_command_logging():
-        with d1_test.d1_test_case.disable_debug_level_logging():
-          django.core.management.call_command('cert', 'view', cert_path)
-    self.sample.assert_equals(log_stream.getvalue(), 'view')
+    with self.mock.disable_management_command_logging():
+      with d1_test.d1_test_case.disable_debug_level_logging():
+        django.core.management.call_command('cert', 'view', cert_path)
+    self.sample.assert_equals(
+      d1_test.d1_test_case.get_caplog_text(caplog), 'view'
+    )
 
-  def test_1010(self):
+  def test_1010(self, caplog):
     """cert whitelist <pem>: Whitelists subj from cert if not already whitelisted
     """
-    log_str = self._cert_whitelist()
+    log_str = self._cert_whitelist(caplog)
     self.sample.assert_equals(log_str, 'whitelist_new')
 
-  def test_1020(self):
+  def test_1020(self, caplog):
     """cert whitelist <pem>: Raise on cert with subj already whitelisted
     """
-    self._cert_whitelist()
+    self._cert_whitelist(caplog)
     with pytest.raises(django.core.management.CommandError) as exc_info:
-      self._cert_whitelist()
+      self._cert_whitelist(caplog)
     assert 'already enabled' in str(exc_info.value)

gmn/src/d1_gmn/tests/test_mgmt_import.py

@@ -21,6 +21,8 @@
 """
 from __future__ import absolute_import
 
+import logging
+
 import responses
 
 import d1_gmn.tests.gmn_test_case
@@ -38,21 +40,22 @@
 @d1_test.d1_test_case.reproducible_random_decorator('TestMgmtImport')
 class TestMgmtImport(d1_gmn.tests.gmn_test_case.GMNTestCase):
   @responses.activate
-  def test_1000(self):
-    mock_object_list.add_callback(d1_test.d1_test_case.MOCK_REMOTE_BASE_URL)
-    mock_log_records.add_callback(d1_test.d1_test_case.MOCK_REMOTE_BASE_URL)
-    mock_get_system_metadata.add_callback(
-      d1_test.d1_test_case.MOCK_REMOTE_BASE_URL
-    )
-    mock_get.add_callback(d1_test.d1_test_case.MOCK_REMOTE_BASE_URL)
-
-    with self.mock.disable_management_command_logging():
-      with d1_test.d1_test_case.capture_log() as log_stream:
+  def test_1000(self, caplog):
+    with caplog.at_level(logging.INFO):
+      mock_object_list.add_callback(d1_test.d1_test_case.MOCK_REMOTE_BASE_URL)
+      mock_log_records.add_callback(d1_test.d1_test_case.MOCK_REMOTE_BASE_URL)
+      mock_get_system_metadata.add_callback(
+        d1_test.d1_test_case.MOCK_REMOTE_BASE_URL
+      )
+      mock_get.add_callback(d1_test.d1_test_case.MOCK_REMOTE_BASE_URL)
+
+      with self.mock.disable_management_command_logging():
         with d1_test.d1_test_case.disable_debug_level_logging():
           django.core.management.call_command(
             'import', '--force', '--major=2',
             d1_test.d1_test_case.MOCK_REMOTE_BASE_URL
           )
 
-    log_str = log_stream.getvalue()
-    self.sample.assert_equals(log_str, 'import')
+    self.sample.assert_equals(
+      d1_test.d1_test_case.get_caplog_text(caplog), 'import'
+    )

lib_client/src/d1_client/tests/test_iter_sysmeta_multi.py

@@ -43,7 +43,7 @@ def page_size(request):
   yield request.param
 
 
-@pytest.fixture(scope='function', params=[1, 4, 11])
+@pytest.fixture(scope='function', params=[1, 5])
 def n_workers(request):
   yield request.param
 

lib_common/src/d1_common/tests/test_jwt.py

@@ -153,11 +153,13 @@ def test_1070(self):
     ) is None
 
   @freezegun.freeze_time('2021-01-01')
-  def test_1080(self):
+  def test_1080(self, caplog):
     """log_jwt_bu64_info(): Outputs expected log"""
     jwt_bu64 = self.sample.load('jwt_token_20170612_232523.base64')
-    with d1_test.d1_test_case.capture_log() as log_stream:
+    with caplog.at_level(logging.INFO):
+      d1_test.d1_test_case.clear_caplog(caplog)
       d1_common.cert.jwt.log_jwt_bu64_info(logging.info, "test msg", jwt_bu64)
     self.sample.assert_equals(
-      log_stream.getvalue(), 'jwt_token_log_jwt_bu64_info_expected'
+      d1_test.d1_test_case.get_caplog_text(caplog),
+      'jwt_token_log_jwt_bu64_info_expected'
     )

lib_common/src/d1_common/tests/test_x509.py

@@ -108,11 +108,13 @@ def test_1050(self):
     }, 'primary_and_equivalent_without_subject_info')
 
   @freezegun.freeze_time('2021-01-01')
-  def test_1060(self):
+  def test_1060(self, caplog):
     """log_cert_info(): Outputs expected log"""
     cert_obj = d1_common.cert.x509.deserialize_pem(
       self.cert_simple_subject_info_pem
     )
-    with d1_test.d1_test_case.capture_log() as log_stream:
+    with caplog.at_level(logging.WARN):
       d1_common.cert.x509.log_cert_info(logging.warn, 'test msg', cert_obj)
-    self.sample.assert_equals(log_stream.getvalue(), 'log_cert_info_expected')
+    self.sample.assert_equals(
+      d1_test.d1_test_case.get_caplog_text(caplog), 'log_cert_info_expected'
+    )

test_utilities/src/d1_test/d1_test_case.py

@@ -82,23 +82,37 @@ def capture_std():
     sys.stdout, sys.stderr = old_out, old_err
 
 
-@contextlib.contextmanager
-def capture_log(log_level=logging.DEBUG):
-  """Capture anything output by the logging module. Uses a handler that does not
-  not include any context, such as date-time or originating module to help keep
-  the result stable over time.
+# @contextlib.contextmanager
+# def capture_log(log_level=logging.DEBUG):
+#   """Capture anything output by the logging module. Uses a handler that does not
+#   not include any context, such as timestamp and module name, so that the
+#   result is reproducible over time.
+#   """
+#   stream = StringIO.StringIO()
+#   logger = None
+#   stream_handler = None
+#   try:
+#     logger = logging.getLogger()
+#     logger.level = log_level
+#     stream_handler = logging.StreamHandler(stream)
+#     logger.addHandler(stream_handler)
+#     yield stream
+#   finally:
+#     logger.removeHandler(stream_handler)
+
+
+def get_caplog_text(caplog, logger_name=None):
+  """Return the log messages currently captured by the caplog fixture
+  If {module_name} is set, only messages from the given module are returned.
   """
-  stream = StringIO.StringIO()
-  logger = None
-  stream_handler = None
-  try:
-    logger = logging.getLogger()
-    logger.level = log_level
-    stream_handler = logging.StreamHandler(stream)
-    logger.addHandler(stream_handler)
-    yield stream
-  finally:
-    logger.removeHandler(stream_handler)
+  return '\n'.join([
+    r.getMessage()
+    for r in caplog.records if (logger_name is None) or logger_name == r.name
+  ])
+
+
+def clear_caplog(caplog):
+  caplog.handler.records = []
 
 
 @contextlib.contextmanager

test_utilities/src/d1_test/sample.py

@@ -25,6 +25,7 @@
 import re
 import subprocess
 import tempfile
+import thread
 import traceback
 
 import pytest
@@ -42,6 +43,8 @@
 import django.core
 import django.core.management
 
+tidy_lock = thread.allocate_lock()
+
 
 def start_tidy():
   """Call at start of test run to tidy the samples directory.
@@ -129,16 +132,17 @@ def assert_no_diff(a_obj, b_obj):
 
 
 def get_path(filename):
-  path = os.path.join(d1_common.util.abs_path('test_docs'), filename)
-  if os.path.isfile(path):
+  with tidy_lock:
+    path = os.path.join(d1_common.util.abs_path('test_docs'), filename)
+    if os.path.isfile(path):
+      return path
+    tidy_file_path = os.path.join(
+      d1_common.util.abs_path('test_docs_tidy'), filename
+    )
+    if os.path.isfile(tidy_file_path):
+      os.rename(tidy_file_path, path)
+      logging.info('Moved from tidy: {} -> {}'.format(tidy_file_path, path))
     return path
-  tidy_file_path = os.path.join(
-    d1_common.util.abs_path('test_docs_tidy'), filename
-  )
-  if os.path.isfile(tidy_file_path):
-    os.rename(tidy_file_path, path)
-    logging.info('Moved from tidy: {} -> {}'.format(tidy_file_path, path))
-  return path
 
 
 def load(filename, mode_str='rb'):
@@ -254,7 +258,7 @@ def _get_or_create_path(filename):
   See the test docs for usage.
   """
   path = get_path(filename)
-  logging.info('Sample path: {}'.format(path))
+  logging.debug('Sample path: {}'.format(path))
   if not os.path.isfile(path):
     logging.info('Write new blank file: {}'.format(path))
     with open(path, 'w') as f: