tempest scenario test_server_basic_ops curl meta-data/public-ipv4 test sometimes fail

[Robert Varjasi]

I noticed curl http://169.254.169.254/latest/meta-data/public-ipv4 random failures. For example 1 or 2 in 10 tests failed. There is nothing wrong with my metadata server. When I modified the tempest code locally to check this problem again on a VM when it failed it started to work after a few attempts.

Particular log output from my tempest.log:

2018-10-16 16:30:21.548 12760 INFO paramiko.transport [-] Connected (version 2.0, client dropbear_2012.55)
2018-10-16 16:30:21.691 12760 INFO paramiko.transport [-] Authentication (publickey) successful!
2018-10-16 16:30:21.716 12760 INFO tempest.lib.common.ssh [-] ssh connection to cirros@10.210.204.90 successfully created
2018-10-16 16:30:21.831 12760 INFO tempest.lib.common.ssh [-] Creating ssh connection to '10.210.204.90:22' as 'cirros' with public key authentication
2018-10-16 16:30:21.834 12760 INFO paramiko.transport [-] Connected (version 2.0, client dropbear_2012.55)
2018-10-16 16:30:21.967 12760 INFO paramiko.transport [-] Authentication (publickey) successful!
2018-10-16 16:30:21.998 12760 INFO tempest.lib.common.ssh [-] ssh connection to cirros@10.210.204.90 successfully created
2018-10-16 16:30:22.012 12760 ERROR tempest.lib.common.ssh [-] SSH exec_command stderr: % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
^M 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0curl: (7) couldn't connect to host

2018-10-16 16:30:22.013 12760 ERROR tempest.lib.common.ssh [-] SSH exec_command exit_status: 7
2018-10-16 16:30:22.013 12760 INFO root [-] METADATA IPV4 RESULT:
2018-10-16 16:30:22.013 12760 INFO tempest.lib.common.ssh [-] Creating ssh connection to '10.210.204.90:22' as 'cirros' with public key authentication
2018-10-16 16:30:22.016 12760 INFO paramiko.transport [-] Connected (version 2.0, client dropbear_2012.55)
2018-10-16 16:30:22.153 12760 INFO paramiko.transport [-] Authentication (publickey) successful!
2018-10-16 16:30:22.180 12760 INFO tempest.lib.common.ssh [-] ssh connection to cirros@10.210.204.90 successfully created
2018-10-16 16:30:22.194 12760 ERROR tempest.lib.common.ssh [-] SSH exec_command stderr: % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
^M 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0curl: (7) couldn't connect to host

2018-10-16 16:30:22.194 12760 ERROR tempest.lib.common.ssh [-] SSH exec_command exit_status: 7
2018-10-16 16:30:22.195 12760 INFO root [-] METADATA IPV4 RESULT:
2018-10-16 16:30:22.196 12760 INFO tempest.lib.common.ssh [-] Creating ssh connection to '10.210.204.90:22' as 'cirros' with public key authentication
2018-10-16 16:30:22.198 12760 INFO paramiko.transport [-] Connected (version 2.0, client dropbear_2012.55)
2018-10-16 16:30:22.331 12760 INFO paramiko.transport [-] Authentication (publickey) successful!
2018-10-16 16:30:22.363 12760 INFO tempest.lib.common.ssh [-] ssh connection to cirros@10.210.204.90 successfully created
2018-10-16 16:30:23.042 12760 INFO root [-] METADATA IPV4 RESULT: 10.210.204.90

I think you need to check the result of meta-data/public-ipv4 result more than once to eliminate false positive errors.

[Robert Varjasi (robert.varjasi)]

I am using tempest v18.0.0 with cirros-0.3.5. Openstack release Queens deployed with OSA 17.1.2

[Robert Varjasi (robert.varjasi)]

Important lines are with my custom log outputs:

2018-10-16 16:30:22.013 12760 INFO root [-] METADATA IPV4 RESULT:
2018-10-16 16:30:22.195 12760 INFO root [-] METADATA IPV4 RESULT:
2018-10-16 16:30:23.042 12760 INFO root [-] METADATA IPV4 RESULT: 10.210.204.90

Curl GET request was successful after 3 tries. Before that I got exit code 7 with message "couldn't connect to host" from curl.

[Martin Kopec (mkopec)]

Is this still reproducible? I'm wondering if there is any chance this could have resulted in https://bugs.launchpad.net/tempest/+bug/1860294 ?

[Martin Kopec (mkopec)]

Due to the age of the bug report it's possible it got already fixed as lots of changes have been merged since the bug report. I'll mark this as Invalid, but if you encounter the issue with the latest tempest codebase as well, feel free to reopen.