migrate_repo script output clutters unit test output

[Jason Dunsmore]

The console output of each failing unit test is cluttered with ~100 lines of info about the migrate_repo script. Before commit fb5ae22 (https://review.openstack.org/#/c/67759/), the output of a failing test looked like this:

$ python -m testtools.run heat.tests.test_server
Tests running...
======================================================================
FAIL: heat.tests.test_server.ServersTest.test_validate_metadata_too_many
----------------------------------------------------------------------
pythonlogging:'': {{{Validating Server "server_create_image_err" Stack "srv_val_metadata" [d2400014-a936-451b-b891-f971900a3d34]}}}

Traceback (most recent call last):
  File "heat/tests/test_server.py", line 1231, in test_validate_metadata_too_many
    'entries', str(ex))
  File "/home/jason/github/heat/.venv/local/lib/python2.7/site-packages/testtools/testcase.py", line 327, in assertIn
    self.assertThat(haystack, Contains(needle))
  File "/home/jason/github/heat/.venv/local/lib/python2.7/site-packages/testtools/testcase.py", line 406, in assertThat
    raise mismatch_error
MismatchError: 'Instance metadata must nodt contain greater than 3 entries' not in 'Instance metadata must not contain greater than 3 entries. This is the maximum number allowed by your service provider'

Ran 61 tests in 1.551s
FAILED (failures=1)

Now, it looks like this:

$ python -m testtools.run heat.tests.test_server
Tests running...
======================================================================
FAIL: heat.tests.test_server.ServersTest.test_server_validate_personality_file_size_too_big
----------------------------------------------------------------------
pythonlogging:'': {{{
Loading repository /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo...
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/015_grizzly.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/015_grizzly.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/016_timeout_nullable.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/016_timeout_nullable.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/017_event_state_status.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/017_event_state_status.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/018_resource_id_uuid.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/018_resource_id_uuid.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/019_resource_action_status.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/019_resource_action_status.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/020_stack_action.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/020_stack_action.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/021_resource_data.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/021_resource_data.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/022_stack_event_soft_delete.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/022_stack_event_soft_delete.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/023_raw_template_mysql_longtext.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/023_raw_template_mysql_longtext.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/024_event_resource_name.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/024_event_resource_name.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/025_user_creds_drop_service.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/025_user_creds_drop_service.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/026_user_creds_drop_aws.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/026_user_creds_drop_aws.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/027_user_creds_trusts.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/027_user_creds_trusts.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/028_text_mysql_longtext.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/028_text_mysql_longtext.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/029_event_id_to_uuid.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/029_event_id_to_uuid.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/030_remove_uuidutils.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/030_remove_uuidutils.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/031_stack_lock.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/031_stack_lock.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/032_decrypt_method.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/032_decrypt_method.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/033_software_config.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/033_software_config.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/034_raw_template_files.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/034_raw_template_files.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/035_event_uuid_to_id.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/035_event_uuid_to_id.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/036_stack_domain_project.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/036_stack_domain_project.py loaded successfully
Repository /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo loaded successfully
Config: OrderedDict([('db_settings', OrderedDict([('__name__', 'db_settings'), ('repository_id', 'heat'), ('version_table', 'migrate_version'), ('required_dbs', '[]'), ('use_timestamp_numbering', 'False')]))])
Loading repository /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo...
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/015_grizzly.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/015_grizzly.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/016_timeout_nullable.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/016_timeout_nullable.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/017_event_state_status.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/017_event_state_status.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/018_resource_id_uuid.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/018_resource_id_uuid.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/019_resource_action_status.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/019_resource_action_status.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/020_stack_action.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/020_stack_action.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/021_resource_data.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/021_resource_data.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/022_stack_event_soft_delete.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/022_stack_event_soft_delete.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/023_raw_template_mysql_longtext.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/023_raw_template_mysql_longtext.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/024_event_resource_name.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/024_event_resource_name.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/025_user_creds_drop_service.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/025_user_creds_drop_service.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/026_user_creds_drop_aws.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/026_user_creds_drop_aws.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/027_user_creds_trusts.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/027_user_creds_trusts.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/028_text_mysql_longtext.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/028_text_mysql_longtext.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/029_event_id_to_uuid.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/029_event_id_to_uuid.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/030_remove_uuidutils.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/030_remove_uuidutils.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/031_stack_lock.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/031_stack_lock.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/032_decrypt_method.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/032_decrypt_method.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/033_software_config.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/033_software_config.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/034_raw_template_files.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/034_raw_template_files.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/035_event_uuid_to_id.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/035_event_uuid_to_id.py loaded successfully
Loading script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/036_stack_domain_project.py...
Script /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo/versions/036_stack_domain_project.py loaded successfully
Repository /home/jason/github/heat/heat/db/sqlalchemy/migrate_repo loaded successfully
Config: OrderedDict([('db_settings', OrderedDict([('__name__', 'db_settings'), ('repository_id', 'heat'), ('version_table', 'migrate_version'), ('required_dbs', '[]'), ('use_timestamp_numbering', 'False')]))])
Validating Server "server_create_image_err" Stack "srv_val" [cd6a2f19-8295-49c4-b5e1-bb1ea14b4366]
}}}

Traceback (most recent call last):
  File "heat/tests/test_server.py", line 1546, in test_server_validate_personality_file_size_too_big
    "file size (10240 bytes).", str(exc))
  File "/home/jason/github/heat/.venv/local/lib/python2.7/site-packages/testtools/testcase.py", line 321, in assertEqual
    self.assertThat(observed, matcher, message)
  File "/home/jason/github/heat/.venv/local/lib/python2.7/site-packages/testtools/testcase.py", line 406, in assertThat
    raise mismatch_error
MismatchError: !=:
reference = 'The contents of personality file "/fdake/path1" is larger than the maximum allowed personality file size (10240 bytes).'
actual = 'The contents of personality file "/fake/path1" is larger than the maximum allowed personality file size (10240 bytes).'

Ran 70 tests in 1.871s
FAILED (failures=1)

Full details on how to reproduce:
http://paste.openstack.org/show/66572/

[Jason Dunsmore (jasondunsmore)]

Related bugs (Heat unit test cleanup):
https://bugs.launchpad.net/oslo/+bug/1280454
https://bugs.launchpad.net/oslo/+bug/1280435

[Jason Dunsmore (jasondunsmore)]

Now I'm seeing it at fb5ae22~1. I'm having trouble narrowing down the commit when this behavior started. It might be intermittent.

[Angus Salkeld (asalkeld)]

this is irritating me too.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/92971

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/92972

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/92972
Committed: https://git.openstack.org/cgit/openstack/heat/commit/?id=a54406651b1582d5d9e5baa970193d1ac3a9df0c
Submitter: Jenkins
Branch: master

commit a54406651b1582d5d9e5baa970193d1ac3a9df0c
Author: Angus Salkeld <email address hidden>
Date: Fri May 9 14:32:16 2014 +1000

    TestRandomString was calling the wrong setUp

    Just incorrect usage of super(). This was bypassing HeatTestCase.setUp()
    and causing extra logs to be printed.

    Change-Id: I6f77cce53b971b14637e8705c3f73993ac458550
    Partial-bug: 1281226

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/92971
Committed: https://git.openstack.org/cgit/openstack/heat/commit/?id=8ddb4e9ac1c18fc3861acf187e561edc87ad3950
Submitter: Jenkins
Branch: master

commit 8ddb4e9ac1c18fc3861acf187e561edc87ad3950
Author: Angus Salkeld <email address hidden>
Date: Fri May 9 14:28:47 2014 +1000

    Add a test equivalent to default_log_levels

    This is to mainly kill the migrate script logs
    but can be used to quieten down any log.
    Also the migrations were not using the FakeLogger
    so now both are using the same mechanism.

    Fixes-bug: 1281226
    Change-Id: I2f1efcace6a38450020fcbf516ee5026204359d2