Unit test is broken in stable/liberty

[Xing Yang]

stable/liberty unit tests are broken at the moment. The error can be seen in the following patch and a few other backport patches.
There is a call to LOG.exception in the except putils.ProcessExecutionError block. In the unit test, this exception is mocked: mock_open.side_effect = putils.ProcessExecutionError and mock_execute.side_effect = putils.ProcessExecutionError. When trying to print the message using LOG.exception that is not in a real exception block, it throws additional exception.

https://review.openstack.org/#/c/249358/

http://logs.openstack.org/58/249358/1/check/gate-cinder-python27/0aa1713/

2015-11-24 22:58:29.322 | cinder.tests.unit.targets.test_iet_driver.TestIetAdmDriver.test_create_iscsi_target
2015-11-24 22:58:29.322 | -----------------------------------------------------------------------------------
2015-11-24 22:58:29.323 |
2015-11-24 22:58:29.323 | Captured traceback:
2015-11-24 22:58:29.323 | ~~~~~~~~~~~~~~~~~~~
2015-11-24 22:58:29.323 | Traceback (most recent call last):
2015-11-24 22:58:29.323 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/mock/mock.py", line 1305, in patched
2015-11-24 22:58:29.323 | return func(*args, **keywargs)
2015-11-24 22:58:29.323 | File "cinder/tests/unit/targets/test_iet_driver.py", line 109, in test_create_iscsi_target
2015-11-24 22:58:29.324 | self.fake_volumes_dir)
2015-11-24 22:58:29.324 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 422, in assertRaises
2015-11-24 22:58:29.324 | self.assertThat(our_callable, matcher)
2015-11-24 22:58:29.324 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 433, in assertThat
2015-11-24 22:58:29.324 | mismatch_error = self._matchHelper(matchee, matcher, message, verbose)
2015-11-24 22:58:29.324 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 483, in _matchHelper
2015-11-24 22:58:29.324 | mismatch = matcher.match(matchee)
2015-11-24 22:58:29.325 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/matchers/_exception.py", line 108, in match
2015-11-24 22:58:29.325 | mismatch = self.exception_matcher.match(exc_info)
2015-11-24 22:58:29.325 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/matchers/_higherorder.py", line 62, in match
2015-11-24 22:58:29.325 | mismatch = matcher.match(matchee)
2015-11-24 22:58:29.325 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 414, in match
2015-11-24 22:58:29.325 | reraise(*matchee)
2015-11-24 22:58:29.325 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/matchers/_exception.py", line 101, in match
2015-11-24 22:58:29.326 | result = matchee()
2015-11-24 22:58:29.326 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 969, in __call__
2015-11-24 22:58:29.326 | return self._callable_object(*self._args, **self._kwargs)
2015-11-24 22:58:29.326 | File "cinder/volume/targets/iet.py", line 146, in create_iscsi_target
2015-11-24 22:58:29.326 | self.update_config_file(name, tid, path, config_auth)
2015-11-24 22:58:29.326 | File "cinder/volume/targets/iet.py", line 180, in update_config_file
2015-11-24 22:58:29.327 | {'conf': conf_file, 'vol_id': vol_id})
2015-11-24 22:58:29.327 | File "/usr/lib/python2.7/logging/__init__.py", line 1458, in exception
2015-11-24 22:58:29.327 | self.logger.error(msg, *args, **kwargs)
2015-11-24 22:58:29.327 | File "/usr/lib/python2.7/logging/__init__.py", line 1178, in error
2015-11-24 22:58:29.327 | self._log(ERROR, msg, args, **kwargs)
2015-11-24 22:58:29.327 | File "/usr/lib/python2.7/logging/__init__.py", line 1271, in _log
2015-11-24 22:58:29.327 | self.handle(record)
2015-11-24 22:58:29.328 | File "/usr/lib/python2.7/logging/__init__.py", line 1281, in handle
2015-11-24 22:58:29.328 | self.callHandlers(record)
2015-11-24 22:58:29.328 | File "/usr/lib/python2.7/logging/__init__.py", line 1321, in callHandlers
2015-11-24 22:58:29.328 | hdlr.handle(record)
2015-11-24 22:58:29.328 | File "/usr/lib/python2.7/logging/__init__.py", line 749, in handle
2015-11-24 22:58:29.328 | self.emit(record)
2015-11-24 22:58:29.328 | File "/usr/lib/python2.7/logging/__init__.py", line 879, in emit
2015-11-24 22:58:29.329 | self.handleError(record)
2015-11-24 22:58:29.329 | File "/usr/lib/python2.7/logging/__init__.py", line 802, in handleError
2015-11-24 22:58:29.329 | None, sys.stderr)
2015-11-24 22:58:29.329 | File "/usr/lib/python2.7/traceback.py", line 125, in print_exception
2015-11-24 22:58:29.329 | print_tb(tb, limit, file)
2015-11-24 22:58:29.329 | File "/usr/lib/python2.7/traceback.py", line 69, in print_tb
2015-11-24 22:58:29.330 | line = linecache.getline(filename, lineno, f.f_globals)
2015-11-24 22:58:29.330 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/lib/python2.7/linecache.py", line 14, in getline
2015-11-24 22:58:29.330 | lines = getlines(filename, module_globals)
2015-11-24 22:58:29.330 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/lib/python2.7/linecache.py", line 40, in getlines
2015-11-24 22:58:29.330 | return updatecache(filename, module_globals)
2015-11-24 22:58:29.330 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/lib/python2.7/linecache.py", line 132, in updatecache
2015-11-24 22:58:29.413 | with open(fullname, 'rU') as fp:
2015-11-24 22:58:29.413 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/mock/mock.py", line 1062, in __call__
2015-11-24 22:58:29.413 | return _mock_self._mock_call(*args, **kwargs)
2015-11-24 22:58:29.413 | File "/home/jenkins/workspace/gate-cinder-python27/.tox/py27/local/lib/python2.7/site-packages/mock/mock.py", line 1118, in _mock_call
2015-11-24 22:58:29.414 | raise effect
2015-11-24 22:58:29.414 | oslo_concurrency.processutils.ProcessExecutionError: Unexpected error while running command.
2015-11-24 22:58:29.414 | Command: None
2015-11-24 22:58:29.414 | Exit code: -
2015-11-24 22:58:29.414 | Stdout: None
2015-11-24 22:58:29.414 | Stderr: None
2015-11-24 22:58:29.414 |
2015-11-24 22:58:29.415 |
2015-11-24 22:58:29.415 | Captured stderr:
2015-11-24 22:58:29.415 | ~~~~~~~~~~~~~~~~
2015-11-24 22:58:29.415 | Traceback (most recent call last):
2015-11-24 22:58:29.415 | File "/usr/lib/python2.7/logging/__init__.py", line 851, in emit
2015-11-24 22:58:29.415 |
2015-11-24 22:58:29.415 |

The fix is to mock the LOG in the unit test.

This problem is already fixed in the master as part of porting the test to py3.

https://github.com/openstack/cinder/commit/7d849b5da48a4edb29db288c041b945cc34f667a

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/liberty
Review: https://review.openstack.org/250039

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/250039
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=e0a6b092192023c6a451c7e1a8613b4a2a210efe
Submitter: Jenkins
Branch: stable/liberty

commit e0a6b092192023c6a451c7e1a8613b4a2a210efe
Author: Xing Yang <email address hidden>
Date: Mon Nov 16 08:21:49 2015 -0500

    LOG.exception should be mocked in unit test

    There is a call to LOG.exception in the exception block
    (except putils.ProcessExecutionError).

    In the unit test, this exception is mocked:
    mock_open.side_effect = putils.ProcessExecutionError
    mock_execute.side_effect = putils.ProcessExecutionError.
    When trying to print the message using LOG.exception that
    is not in a real exception block, it throws additional exception.

    All patches to stable/liberty are blocked by this unit test
    failure. See this patch here:
    https://review.openstack.org/#/c/249358/

    This bug was fixed in the trunk as part of porting the test
    to python3. This fix was manually cherry-picked from the
    following commit because that commit also had other changes:
    https://github.com/openstack/cinder/commit/
    7d849b5da48a4edb29db288c041b945cc34f667a

    Change-Id: I2960ac83ee772ce2b4bda3de7eb76789e6f1a0ac
    Closes-Bug: #1519978

[Thierry Carrez (ttx)]

This issue was fixed in the cinder 7.0.1 release (liberty).