remove race on globals

[marqh]

changed logging to avoid the race condition on config during testing,

see:
https://travis-ci.org/SciTools/iris/jobs/89628997
https://travis-ci.org/SciTools/iris/jobs/89628998

[DPeterK]

@marqh I hate to say it but you've got test failures in the test you were aiming to fix...

[QuLogic]

This appears to be failing quite regularly now. It might need to be reverted.

[pelson]

This test is a bit strange - it makes no assertions. I was expecting something in the rules.log to be tested...

[pp-mo]

I think from reading it that this usage used to blow up, so this is just a regression test against previous problems.

[pp-mo]

@QuLogic This appears to be failing quite regularly now. It might need to be reverted.

Do you mean just the recent failure on #1829, or have you seen lots of others somewhere -- and are they intermittent, as that one seemed to be ?
I have been looking into that #1829 problem, but I'm currently at a loss to understand how it happened : It seems like the config module had only partially initialised, but I don't see how that can actually happen.

The "race" problem this tries to address is related to multi-threaded testing via nose.
If your observed problems are all like the #1829 one, then I don't think just reverting this will solve anything, as it is supposed to remove exactly that kind of intermittent error which was already proving a problem.

[marqh]

This appears to be failing quite regularly now. It might need to be reverted.

@QuLogic please may you confirm for me that the failures you are observing are on Travis and that the branches include this change?

Please also include a stack trace, or pointer to a travis log, so I can look at the failure mode in more detail

thank you
marqh

[marqh]

i have also observed another failure in this test, but it is not directly caused by this change.

As @pp-mo has indicated, there is something going on where a global:
config.RULE_LOG_IGNORE
is not available from the config module. This global is set at the bottom of config.py and should always exist. There is no race condition or multiple access occuring here, as far as I can see.

If this is the problem being reported, then I don't believe the change in this PR has caused this issue and I don't think the PR should be reverted.
I cannot see the failure mechanism which leads to:

ERROR: test_verbose_logging (iris.tests.test_verbose_fileformat_rules_logging.TestVerboseLogging)

----------------------------------------------------------------------

Traceback (most recent call last):

  File "/home/travis/miniconda/envs/test-environment/lib/python2.7/site-packages/Iris-1.9.0.dev0-py2.7-linux-x86_64.egg/iris/tests/test_verbose_fileformat_rules_logging.py", line 46, in test_verbose_logging

    log_dir='/var/tmp')

  File "/home/travis/miniconda/envs/test-environment/lib/python2.7/site-packages/Iris-1.9.0.dev0-py2.7-linux-x86_64.egg/iris/fileformats/rules.py", line 130, in _prepare_rule_logger

    ignore_users = config.RULE_LOG_IGNORE

AttributeError: 'module' object has no attribute 'RULE_LOG_IGNORE'

it does not fail when I run the test in isolation, it can only occur when run as part of a suite of tests, and it is intermittent

i'll continue looking

[QuLogic]

Hmm, perhaps it's a red-herring that the above error started occurring after merging this one? As far as I can tell, it did not occur on any of @pp-mo's Python 3 PRs until they were updated to include this commit.

[pp-mo]

perhaps it's a red-herring that the above error started occurring after merging this one?

Sort-of.
I think I have at last tracked down the real culprit, which is here :

• https://github.com/SciTools/iris/blob/master/lib/iris/fileformats/rules.py#L376
  So the real problem is that cf_units has a 'config' property (which iris.unit did not cf this), and thus it is now overwriting rules.config with cf_units.config when we execute the first rule.
  Yuck, eh ?

Really, this is an accident waiting to happen, equivalent to a mysterious delayed-action "from xx import *".
It's a nasty practice, in some very old code, and we really ought to get on with phasing out the last of the text rules, compiling odd chunks of text, and the use of 'exec'...
However, I think the really simplest fix for now will be to just rename the "config" variable in rules.py to "iris_config", or somesuch.

I will look into this later on today.

[rhattersley]

It's a nasty practice, in some very old code, and we really ought to get on with phasing out the last of the text rules, compiling odd chunks of text, and the use of 'exec'...

👍

NB. Related to this (but not a fix for this issue) I've put up #1836.

[pp-mo]

#1837 addresses, hopefully