Attachment 1473946 Details for Bug 1610736 – automation.log

automation.log

automation.log (text/plain), 88.59 KB, created by Danylo Kholodov on 2018-08-07 10:29:13 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Danylo Kholodov

Created: 2018-08-07 10:29:13 UTC

Size: 88.59 KB

patch

obsolete

>2018-08-07 09:56:28,600 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:56:28,750 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/settings {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:56:28,900 [I] [cfme] Pushed appliance 10.0.0.90 on stack (was empty before)  (cfme/utils/appliance/__init__.py:2900)
>2018-08-07 09:57:08,705 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'expand': 'resources'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:09,909 [I] [cfme] ============================ Starting new test run ============================= (cfme/fixtures/log.py:32)
>2018-08-07 09:57:09,910 [I] [cfme] Collected 1 items (cfme/fixtures/log.py:35)
>2018-08-07 09:57:09,940 [I] [cfme] ---------------------- test_create_instance[openstack-11] ---------------------- (cfme/fixtures/log.py:27)
>2018-08-07 09:57:09,942 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:10,072 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:10,196 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/settings {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:10,441 [I] [cfme] default appliance ssh credentials are valid (cfme/utils/appliance/__init__.py:879)
>2018-08-07 09:57:10,442 [I] [cfme] Running command 'ip address show' (cfme/utils/ssh.py:295)
>2018-08-07 09:57:10,835 [I] [cfme] [DB] db_url is postgresql://root:smartvm@10.0.0.90:5432/vmdb_production (cfme/utils/db.py:195)
>2018-08-07 09:57:10,952 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:11,080 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/settings {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:11,231 [I] [cfme] Running command 'test -s /etc/init.d/merkyl' (cfme/utils/ssh.py:295)
>2018-08-07 09:57:11,390 [I] [cfme] Checking appliance's /etc/hosts for a resolvable hostname (cfme/fixtures/base.py:48)
>2018-08-07 09:57:11,391 [I] [cfme] Running command 'host 10.0.0.90' (cfme/utils/ssh.py:295)
>2018-08-07 09:57:11,611 [I] [cfme] Get the resolvable hostname (cfme/utils/log.py:173)
>2018-08-07 09:57:11,612 [I] [cfme] Get the resolvable hostname (cfme/utils/log.py:173)
>2018-08-07 09:57:11,612 [I] [cfme] Running command 'grep cfme.redhat.local /etc/hosts' (cfme/utils/ssh.py:295)
>2018-08-07 09:57:11,874 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'expand': 'resources'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:12,032 [I] [cfme] removing provider 'uc_ci' (cfme/fixtures/provider.py:119)
>2018-08-07 09:57:12,033 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:12,160 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000133 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:12,290 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000133 {'action': u'delete'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 09:57:12,422 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 09:57:12,423 [I] [cfme] waiting for provider 'uc_ci' to disappear (cfme/fixtures/provider.py:123)
>2018-08-07 09:57:12,425 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:12,555 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000133 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:12,686 [I] [cfme] Waiting for a provider to delete... (cfme/common/provider.py:766)
>2018-08-07 09:57:12,687 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000133 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:13,829 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000133 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:14,963 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000133 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:16,112 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000133 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:17,253 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000133 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:18,391 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000133 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:19,530 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000133 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:19,653 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/settings {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:19,805 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'expand': 'resources'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:19,951 [I] [cfme] Setting up provider via REST: uc_ci (cfme/common/provider.py:404)
>2018-08-07 09:57:19,953 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers {'action': u'create', 'resource': {'name': 'uc_ci', 'type': 'ManageIQ::Providers::Openstack::InfraManager', 'hostname': '192.168.24.2', 'connection_configurations': [{'endpoint': {'security_protocol': 'ssl', 'role': 'default', 'port': 13000}}], 'uid_ems': 'default', 'credentials': [{'password': '645feae33a1d4c3ad596e4ba12648515d6236ef8', 'userid': 'admin'}, {'auth_type': 'ssh_keypair', 'userid': 'heat-admin', 'auth_key': '-----BEGIN RSA PRIVATE KEY-----\nMIIEpQIBAAKCAQEAr0Kj5sL7QrkMn5+YK7/0DxCeeYmV0qTBbOTv0SGf4FHUKiNO ZcHnQHY+AF/ilAliyL9nxFW04nsVPwLWFQRunDu2SS9d05cRYwZJqLyrwNMAAMeg GeDGlVk2MDChNoRrDZZJ1PfRBME9SF1jHfPDnms18CEEGWUff1Tjad6toM/draKP Keh6M0Rs1slVUjACyB1H3I9GceY7k8aQUJtHKR/6u/X3ae4k27+yEFGx4ail1XvR zq9kaqQbiCxe2P+NMFVIZQsCXgl9v9pux1WLyg3xYnLCtdgJfttQNkpmvApAhSXg Yjyr19po8hYUSGWbOk1xjPSFNmAJodFaL9LN4QIDAQABAoIBAAIp124c0A81y5MY 3D8GApRBB0PG0AOmpwCaHt+9A4U4XV8bynb1Gs6v5voINPrQ1thVjIle6Xm2PT/m 4A+oW1kwX4KtxAG9pqhLRpN/qLsbn69ix3YqUSk8za9wmjzbC5tCVKz9ViYx4HjJ NlUDUlHdTvAk6DEMD4R53sjKx+fpQ76Qrxr7WHGJAtr1LQz2xr1hnxpdc5h4gaXy Bs1Qui0M3+q1w6DsdNXLR9ZM01QN+6vOHhdJFqHYxUq/C3s+wjouQIYJN7z8/ZVu QWo4n5ZOxDFjiCxUuo47Wzqwtuyu+gdheHz6vNsMBGEAZRlUvG0TP7buSf6/UFF6 7WTjJWUCgYEA2/kcA1SDg5GMK2ZPjd+u9XL2JPg1RX7w7ooLkSW2r90opk2F5G9Q 42DUvvA9oF0JYBfG5+SyzBnVEVeKcNXFquPewEe/IKrkHe5ed2Ju9OnntjmoCQkN MUVEWVqiaIIocSZdeVvWgsjMoujthTqkFanU4Pk0M1KsD8FBAWwPCY8CgYEAy/bX qLxAwTDsWDuezMhQaf/qiwFJ4LJfRUzrLPFzJmXl755SOLvuqD5w66nWKev/35kR B9komy8jfELhJUw/bi8y6DiXlQ5d1giYfq38e///d4zfv7sQLk8ir1Pr1UeFLyNz UlBf4j6PYRXjOgSho16Th1fxZDtCWnTlgkbqmY8CgYEArefPgcJ7BrU2v8ju9Bb3 Vw1AFBI2625kQ/HXGzVZrMeHr5JyXBq1NE4FY77CudlT5ChoFET2Je32SPOQe4xF 7cig/hq6u7TfC9q7zF6BohaaHbKPajVBvMYqNwo0g7MDDhFqrNsyR8tAHTtRLJcj ygyuQ/5AiqK9bOc34Uvwx3kCgYEAvV8B/HhM5xI1XfZ9CkUx5Djn2wfnP+hc7Eru T1wePZh+VGv6ixJyE2NmFGgrn+CuQTwsw8ysFuk9WTH/OFIC0pqf+VwR4SLlnMN+ Up/XvImC98ykMa/M5jIzUfXpEKzGy21utQ5K+BR9qvZXcpa6PKSi9RaB2T3r7XB7 ZunRB6ECgYEAmQ38xl7AZgIW0rkEe/9mm0naMwG4YPXVYJxByRfmaoJ7qK9dEDYa tUNg+crSvl+JZxprkARZTjIq4Mwbg/JL/q5etM6tK4BKuJGSCGEqZ16fUYFUyDj1 c2q99tcpGItrbccHjRjSbxk2FVDTnhbxmftWFYelTM/uIJTcgEtNpzU=\n-----END RSA PRIVATE KEY-----'}], 'ipaddress': '192.168.24.2', 'api_version': 'v3'}} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 09:57:20,153 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 09:57:20,156 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:20,302 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:20,443 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:57:20,581 [I] [cfme] (rest-api) [RESTAPI] OPTIONS https://10.0.0.90/api/providers {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:143)
>2018-08-07 09:58:20,600 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:58:20,749 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:58:20,889 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:59:21,064 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:59:21,205 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 09:59:21,343 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:00:21,484 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:00:21,622 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:00:21,755 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:01:21,890 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:01:22,043 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:01:22,180 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:02:22,319 [I] [cfme]  Time for a refresh! (cfme/common/provider.py:590)
>2018-08-07 10:02:22,321 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:02:22,461 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:02:22,603 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000135 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:02:22,754 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:02:22,755 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:02:22,883 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:02:23,014 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:03:23,169 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:03:23,320 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:03:23,459 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:04:23,655 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:04:23,805 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:04:23,954 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:05:24,179 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:05:24,317 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:05:24,458 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:06:24,624 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:06:24,756 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:06:24,892 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:07:25,060 [I] [cfme]  Time for a refresh! (cfme/common/provider.py:590)
>2018-08-07 10:07:25,062 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:07:25,199 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:07:25,341 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000135 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:07:25,487 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:07:25,488 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:07:25,624 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:07:25,772 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:08:25,971 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:08:26,111 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:08:26,251 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:09:26,443 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:09:26,585 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:09:26,718 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:10:26,853 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:10:26,991 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:10:27,136 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:11:27,286 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:11:27,426 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:11:27,558 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:27,695 [I] [cfme]  Time for a refresh! (cfme/common/provider.py:590)
>2018-08-07 10:12:27,697 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:27,834 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:27,976 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000135 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:28,123 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:28,125 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:28,254 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:28,385 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:28,554 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "uc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:28,681 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:28,812 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000135 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:28,946 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'expand': 'resources'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:29,106 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:29,233 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:29,369 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:29,529 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:29,659 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:29,797 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:29,933 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:29,936 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:30,063 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:30,198 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:30,334 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:30,336 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:30,463 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:30,586 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:30,736 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:30,861 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:30,988 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:31,119 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:32,120 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:32,248 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:32,379 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:32,529 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:32,655 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:32,782 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:32,911 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:33,913 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:34,041 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:34,167 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:34,318 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:34,438 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:34,581 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:34,750 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:35,751 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:35,894 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:36,026 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:36,176 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:36,305 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:36,437 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:36,568 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:37,569 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:37,701 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:37,837 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:37,987 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:38,128 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:38,260 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:38,398 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:39,400 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:39,531 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:39,663 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:39,813 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:39,940 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:40,070 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:40,203 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:41,204 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:41,337 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:41,473 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:41,633 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:41,767 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:41,902 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:42,043 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:43,044 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:43,186 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:43,339 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:43,489 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:43,620 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:43,759 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:43,900 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:44,901 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:45,034 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:45,172 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:45,321 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:45,454 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:45,601 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:45,743 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:46,744 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:46,880 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:47,027 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:47,207 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:47,343 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:47,480 [I] [cfme] (rest-api) [RESTAPI] POST https://10.0.0.90/api/providers/1000000000125 {'action': u'refresh'} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:115)
>2018-08-07 10:12:47,629 [I] [cfme] (rest-api) [RESTAPI] RESPONSE <Response [200]> (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:118)
>2018-08-07 10:12:48,630 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers {'filter[]': [u'name = "oc_ci"']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:48,780 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/providers/1000000000125 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:48,911 [I] [cfme] Running command 'date --iso-8601=seconds -u' (cfme/utils/ssh.py:295)
>2018-08-07 10:12:49,083 [I] [cfme] [UI-NAV/InstanceCollection/Provision]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:12:49,083 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:49,227 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:49,359 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:12:49,360 [I] [cfme] starting browser (cfme/utils/browser.py:327)
>2018-08-07 10:12:49,361 [I] [cfme] starting browser for 'https://10.0.0.90/' (cfme/utils/browser.py:335)
>2018-08-07 10:12:51,816 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:51,946 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:52,076 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:12:52,092 [I] [cfme] (MiqBrowser) Opened browser firefox 38.6.0 (cfme/utils/appliance/implementations/ui.py:256)
>2018-08-07 10:12:53,332 [I] [cfme] [UI-NAV/InstanceCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:12:53,333 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:53,463 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:53,593 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:12:53,729 [I] [cfme] IPAppliance.from_json('{"container": null, "ui_port": 443, "ssh_port": 22, "openshift_creds": {}, "ui_protocol": "https", "hostname": "10.0.0.90", "db_port": 5432, "project": null, "is_dev": false, "db_host": null, "browser_steal": false}').user was set to None before, therefore generating an admin user: admin/smartvm (cfme/utils/appliance/__init__.py:356)
>2018-08-07 10:12:53,756 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:53,878 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:54,006 [I] [cfme] [UI-NAV/Server/LoggedIn]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:12:54,007 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:54,134 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:54,265 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:12:54,434 [I] [cfme] [UI-NAV/Server/LoginScreen]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:12:54,435 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:54,563 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:54,692 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:12:55,046 [I] [cfme] [UI-NAV/Server/LoginScreen]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 610ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:12:55,047 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:55,181 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:12:55,308 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:12:56,424 [I] [cfme] [LoginPage/username]: fill('admin') -> True (elapsed 977 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:12:57,373 [I] [cfme] [LoginPage/password]: fill('smartvm') -> True (elapsed 948 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:12:57,377 [I] [cfme] [LoginPage]: fill({'username': 'admin', 'password': 'smartvm'}) -> True (elapsed 1933 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:00,819 [I] [cfme] [LoginPage/login]: click (elapsed 3441 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:13:01,009 [I] [cfme] [UI-NAV/Server/LoggedIn]: Needed Navigation/Resetter Used/View Returned/No Wait on View (elapsed 7001ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:13:01,011 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:13:01,155 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:13:01,291 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:13:01,525 [I] [cfme] [BaseLoggedInPage/navigation]: Selecting ['Compute', 'Clouds', 'Instances'] in navigation (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:593)
>2018-08-07 10:13:08,673 [I] [cfme] [InstanceAllView/sidebar/instances]: opening (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:801)
>2018-08-07 10:13:09,878 [I] [cfme] [InstanceAllView/sidebar/instances/tree]: Expanding path All Instances on tree instances_filter_tree (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:1320)
>2018-08-07 10:13:10,130 [I] [cfme] [InstanceAllView/sidebar/instances/tree]: clicking node 'All Instances' (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:1378)
>2018-08-07 10:13:10,766 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:13:10,899 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:13:11,028 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:13:11,600 [I] [cfme] [InstanceAllView/toolbar/view_selector]: read -> u'Grid View' (elapsed 342 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:11,602 [I] [cfme] [InstanceAllView]: Picked GridView (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:2388)
>2018-08-07 10:13:11,711 [I] [cfme] [InstanceAllView/GridView/search]: is_empty -> True (elapsed 43 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:12,547 [I] [cfme] [InstanceAllView/toolbar/reload]: click (elapsed 834 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:13:12,549 [I] [cfme] [UI-NAV/InstanceCollection/All]: Needed Navigation/Resetter Used/View Returned/No Wait on View (elapsed 19215ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:13:12,550 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:13:12,670 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:13:12,796 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:13:13,134 [I] [cfme] [InstanceAllView/toolbar/lifecycle]: Selecting 'Provision Instances' (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:1607)
>2018-08-07 10:13:14,136 [I] [cfme] [InstanceAllView/toolbar/lifecycle]: Dropdown('Lifecycle') hid so it was not possible to close it. But ignoring. (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:1550)
>2018-08-07 10:13:14,137 [I] [cfme] [UI-NAV/InstanceCollection/Provision]: Needed Navigation/Resetter Used/View Returned/No Wait on View (elapsed 25053ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:13:14,606 [W] [cfme] [ProvisionView/image_table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:13:14,739 [I] [cfme] [ProvisionView/image_table[1]]: click (elapsed 207 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:13:17,389 [I] [cfme] [ProvisionView/form/continue_button]: click (elapsed 2369 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:13:20,394 [W] [cfme] [ProvisionView/form]: Extra values that have no corresponding fill fields passed: template_name, provider_name (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:772)
>2018-08-07 10:13:25,396 [I] [cfme] [ProvisionView/form/request/email]: fill('ZLLKwPZU@test.com') -> True (elapsed 4929 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:30,314 [I] [cfme] [ProvisionView/form/request/first_name]: fill('GSjZdTdEsU') -> True (elapsed 4880 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:35,209 [I] [cfme] [ProvisionView/form/request/last_name]: fill('VgdXhMroWa') -> True (elapsed 4858 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:35,279 [I] [cfme] [ProvisionView/form/request]: fill({'first_name': 'GSjZdTdEsU', 'last_name': 'VgdXhMroWa', 'email': 'ZLLKwPZU@test.com'}) -> True (elapsed 14883 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:35,343 [I] [cfme] [ProvisionView/form/catalog]: opened the tab Catalog (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:685)
>2018-08-07 10:13:42,493 [I] [cfme] [ProvisionView/form/catalog/vm_name]: fill('CTqwvjHTXO') -> True (elapsed 4854 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:42,679 [I] [cfme] [ProvisionView/form/catalog/num_vms]: fill('1') -> False (elapsed 80 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:42,875 [I] [cfme] [ProvisionView/form/catalog]: fill({'vm_name': 'CTqwvjHTXO', 'num_vms': '1'}) -> True (elapsed 7595 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:42,952 [I] [cfme] [ProvisionView/form/environment]: opened the tab Environment (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:685)
>2018-08-07 10:13:47,635 [I] [cfme] [ProvisionView/form/environment/availability_zone]: click (elapsed 2275 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:13:47,636 [I] [cfme] [ProvisionView/form/environment/availability_zone]: selecting by visible text: 'nova' (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:934)
>2018-08-07 10:13:50,080 [I] [cfme] [ProvisionView/form/environment/availability_zone]: fill('nova') -> True (elapsed 4836 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:52,502 [I] [cfme] [ProvisionView/form/environment/cloud_network]: click (elapsed 2256 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:13:52,504 [I] [cfme] [ProvisionView/form/environment/cloud_network]: selecting by visible text: 'private' (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:934)
>2018-08-07 10:13:54,921 [I] [cfme] [ProvisionView/form/environment/cloud_network]: fill('private') -> True (elapsed 4802 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:55,533 [I] [cfme] [ProvisionView/form/environment]: fill({'cloud_subnet': None, 'resource_groups': None, 'cloud_network': 'private', 'availability_zone': 'nova'}) -> True (elapsed 12658 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:13:55,610 [I] [cfme] [ProvisionView/form/properties]: opened the tab Properties (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:685)
>2018-08-07 10:14:00,320 [I] [cfme] [ProvisionView/form/properties/instance_type]: click (elapsed 2266 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:14:00,322 [I] [cfme] [ProvisionView/form/properties/instance_type]: selecting by partial visible text: 'm1.tiny' (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:920)
>2018-08-07 10:14:02,702 [I] [cfme] [ProvisionView/form/properties/instance_type]: fill(partial_match('m1.tiny')) -> True (elapsed 4776 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:14:02,844 [I] [cfme] [ProvisionView/form/properties]: fill({'instance_type': partial_match('m1.tiny'), 'guest_keypair': None}) -> True (elapsed 7309 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:14:02,848 [I] [cfme] [ProvisionView/form]: fill({'environment': {'cloud_subnet': None, 'resource_groups': None, 'cloud_network': 'private', 'availability_zone': 'nova'}, 'catalog': {'vm_name': 'CTqwvjHTXO', 'num_vms': '1'}, 'template_name': 'cirros', 'provider_name': 'oc_ci', 'request': {'first_name': 'GSjZdTdEsU', 'last_name': 'VgdXhMroWa', 'email': 'ZLLKwPZU@test.com'}, 'properties': {'instance_type': partial_match('m1.tiny'), 'guest_keypair': None}}) -> True (elapsed 48709 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:134)
>2018-08-07 10:14:08,629 [I] [cfme] [ProvisionView/form/submit_button]: click (elapsed 5780 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:14:10,673 [I] [cfme] [RequestsView/flash]: asserting there are no error messages (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic_patternfly/__init__.py:223)
>2018-08-07 10:14:10,731 [I] [cfme] Waiting for cfme provision request for vm CTqwvjHTXO (cfme/common/vm.py:527)
>2018-08-07 10:14:10,733 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:14:10,734 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:14:10,864 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:14:10,994 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:14:11,401 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 667ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:14:12,437 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 1034 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:14:12,707 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:12,746 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:12,778 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:13,061 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:13,078 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:13,191 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:13,208 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:23,223 [I] [cfme] Last Request message in UI: 'TableColumn(TableRow(Table('//div[@id="gtl_div"]//table', column_widgets={}, assoc_column=None, rows_ignore_top=None, rows_ignore_bottom=None), 1), 14)' (cfme/services/requests.py:60)
>2018-08-07 10:14:23,225 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:14:23,226 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:14:23,354 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:14:23,490 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:14:23,933 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 707ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:14:24,948 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 1012 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:14:25,258 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:25,292 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:25,327 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:25,611 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:25,628 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:25,750 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:25,767 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:35,784 [I] [cfme] Last Request message in UI: 'TableColumn(TableRow(Table('//div[@id="gtl_div"]//table', column_widgets={}, assoc_column=None, rows_ignore_top=None, rows_ignore_bottom=None), 1), 14)' (cfme/services/requests.py:60)
>2018-08-07 10:14:35,785 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:14:35,786 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:14:35,938 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:14:36,071 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:14:36,468 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 681ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:14:37,305 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 836 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:14:37,560 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:37,590 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:37,622 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:37,916 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:37,935 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:38,067 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:38,084 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:48,100 [I] [cfme] Last Request message in UI: 'TableColumn(TableRow(Table('//div[@id="gtl_div"]//table', column_widgets={}, assoc_column=None, rows_ignore_top=None, rows_ignore_bottom=None), 1), 14)' (cfme/services/requests.py:60)
>2018-08-07 10:14:48,102 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:14:48,102 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:14:48,252 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:14:48,379 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:14:48,813 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 710ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:14:49,682 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 867 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:14:50,088 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:50,117 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:50,148 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:14:50,418 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:50,436 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:50,565 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:14:50,582 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:00,606 [I] [cfme] Last Request message in UI: 'TableColumn(TableRow(Table('//div[@id="gtl_div"]//table', column_widgets={}, assoc_column=None, rows_ignore_top=None, rows_ignore_bottom=None), 1), 14)' (cfme/services/requests.py:60)
>2018-08-07 10:15:00,608 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:00,609 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:00,752 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:00,880 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:15:01,234 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 625ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:02,103 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 867 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:15:02,349 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:02,383 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:02,414 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:02,660 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:02,676 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:02,781 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:02,796 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:02,905 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:02,921 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:12,944 [I] [cfme] Last Request message in UI: 'TableColumn(TableRow(Table('//div[@id="gtl_div"]//table', column_widgets={}, assoc_column=None, rows_ignore_top=None, rows_ignore_bottom=None), 1), 14)' (cfme/services/requests.py:60)
>2018-08-07 10:15:12,946 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:12,948 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:13,093 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:13,220 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:15:13,776 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 828ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:14,548 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 770 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:15:14,843 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:14,879 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:14,913 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:15,177 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:15,192 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:15,300 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:15,316 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:15,416 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:15,433 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:25,448 [I] [cfme] Last Request message in UI: 'TableColumn(TableRow(Table('//div[@id="gtl_div"]//table', column_widgets={}, assoc_column=None, rows_ignore_top=None, rows_ignore_bottom=None), 1), 14)' (cfme/services/requests.py:60)
>2018-08-07 10:15:25,450 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:25,450 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:25,587 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:25,718 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:15:26,115 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 664ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:26,969 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 852 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:15:27,306 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:27,336 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:27,368 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:27,657 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:27,673 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:27,782 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:27,798 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:27,902 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:27,919 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:37,940 [I] [cfme] Last Request message in UI: 'TableColumn(TableRow(Table('//div[@id="gtl_div"]//table', column_widgets={}, assoc_column=None, rows_ignore_top=None, rows_ignore_bottom=None), 1), 14)' (cfme/services/requests.py:60)
>2018-08-07 10:15:37,942 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:37,942 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:38,120 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:38,250 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:15:38,693 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 750ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:39,503 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 808 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:15:39,779 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:39,809 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:39,840 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:40,126 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:40,144 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:40,276 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:40,294 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:40,406 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:40,424 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:50,439 [I] [cfme] Last Request message in UI: 'TableColumn(TableRow(Table('//div[@id="gtl_div"]//table', column_widgets={}, assoc_column=None, rows_ignore_top=None, rows_ignore_bottom=None), 1), 14)' (cfme/services/requests.py:60)
>2018-08-07 10:15:50,441 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:50,442 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:50,584 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:15:50,720 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:15:51,418 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 976ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:15:52,404 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 984 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:15:52,682 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:52,719 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:52,750 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:15:53,017 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:53,032 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:53,145 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:53,167 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:53,275 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:15:53,290 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:03,314 [I] [cfme] Last Request message in UI: 'TableColumn(TableRow(Table('//div[@id="gtl_div"]//table', column_widgets={}, assoc_column=None, rows_ignore_top=None, rows_ignore_bottom=None), 1), 14)' (cfme/services/requests.py:60)
>2018-08-07 10:16:03,315 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:16:03,316 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:16:03,448 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:16:03,578 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:16:04,011 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 695ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:16:04,823 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 810 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:16:05,072 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:16:05,099 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:16:05,126 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:16:05,389 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:05,406 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:05,534 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:05,550 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:05,659 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:05,677 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:05,691 [I] [cfme] [UI-NAV/RequestCollection/All]: Beginning Navigation... (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:16:05,692 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers {'filter[]': [u'is_master = True']} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:16:05,825 [I] [cfme] (rest-api) [RESTAPI] GET https://10.0.0.90/api/servers/1000000000001 {} (/root/cfme/cfme_venv/lib/python2.7/site-packages/manageiq_client/api.py:109)
>2018-08-07 10:16:05,958 [I] [cfme] USING UI ADDRESS (cfme/base/ui.py:37)
>2018-08-07 10:16:06,317 [I] [cfme] [UI-NAV/RequestCollection/All]: Already Here/Resetter Used/View Returned/No Wait on View (elapsed 624ms) (cfme/utils/appliance/implementations/ui.py:519)
>2018-08-07 10:16:07,052 [I] [cfme] [RequestsView/toolbar/reload]: click (elapsed 734 ms) (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/log.py:136)
>2018-08-07 10:16:07,312 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:16:07,340 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_pages_amount", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:16:07,368 [I] [cfme] [RequestsView/paginator]: executed command: sendDataWithRx({"action": "get_current_page", "controller": "reportDataController"}); return ManageIQ.qe.gtl.result (widgetastic_manageiq/__init__.py:1393)
>2018-08-07 10:16:07,656 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:07,677 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:07,823 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:07,847 [W] [cfme] [RequestsView/table[1][u'Request State']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:07,973 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:07,989 [W] [cfme] [RequestsView/table[1][u'Status']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:08,105 [W] [cfme] [RequestsView/table[1]]: __locator__ of TableRow class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:08,123 [W] [cfme] [RequestsView/table[1][u'Last Message']]: __locator__ of TableColumn class returns a WebElement! (/root/cfme/cfme_venv/lib/python2.7/site-packages/widgetastic/widget.py:350)
>2018-08-07 10:16:08,247 [E] [cfme] @pytest.fixture(scope='function')
>    def new_instance(provider):
>        prov_data = provider.data['provisioning']
>        prov_form_data = {
>            'request': {'email': fauxfactory.gen_email(),
>                        'first_name': fauxfactory.gen_alpha(),
>                        'last_name': fauxfactory.gen_alpha()},
>            'catalog': {'num_vms': '1',
>                        'vm_name': fauxfactory.gen_alpha()},
>            'environment': {'cloud_network': prov_data['cloud_network']},
>            'properties': {'instance_type': partial_match(prov_data['instance_type'])},
>        }
>    
>        instance_name = prov_form_data['catalog']['vm_name']
>    
>        try:
>            instance = provider.appliance.collections.cloud_instances.create(
>                instance_name,
>                provider,
>>               prov_form_data, find_in_cfme=True
>            )
>
>cfme/tests/openstack/cloud/test_instances.py:43: 
>_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
>
>    def create(self, vm_name, provider, form_values=None, cancel=False, check_existing=False,
>               find_in_cfme=False, wait=True, request_description=None, auto_approve=False,
>               override=False):
>        """Provisions an vm/instance with the given properties through CFME
>    
>            Args:
>                vm_name: the vm/instance's name
>                provider: provider object
>                form_values: dictionary of form values for provisioning, structured into tabs
>                cancel: boolean, whether or not to cancel form filling
>                check_existing: verify if such vm_name exists
>                find_in_cfme: verify that vm was created and appeared in CFME
>                wait: wait for vm provision request end
>                request_description: request description that test needs to search in request table.
>                auto_approve: if true the request is approved before waiting for completion.
>                override: To override any failure related exception
>    
>            Note:
>                Calling create on a sub-class of instance will generate the properly formatted
>                dictionary when the correct fields are supplied.
>            """
>        vm = self.instantiate(vm_name, provider)
>        if check_existing and vm.exists:
>            return vm
>        if not provider.is_refreshed():
>            provider.refresh_provider_relationships()
>            wait_for(provider.is_refreshed, func_kwargs={'refresh_delta': 10}, timeout=600)
>        if not form_values:
>            form_values = vm.vm_default_args
>        else:
>            inst_args = vm.vm_default_args
>            form_values = recursive_update(inst_args, form_values)
>        env = form_values.get('environment') or {}
>        if env.get('automatic_placement'):
>            form_values['environment'] = {'automatic_placement': True}
>        form_values.update({'provider_name': provider.name})
>        if not form_values.get('template_name'):
>            template_name = (provider.data.get('provisioning').get('image', {}).get('name') or
>                             provider.data.get('provisioning').get('template'))
>            vm.template_name = template_name
>            form_values.update({'template_name': template_name})
>        view = navigate_to(self, 'Provision')
>        view.form.fill(form_values)
>    
>        if cancel:
>            view.form.cancel_button.click()
>            view = self.browser.create_view(BaseLoggedInPage)
>            view.flash.assert_success_message(self.ENTITY.PROVISION_CANCEL)
>            view.flash.assert_no_error()
>        else:
>            view.form.submit_button.click()
>    
>            view = vm.appliance.browser.create_view(RequestsView)
>            if not BZ(1608967, forced_streams=['5.10']).blocks:
>                wait_for(lambda: view.flash.messages, fail_condition=[], timeout=10, delay=2,
>                        message='wait for Flash Success')
>            # This flash message is not flashed in 5.10.
>            if self.appliance.version < 5.10:
>                wait_for(lambda: view.flash.messages, fail_condition=[], timeout=10, delay=2,
>                         message='wait for Flash Success')
>            view.flash.assert_no_error()
>            if wait:
>                if request_description is None:
>                    request_description = 'Provision from [{}] to [{}]'.format(
>                        form_values.get('template_name'), vm.name)
>                provision_request = vm.appliance.collections.requests.instantiate(
>                    request_description)
>                logger.info('Waiting for cfme provision request for vm %s', vm.name)
>                if auto_approve:
>                    provision_request.approve_request(method='ui', reason="Approved")
>                provision_request.wait_for_request(method='ui', num_sec=900)
>                if provision_request.is_succeeded(method='ui'):
>                    logger.info('Waiting for vm %s to appear on provider %s', vm.name,
>                                provider.key)
>                    wait_for(provider.mgmt.does_vm_exist, [vm.name],
>                             handle_exception=True, num_sec=600)
>                elif override:
>                    logger.info('Overriding exception to check failure condition.')
>                else:
>                    raise Exception(
>                        "Provisioning vm {} failed with: {}"
>>                       .format(vm.name, provision_request.row.last_message.text)
>                    )
>E                   Exception: Provisioning vm CTqwvjHTXO failed with: [EVM] VM [CTqwvjHTXO] Step [CheckProvisioned] Status [Error Creating VM] Message [[MiqException::MiqProvisionError]: An error occurred while provisioning Instance CTqwvjHTXO: undefined method `name' for nil:NilClass]
>
>cfme/common/vm.py:541: Exception (cfme/fixtures/log.py:83)
>2018-08-07 10:16:08,715 [I] [cfme] --------------- test_create_instance[openstack-11] result: error --------------- (cfme/fixtures/log.py:70)
>2018-08-07 10:16:08,831 [I] [cfme] ============================== Finished test run =============================== (cfme/fixtures/log.py:95)
>2018-08-07 10:16:08,850 [I] [cfme] ============================== total: 1, error: 1 ============================== (cfme/fixtures/log.py:96)
>2018-08-07 10:16:08,877 [I] [cfme] Popped appliance empty from the stack (now there is empty) (cfme/utils/appliance/__init__.py:2911)

Actions: View

Attachments on bug 1610736: 1472053 | 1472054 | 1472056 | 1473946