2019-03-04 07:21:39.210217 | primary | ==============================
2019-03-04 07:21:39.210294 | primary | Failed 1 tests - output below:
2019-03-04 07:21:39.210365 | primary | ==============================
2019-03-04 07:21:39.210390 | primary |
2019-03-04 07:21:39.210629 | primary | ec2api_tempest_plugin.scenario.test_instances_in_vpc.InstancesInVPCTest.test_default_gateway[id-9c3a8066-68b2-4bd0-85e0-6d4a0d7cb053]
2019-03-04 07:21:39.210884 | primary | -------------------------------------------------------------------------------------------------------------------------------------
2019-03-04 07:21:39.210915 | primary |
2019-03-04 07:21:39.210969 | primary | Captured traceback:
2019-03-04 07:21:39.211023 | primary | ~~~~~~~~~~~~~~~~~~~
2019-03-04 07:21:39.211104 | primary | Traceback (most recent call last):
2019-03-04 07:21:39.211331 | primary | File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/base.py", line 239, in wrapper
2019-03-04 07:21:39.211430 | primary | return f(self, *func_args, **func_kwargs)
2019-03-04 07:21:39.211725 | primary | File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py", line 170, in test_default_gateway
2019-03-04 07:21:39.211823 | primary | self.assertEqual('', resp)
2019-03-04 07:21:39.212048 | primary | File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/testtools/testcase.py", line 411, in assertEqual
2019-03-04 07:21:39.212150 | primary | self.assertThat(observed, matcher, message)
2019-03-04 07:21:39.212369 | primary | File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/testtools/testcase.py", line 498, in assertThat
2019-03-04 07:21:39.212436 | primary | raise mismatch_error
2019-03-04 07:21:39.212622 | primary | testtools.matchers._impl.MismatchError: '' != u'PING 172.24.5.136 (172.24.5.136): 56 data bytes\n'
2019-03-04 07:21:39.212662 | primary |
2019-03-04 07:21:39.212688 | primary |
2019-03-04 07:21:39.212747 | primary | Captured pythonlogging:
2019-03-04 07:21:39.212806 | primary | ~~~~~~~~~~~~~~~~~~~~~~~
2019-03-04 07:21:39.213085 | primary | 2019-03-04 07:12:24,757 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.delete_security_group(GroupName=tempest-sgName-2021022394)
2019-03-04 07:21:39.213366 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 85, 'create_standard_security_group')
2019-03-04 07:21:39.213640 | primary | 2019-03-04 07:12:32,563 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.terminate_instances(InstanceIds=['i-5fc6be21'])
2019-03-04 07:21:39.213885 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/base.py', 837, 'run_instance')
2019-03-04 07:21:39.214102 | primary | 2019-03-04 07:12:36,427 3549 INFO [ec2api_tempest_plugin.base] State transition "pending" ==> "running" 3 second
2019-03-04 07:21:39.214344 | primary | 2019-03-04 07:12:40,664 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.release_address(AllocationId=eipalloc-96f1ac38)
2019-03-04 07:21:39.214595 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 67, 'allocate_address')
2019-03-04 07:21:39.214873 | primary | 2019-03-04 07:12:42,426 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.disassociate_address(AssociationId=eipassoc-96f1ac38)
2019-03-04 07:21:39.215148 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 47, 'get_instance_ip')
2019-03-04 07:21:39.215765 | primary | 2019-03-04 07:12:42,717 3549 DEBUG [ec2api_tempest_plugin.base] Addresses: [{u'NetworkInterfaceId': 'eni-c7570332', u'AllocationId': 'eipalloc-96f1ac38', u'PrivateIpAddress': '172.31.2.27', u'AssociationId': 'eipassoc-96f1ac38', u'NetworkInterfaceOwnerId': '8a9d8d10353344cb8400f58fabdbf93d', u'InstanceId': 'i-5fc6be21', u'Domain': 'vpc', u'PublicIp': '172.24.5.136'}]
2019-03-04 07:21:39.215984 | primary | 2019-03-04 07:12:44,027 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.delete_vpc(VpcId=vpc-7aaaa04a)
2019-03-04 07:21:39.216276 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 87, 'test_default_gateway')
2019-03-04 07:21:39.216500 | primary | 2019-03-04 07:12:50,504 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.delete_subnet(SubnetId=subnet-6e171035)
2019-03-04 07:21:39.216791 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 95, 'test_default_gateway')
2019-03-04 07:21:39.217031 | primary | 2019-03-04 07:12:56,604 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.delete_subnet(SubnetId=subnet-4aae4123)
2019-03-04 07:21:39.218163 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 102, 'test_default_gateway')
2019-03-04 07:21:39.218421 | primary | 2019-03-04 07:12:56,635 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.delete_internet_gateway(InternetGatewayId=igw-7bba3ddc)
2019-03-04 07:21:39.218715 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 107, 'test_default_gateway')
2019-03-04 07:21:39.219028 | primary | 2019-03-04 07:12:59,313 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.detach_internet_gateway(VpcId=vpc-7aaaa04a, InternetGatewayId=igw-7bba3ddc)
2019-03-04 07:21:39.219319 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 111, 'test_default_gateway')
2019-03-04 07:21:39.219551 | primary | 2019-03-04 07:13:01,664 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.delete_route_table(RouteTableId=rtb-b4533147)
2019-03-04 07:21:39.219845 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 118, 'test_default_gateway')
2019-03-04 07:21:39.220099 | primary | 2019-03-04 07:13:03,163 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.disassociate_route_table(AssociationId=rtbassoc-4aae4123)
2019-03-04 07:21:39.220383 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 123, 'test_default_gateway')
2019-03-04 07:21:39.220623 | primary | 2019-03-04 07:13:04,093 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.delete_key_pair(KeyName=tempest-testkey-1997975995)
2019-03-04 07:21:39.220881 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 76, 'create_key_pair')
2019-03-04 07:21:39.221132 | primary | 2019-03-04 07:13:08,573 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.terminate_instances(InstanceIds=['i-8a5ae901'])
2019-03-04 07:21:39.221367 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/base.py', 837, 'run_instance')
2019-03-04 07:21:39.221572 | primary | 2019-03-04 07:13:12,937 3549 INFO [ec2api_tempest_plugin.base] State transition "pending" ==> "running" 4 second
2019-03-04 07:21:39.221815 | primary | 2019-03-04 07:13:16,886 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.terminate_instances(InstanceIds=['i-074c3c1b'])
2019-03-04 07:21:39.222065 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/base.py', 837, 'run_instance')
2019-03-04 07:21:39.222272 | primary | 2019-03-04 07:13:19,993 3549 INFO [ec2api_tempest_plugin.base] State transition "pending" ==> "running" 3 second
2019-03-04 07:21:39.222505 | primary | 2019-03-04 07:13:23,151 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.release_address(AllocationId=eipalloc-48e00712)
2019-03-04 07:21:39.222754 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 67, 'allocate_address')
2019-03-04 07:21:39.223025 | primary | 2019-03-04 07:13:24,789 3549 DEBUG [ec2api_tempest_plugin.base] For cleaning up: EC2.disassociate_address(AssociationId=eipassoc-48e00712)
2019-03-04 07:21:39.223280 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 47, 'get_instance_ip')
2019-03-04 07:21:39.223876 | primary | 2019-03-04 07:13:25,059 3549 DEBUG [ec2api_tempest_plugin.base] Addresses: [{u'NetworkInterfaceId': 'eni-18e5b381', u'AllocationId': 'eipalloc-48e00712', u'PrivateIpAddress': '10.10.1.68', u'AssociationId': 'eipassoc-48e00712', u'NetworkInterfaceOwnerId': '8a9d8d10353344cb8400f58fabdbf93d', u'InstanceId': 'i-074c3c1b', u'Domain': 'vpc', u'PublicIp': '172.24.5.192'}]
2019-03-04 07:21:39.224147 | primary | 2019-03-04 07:13:27,053 3549 INFO [tempest.lib.common.ssh] Creating ssh connection to '172.24.5.192:22' as 'cirros' with public key authentication
2019-03-04 07:21:39.224544 | primary | 2019-03-04 07:13:30,051 3549 WARNING [tempest.lib.common.ssh] Failed to establish authenticated ssh connection to cirros@172.24.5.192 ([Errno None] Unable to connect to port 22 on 172.24.5.192). Number attempts: 1. Retry after 2 seconds.
2019-03-04 07:21:39.224944 | primary | 2019-03-04 07:13:33,051 3549 WARNING [tempest.lib.common.ssh] Failed to establish authenticated ssh connection to cirros@172.24.5.192 ([Errno None] Unable to connect to port 22 on 172.24.5.192). Number attempts: 2. Retry after 3 seconds.
2019-03-04 07:21:39.225351 | primary | 2019-03-04 07:13:36,558 3549 WARNING [tempest.lib.common.ssh] Failed to establish authenticated ssh connection to cirros@172.24.5.192 ([Errno None] Unable to connect to port 22 on 172.24.5.192). Number attempts: 3. Retry after 4 seconds.
2019-03-04 07:21:39.225767 | primary | 2019-03-04 07:13:41,066 3549 WARNING [tempest.lib.common.ssh] Failed to establish authenticated ssh connection to cirros@172.24.5.192 ([Errno None] Unable to connect to port 22 on 172.24.5.192). Number attempts: 4. Retry after 5 seconds.
2019-03-04 07:21:39.226178 | primary | 2019-03-04 07:13:46,574 3549 WARNING [tempest.lib.common.ssh] Failed to establish authenticated ssh connection to cirros@172.24.5.192 ([Errno None] Unable to connect to port 22 on 172.24.5.192). Number attempts: 5. Retry after 6 seconds.
2019-03-04 07:21:39.226397 | primary | 2019-03-04 07:13:53,384 3549 INFO [tempest.lib.common.ssh] ssh connection to cirros@172.24.5.192 successfully created
2019-03-04 07:21:39.226663 | primary | 2019-03-04 07:13:55,093 3549 INFO [tempest.lib.common.ssh] Creating ssh connection to '172.24.5.192:22' as 'cirros' with public key authentication
2019-03-04 07:21:39.226905 | primary | 2019-03-04 07:13:55,378 3549 INFO [tempest.lib.common.ssh] ssh connection to cirros@172.24.5.192 successfully created
2019-03-04 07:21:39.227170 | primary | 2019-03-04 07:13:55,435 3549 INFO [tempest.lib.common.ssh] Creating ssh connection to '172.24.5.192:22' as 'cirros' with public key authentication
2019-03-04 07:21:39.228383 | primary | 2019-03-04 07:13:55,754 3549 INFO [tempest.lib.common.ssh] ssh connection to cirros@172.24.5.192 successfully created
2019-03-04 07:21:39.228652 | primary | 2019-03-04 07:13:55,872 3549 INFO [tempest.lib.common.ssh] Creating ssh connection to '172.24.5.192:22' as 'cirros' with public key authentication
2019-03-04 07:21:39.228867 | primary | 2019-03-04 07:13:56,207 3549 INFO [tempest.lib.common.ssh] ssh connection to cirros@172.24.5.192 successfully created
2019-03-04 07:21:39.229159 | primary | 2019-03-04 07:13:56,289 3549 INFO [tempest.lib.common.ssh] Creating ssh connection to '172.24.5.192:22' as 'cirros' with public key authentication
2019-03-04 07:21:39.229380 | primary | 2019-03-04 07:13:56,571 3549 INFO [tempest.lib.common.ssh] ssh connection to cirros@172.24.5.192 successfully created
2019-03-04 07:21:39.229638 | primary | 2019-03-04 07:13:56,650 3549 INFO [tempest.lib.common.ssh] Creating ssh connection to '172.24.5.192:22' as 'cirros' with public key authentication
2019-03-04 07:21:39.229851 | primary | 2019-03-04 07:13:56,932 3549 INFO [tempest.lib.common.ssh] ssh connection to cirros@172.24.5.192 successfully created
2019-03-04 07:21:39.230118 | primary | 2019-03-04 07:13:57,511 3549 INFO [tempest.lib.common.ssh] Creating ssh connection to '172.24.5.192:22' as 'cirros' with public key authentication
2019-03-04 07:21:39.230337 | primary | 2019-03-04 07:13:57,813 3549 INFO [tempest.lib.common.ssh] ssh connection to cirros@172.24.5.192 successfully created
2019-03-04 07:21:39.230575 | primary | 2019-03-04 07:13:58,389 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.disassociate_address(AssociationId=eipassoc-48e00712)
2019-03-04 07:21:39.230850 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 47, 'get_instance_ip')
2019-03-04 07:21:39.231018 | primary | 2019-03-04 07:13:59,926 3549 DEBUG [ec2api_tempest_plugin.base] Addresses: []
2019-03-04 07:21:39.231252 | primary | 2019-03-04 07:13:59,926 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.release_address(AllocationId=eipalloc-48e00712)
2019-03-04 07:21:39.231504 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 67, 'allocate_address')
2019-03-04 07:21:39.231732 | primary | 2019-03-04 07:14:01,256 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.terminate_instances(InstanceIds=['i-074c3c1b'])
2019-03-04 07:21:39.231974 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/base.py', 837, 'run_instance')
2019-03-04 07:21:39.232209 | primary | 2019-03-04 07:14:05,970 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.terminate_instances(InstanceIds=['i-8a5ae901'])
2019-03-04 07:21:39.232443 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/base.py', 837, 'run_instance')
2019-03-04 07:21:39.232677 | primary | 2019-03-04 07:14:09,941 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.delete_key_pair(KeyName=tempest-testkey-1997975995)
2019-03-04 07:21:39.232926 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 76, 'create_key_pair')
2019-03-04 07:21:39.233191 | primary | 2019-03-04 07:14:10,041 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.disassociate_route_table(AssociationId=rtbassoc-4aae4123)
2019-03-04 07:21:39.233483 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 123, 'test_default_gateway')
2019-03-04 07:21:39.233711 | primary | 2019-03-04 07:14:10,751 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.delete_route_table(RouteTableId=rtb-b4533147)
2019-03-04 07:21:39.234012 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 118, 'test_default_gateway')
2019-03-04 07:21:39.234289 | primary | 2019-03-04 07:14:10,796 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.detach_internet_gateway(VpcId=vpc-7aaaa04a, InternetGatewayId=igw-7bba3ddc)
2019-03-04 07:21:39.234574 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 111, 'test_default_gateway')
2019-03-04 07:21:39.234842 | primary | 2019-03-04 07:14:12,981 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.delete_internet_gateway(InternetGatewayId=igw-7bba3ddc)
2019-03-04 07:21:39.235152 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 107, 'test_default_gateway')
2019-03-04 07:21:39.235374 | primary | 2019-03-04 07:14:13,016 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.delete_subnet(SubnetId=subnet-4aae4123)
2019-03-04 07:21:39.235665 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 102, 'test_default_gateway')
2019-03-04 07:21:39.235882 | primary | 2019-03-04 07:14:18,102 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.delete_subnet(SubnetId=subnet-6e171035)
2019-03-04 07:21:39.236173 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 95, 'test_default_gateway')
2019-03-04 07:21:39.236380 | primary | 2019-03-04 07:14:22,693 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.delete_vpc(VpcId=vpc-7aaaa04a)
2019-03-04 07:21:39.236664 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/test_instances_in_vpc.py', 87, 'test_default_gateway')
2019-03-04 07:21:39.236901 | primary | 2019-03-04 07:14:24,034 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.disassociate_address(AssociationId=eipassoc-96f1ac38)
2019-03-04 07:21:39.237172 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 47, 'get_instance_ip')
2019-03-04 07:21:39.237330 | primary | 2019-03-04 07:14:25,432 3549 DEBUG [ec2api_tempest_plugin.base] Addresses: []
2019-03-04 07:21:39.238577 | primary | 2019-03-04 07:14:25,432 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.release_address(AllocationId=eipalloc-96f1ac38)
2019-03-04 07:21:39.238864 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 67, 'allocate_address')
2019-03-04 07:21:39.239107 | primary | 2019-03-04 07:14:26,556 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.terminate_instances(InstanceIds=['i-5fc6be21'])
2019-03-04 07:21:39.239348 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/base.py', 837, 'run_instance')
2019-03-04 07:21:39.239594 | primary | 2019-03-04 07:14:31,220 3549 DEBUG [ec2api_tempest_plugin.base] Cleaning up: EC2.delete_security_group(GroupName=tempest-sgName-2021022394)
2019-03-04 07:21:39.239866 | primary | From: ('/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/ec2api_tempest_plugin/scenario/base.py', 85, 'create_standard_security_group')
2019-03-04 07:21:39.239897 | primary |
2019-03-04 07:21:39.239922 | primary |
