2019-03-09 05:14:43,361 [salt.utils.decorators:613 ][WARNING ][2083] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:14:43,924 [salt.utils.decorators:613 ][WARNING ][2083] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:14:45,850 [salt.loaded.int.states.file:2298][WARNING ][2466] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-03-09 05:15:15,550 [salt.state       :2022][WARNING ][3187] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-03-09 05:15:18,102 [salt.utils.decorators:613 ][WARNING ][3187] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:17:39,462 [salt.utils.decorators:613 ][WARNING ][3187] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:33:37,027 [salt.utils.decorators:613 ][WARNING ][3187] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:48:40,353 [salt.utils.decorators:613 ][WARNING ][3187] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:48:48,973 [salt.loaded.ext.module.maas:160 ][ERROR   ][3187] Failed for object commissioning_distro_series reason {"commissioning_distro_series": ["'xenial' is not a valid commissioning_distro_series.  It should be one of: '---'."]}
2019-03-09 05:48:49,027 [salt.loaded.ext.module.maas:160 ][ERROR   ][3187] Failed for object default_osystem reason {"default_osystem": ["'ubuntu' is not a valid osystem.  It should be one of: '---'."]}
2019-03-09 05:48:49,493 [salt.loaded.ext.module.maas:160 ][ERROR   ][3187] Failed for object default_distro_series reason {"default_distro_series": ["'xenial' is not a valid release.  It should be one of: '---'."]}
2019-03-09 05:48:49,557 [salt.loaded.ext.module.maas:160 ][ERROR   ][3187] Failed for object default_min_hwe_kernel reason {"default_min_hwe_kernel": ["'hwe-16.04' is not a valid default_min_hwe_kernel.  It should be one of: ''."]}
2019-03-09 05:48:49,558 [salt.state       :302 ][ERROR   ][3187] Module function maas.process_maas_config threw an exception. Exception: {'updated': [], 'errors': {'commissioning_distro_series': '{"commissioning_distro_series": ["\'xenial\' is not a valid commissioning_distro_series.  It should be one of: \'---\'."]}', 'default_osystem': '{"default_osystem": ["\'ubuntu\' is not a valid osystem.  It should be one of: \'---\'."]}', 'default_distro_series': '{"default_distro_series": ["\'xenial\' is not a valid release.  It should be one of: \'---\'."]}', 'default_min_hwe_kernel': '{"default_min_hwe_kernel": ["\'hwe-16.04\' is not a valid default_min_hwe_kernel.  It should be one of: \'\'."]}'}, 'success': ['enable_http_proxy', 'upstream_dns', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase']}
2019-03-09 05:48:49,711 [salt.loaded.ext.module.maasng:1008][WARNING ][3187] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-03-09 05:48:49,711 [salt.loaded.ext.module.maasng:1011][WARNING ][3187] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-03-09 05:48:50,435 [salt.loaded.ext.module.maasng:1235][WARNING ][3187] Ignoring parameter vlan:0
2019-03-09 05:48:51,300 [salt.utils.decorators:613 ][WARNING ][3187] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:48:53,606 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25482] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-03-09 05:48:53,638 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25482] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-03-09 05:48:53,661 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-03-09 05:48:54,737 [salt.cli.daemons :293 ][INFO    ][25546] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-03-09 05:48:54,836 [salt.cli.daemons :82  ][INFO    ][25546] Starting up the Salt Minion
2019-03-09 05:48:54,836 [salt.utils.event :1017][INFO    ][25546] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-03-09 05:48:55,742 [salt.minion      :976 ][INFO    ][25546] Creating minion process manager
2019-03-09 05:48:57,174 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][25546] Executing command ['date', '+%z'] in directory '/root'
2019-03-09 05:48:57,195 [salt.utils.schedule:568 ][INFO    ][25546] Updating job settings for scheduled job: __mine_interval
2019-03-09 05:48:57,197 [salt.minion      :1108][INFO    ][25546] Added mine.update to scheduler
2019-03-09 05:48:57,202 [salt.minion      :1975][INFO    ][25546] Minion is starting as user 'root'
2019-03-09 05:48:57,217 [salt.minion      :2336][INFO    ][25546] Minion is ready to receive requests!
2019-03-09 05:49:01,999 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command state.apply with jid 20190309054901985760
2019-03-09 05:49:02,021 [salt.minion      :1432][INFO    ][25627] Starting a new job with PID 25627
2019-03-09 05:49:05,702 [salt.state       :915 ][INFO    ][25627] Loading fresh modules for state activity
2019-03-09 05:49:06,427 [salt.state       :1780][INFO    ][25627] Running state [maas-region-controller] at time 05:49:06.426938
2019-03-09 05:49:06,427 [salt.state       :1813][INFO    ][25627] Executing state pkg.installed for [maas-region-controller]
2019-03-09 05:49:06,427 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-03-09 05:49:06,517 [salt.state       :300 ][INFO    ][25627] All specified packages are already installed
2019-03-09 05:49:06,518 [salt.state       :1951][INFO    ][25627] Completed state [maas-region-controller] at time 05:49:06.518279 duration_in_ms=91.341
2019-03-09 05:49:06,518 [salt.state       :1780][INFO    ][25627] Running state [python-oauth] at time 05:49:06.518641
2019-03-09 05:49:06,518 [salt.state       :1813][INFO    ][25627] Executing state pkg.installed for [python-oauth]
2019-03-09 05:49:06,527 [salt.state       :300 ][INFO    ][25627] All specified packages are already installed
2019-03-09 05:49:06,527 [salt.state       :1951][INFO    ][25627] Completed state [python-oauth] at time 05:49:06.527587 duration_in_ms=8.945
2019-03-09 05:49:06,530 [salt.state       :1780][INFO    ][25627] Running state [/etc/maas/regiond.conf] at time 05:49:06.530756
2019-03-09 05:49:06,531 [salt.state       :1813][INFO    ][25627] Executing state file.replace for [/etc/maas/regiond.conf]
2019-03-09 05:49:06,535 [salt.state       :300 ][INFO    ][25627] No changes needed to be made
2019-03-09 05:49:06,535 [salt.state       :1951][INFO    ][25627] Completed state [/etc/maas/regiond.conf] at time 05:49:06.535661 duration_in_ms=4.905
2019-03-09 05:49:06,536 [salt.state       :1780][INFO    ][25627] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:49:06.536078
2019-03-09 05:49:06,536 [salt.state       :1813][INFO    ][25627] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-03-09 05:49:06,579 [salt.state       :300 ][INFO    ][25627] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-03-09 05:49:06,579 [salt.state       :1951][INFO    ][25627] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 05:49:06.579694 duration_in_ms=43.616
2019-03-09 05:49:06,580 [salt.state       :1780][INFO    ][25627] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:49:06.580116
2019-03-09 05:49:06,580 [salt.state       :1813][INFO    ][25627] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-03-09 05:49:06,583 [salt.state       :300 ][INFO    ][25627] No changes needed to be made
2019-03-09 05:49:06,583 [salt.state       :1951][INFO    ][25627] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:49:06.583598 duration_in_ms=3.482
2019-03-09 05:49:06,584 [salt.state       :1780][INFO    ][25627] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:49:06.583993
2019-03-09 05:49:06,584 [salt.state       :1813][INFO    ][25627] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-03-09 05:49:06,647 [salt.state       :300 ][INFO    ][25627] No changes needed to be made
2019-03-09 05:49:06,648 [salt.state       :1951][INFO    ][25627] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 05:49:06.647941 duration_in_ms=63.947
2019-03-09 05:49:06,648 [salt.state       :1780][INFO    ][25627] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:49:06.648699
2019-03-09 05:49:06,649 [salt.state       :1813][INFO    ][25627] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-03-09 05:49:06,687 [salt.state       :300 ][INFO    ][25627] No changes needed to be made
2019-03-09 05:49:06,688 [salt.state       :1951][INFO    ][25627] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 05:49:06.688767 duration_in_ms=40.067
2019-03-09 05:49:06,689 [salt.state       :1780][INFO    ][25627] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:49:06.689820
2019-03-09 05:49:06,690 [salt.state       :1813][INFO    ][25627] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-03-09 05:49:06,706 [salt.state       :300 ][INFO    ][25627] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-03-09 05:49:06,707 [salt.state       :1951][INFO    ][25627] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 05:49:06.707143 duration_in_ms=17.323
2019-03-09 05:49:06,709 [salt.state       :1780][INFO    ][25627] Running state [a2enmod headers] at time 05:49:06.709737
2019-03-09 05:49:06,710 [salt.state       :1813][INFO    ][25627] Executing state cmd.run for [a2enmod headers]
2019-03-09 05:49:06,710 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command 'a2enmod headers' in directory '/root'
2019-03-09 05:49:06,776 [salt.state       :300 ][INFO    ][25627] {'pid': 25646, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-03-09 05:49:06,777 [salt.state       :1951][INFO    ][25627] Completed state [a2enmod headers] at time 05:49:06.776968 duration_in_ms=67.23
2019-03-09 05:49:06,777 [salt.state       :1780][INFO    ][25627] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:49:06.777623
2019-03-09 05:49:06,778 [salt.state       :1813][INFO    ][25627] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-03-09 05:49:06,798 [salt.state       :300 ][INFO    ][25627] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-03-09 05:49:06,798 [salt.state       :1951][INFO    ][25627] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 05:49:06.798450 duration_in_ms=20.824
2019-03-09 05:49:06,799 [salt.state       :1780][INFO    ][25627] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:49:06.799418
2019-03-09 05:49:06,799 [salt.state       :1813][INFO    ][25627] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-03-09 05:49:06,860 [salt.state       :300 ][INFO    ][25627] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-03-09 05:49:06,861 [salt.state       :1951][INFO    ][25627] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 05:49:06.861176 duration_in_ms=61.758
2019-03-09 05:49:06,861 [salt.state       :1780][INFO    ][25627] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:49:06.861932
2019-03-09 05:49:06,862 [salt.state       :1813][INFO    ][25627] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-03-09 05:49:06,919 [salt.state       :300 ][INFO    ][25627] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-03-09 05:49:06,919 [salt.state       :1951][INFO    ][25627] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 05:49:06.919351 duration_in_ms=57.42
2019-03-09 05:49:06,920 [salt.state       :1780][INFO    ][25627] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:49:06.920046
2019-03-09 05:49:06,920 [salt.state       :1813][INFO    ][25627] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-03-09 05:49:06,980 [salt.state       :300 ][INFO    ][25627] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-03-09 05:49:06,980 [salt.state       :1951][INFO    ][25627] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 05:49:06.980877 duration_in_ms=60.831
2019-03-09 05:49:06,981 [salt.state       :1780][INFO    ][25627] Running state [/root/.pgpass] at time 05:49:06.981242
2019-03-09 05:49:06,981 [salt.state       :1813][INFO    ][25627] Executing state file.managed for [/root/.pgpass]
2019-03-09 05:49:07,022 [salt.state       :300 ][INFO    ][25627] File /root/.pgpass is in the correct state
2019-03-09 05:49:07,022 [salt.state       :1951][INFO    ][25627] Completed state [/root/.pgpass] at time 05:49:07.022247 duration_in_ms=41.005
2019-03-09 05:49:07,028 [salt.state       :1780][INFO    ][25627] Running state [maas-region syncdb --noinput] at time 05:49:07.028014
2019-03-09 05:49:07,028 [salt.state       :1813][INFO    ][25627] Executing state cmd.run for [maas-region syncdb --noinput]
2019-03-09 05:49:07,029 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-03-09 05:49:09,048 [salt.state       :300 ][INFO    ][25627] {'pid': 25659, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: auth, sessions, sites, contenttypes, maasserver, metadataserver, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-03-09 05:49:09,049 [salt.state       :1951][INFO    ][25627] Completed state [maas-region syncdb --noinput] at time 05:49:09.049353 duration_in_ms=2021.338
2019-03-09 05:49:09,049 [salt.state       :2022][WARNING ][25627] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-03-09 05:49:09,052 [salt.state       :1780][INFO    ][25627] Running state [maas-regiond] at time 05:49:09.052673
2019-03-09 05:49:09,053 [salt.state       :1813][INFO    ][25627] Executing state service.running for [maas-regiond]
2019-03-09 05:49:09,054 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-03-09 05:49:09,094 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-03-09 05:49:09,114 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-03-09 05:49:09,136 [salt.state       :300 ][INFO    ][25627] The service maas-regiond is already running
2019-03-09 05:49:09,137 [salt.state       :1951][INFO    ][25627] Completed state [maas-regiond] at time 05:49:09.137602 duration_in_ms=84.928
2019-03-09 05:49:09,140 [salt.state       :1780][INFO    ][25627] Running state [bind9] at time 05:49:09.140451
2019-03-09 05:49:09,141 [salt.state       :1813][INFO    ][25627] Executing state service.running for [bind9]
2019-03-09 05:49:09,142 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-03-09 05:49:09,167 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-03-09 05:49:09,187 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-03-09 05:49:09,204 [salt.state       :300 ][INFO    ][25627] The service bind9 is already running
2019-03-09 05:49:09,205 [salt.state       :1951][INFO    ][25627] Completed state [bind9] at time 05:49:09.205039 duration_in_ms=64.588
2019-03-09 05:49:09,207 [salt.state       :1780][INFO    ][25627] Running state [apache2] at time 05:49:09.207245
2019-03-09 05:49:09,207 [salt.state       :1813][INFO    ][25627] Executing state service.running for [apache2]
2019-03-09 05:49:09,208 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-03-09 05:49:09,224 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-03-09 05:49:09,238 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-03-09 05:49:09,257 [salt.state       :300 ][INFO    ][25627] The service apache2 is already running
2019-03-09 05:49:09,257 [salt.state       :1951][INFO    ][25627] Completed state [apache2] at time 05:49:09.257653 duration_in_ms=50.407
2019-03-09 05:49:09,260 [salt.state       :1780][INFO    ][25627] Running state [maasng.wait_for_http_code] at time 05:49:09.260282
2019-03-09 05:49:09,260 [salt.state       :1813][INFO    ][25627] Executing state module.run for [maasng.wait_for_http_code]
2019-03-09 05:49:09,261 [salt.utils.decorators:613 ][WARNING ][25627] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:49:09,384 [salt.state       :300 ][INFO    ][25627] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-03-09 05:49:09,385 [salt.state       :1951][INFO    ][25627] Completed state [maasng.wait_for_http_code] at time 05:49:09.385279 duration_in_ms=124.996
2019-03-09 05:49:09,386 [salt.state       :1780][INFO    ][25627] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:49:09.386458
2019-03-09 05:49:09,386 [salt.state       :1813][INFO    ][25627] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-03-09 05:49:09,387 [salt.state       :300 ][INFO    ][25627] /var/lib/maas/.setup_admin exists
2019-03-09 05:49:09,387 [salt.state       :1951][INFO    ][25627] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 05:49:09.387868 duration_in_ms=1.41
2019-03-09 05:49:09,388 [salt.state       :1780][INFO    ][25627] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:49:09.388836
2019-03-09 05:49:09,389 [salt.state       :1813][INFO    ][25627] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-09 05:49:09,390 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25627] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-09 05:49:10,822 [salt.state       :300 ][INFO    ][25627] {'pid': 25693, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-09 05:49:10,822 [salt.state       :1951][INFO    ][25627] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:49:10.822902 duration_in_ms=1434.067
2019-03-09 05:49:10,826 [salt.state       :1780][INFO    ][25627] Running state [maas_region_boot_source_resources_mirror] at time 05:49:10.826238
2019-03-09 05:49:10,826 [salt.state       :1813][INFO    ][25627] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-03-09 05:49:10,926 [salt.state       :300 ][INFO    ][25627] {'changes': {}}
2019-03-09 05:49:10,927 [salt.state       :1951][INFO    ][25627] Completed state [maas_region_boot_source_resources_mirror] at time 05:49:10.927225 duration_in_ms=100.986
2019-03-09 05:49:10,928 [salt.state       :1780][INFO    ][25627] Running state [maasng.boot_resources_import] at time 05:49:10.928260
2019-03-09 05:49:10,928 [salt.state       :1813][INFO    ][25627] Executing state module.run for [maasng.boot_resources_import]
2019-03-09 05:49:10,929 [salt.utils.decorators:613 ][WARNING ][25627] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:49:11,041 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-03-09 05:49:16,107 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-03-09 05:49:17,102 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309054917088955
2019-03-09 05:49:17,123 [salt.minion      :1432][INFO    ][25706] Starting a new job with PID 25706
2019-03-09 05:49:17,146 [salt.minion      :1711][INFO    ][25706] Returning information for job: 20190309054917088955
2019-03-09 05:49:21,164 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-03-09 05:49:26,237 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:885.0/900s
2019-03-09 05:49:31,308 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:880.0/900s
2019-03-09 05:49:36,379 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:875.0/900s
2019-03-09 05:49:41,439 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:870.0/900s
2019-03-09 05:49:46,493 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:864.0/900s
2019-03-09 05:49:47,157 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309054947144081
2019-03-09 05:49:47,177 [salt.minion      :1432][INFO    ][25750] Starting a new job with PID 25750
2019-03-09 05:49:47,199 [salt.minion      :1711][INFO    ][25750] Returning information for job: 20190309054947144081
2019-03-09 05:49:51,553 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:859.0/900s
2019-03-09 05:49:56,613 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:854.0/900s
2019-03-09 05:50:01,696 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:849.0/900s
2019-03-09 05:50:06,769 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:844.0/900s
2019-03-09 05:50:11,841 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:839.0/900s
2019-03-09 05:50:16,906 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:834.0/900s
2019-03-09 05:50:17,256 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055017243576
2019-03-09 05:50:17,278 [salt.minion      :1432][INFO    ][25799] Starting a new job with PID 25799
2019-03-09 05:50:17,302 [salt.minion      :1711][INFO    ][25799] Returning information for job: 20190309055017243576
2019-03-09 05:50:21,967 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:829.0/900s
2019-03-09 05:50:27,038 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:824.0/900s
2019-03-09 05:50:32,104 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:819.0/900s
2019-03-09 05:50:37,168 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:814.0/900s
2019-03-09 05:50:42,228 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:809.0/900s
2019-03-09 05:50:47,282 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:804.0/900s
2019-03-09 05:50:47,296 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055047286427
2019-03-09 05:50:47,313 [salt.minion      :1432][INFO    ][25848] Starting a new job with PID 25848
2019-03-09 05:50:47,335 [salt.minion      :1711][INFO    ][25848] Returning information for job: 20190309055047286427
2019-03-09 05:50:52,348 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:799.0/900s
2019-03-09 05:50:57,407 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:794.0/900s
2019-03-09 05:51:02,474 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:789.0/900s
2019-03-09 05:51:07,533 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:783.0/900s
2019-03-09 05:51:12,599 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:778.0/900s
2019-03-09 05:51:17,332 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055117322107
2019-03-09 05:51:17,353 [salt.minion      :1432][INFO    ][25881] Starting a new job with PID 25881
2019-03-09 05:51:17,377 [salt.minion      :1711][INFO    ][25881] Returning information for job: 20190309055117322107
2019-03-09 05:51:17,659 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:773.0/900s
2019-03-09 05:51:22,725 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:768.0/900s
2019-03-09 05:51:27,791 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:763.0/900s
2019-03-09 05:51:32,857 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:758.0/900s
2019-03-09 05:51:37,948 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:753.0/900s
2019-03-09 05:51:43,011 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:748.0/900s
2019-03-09 05:51:47,380 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055147368597
2019-03-09 05:51:47,399 [salt.minion      :1432][INFO    ][25932] Starting a new job with PID 25932
2019-03-09 05:51:47,412 [salt.minion      :1711][INFO    ][25932] Returning information for job: 20190309055147368597
2019-03-09 05:51:48,077 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:743.0/900s
2019-03-09 05:51:53,143 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:738.0/900s
2019-03-09 05:51:58,203 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:733.0/900s
2019-03-09 05:52:03,286 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:728.0/900s
2019-03-09 05:52:08,353 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:723.0/900s
2019-03-09 05:52:13,413 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:718.0/900s
2019-03-09 05:52:17,416 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055217403174
2019-03-09 05:52:17,438 [salt.minion      :1432][INFO    ][25963] Starting a new job with PID 25963
2019-03-09 05:52:17,460 [salt.minion      :1711][INFO    ][25963] Returning information for job: 20190309055217403174
2019-03-09 05:52:18,474 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:713.0/900s
2019-03-09 05:52:23,533 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:707.0/900s
2019-03-09 05:52:28,593 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:702.0/900s
2019-03-09 05:52:33,659 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:697.0/900s
2019-03-09 05:52:38,719 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:692.0/900s
2019-03-09 05:52:43,778 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:687.0/900s
2019-03-09 05:52:47,468 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055247459308
2019-03-09 05:52:47,485 [salt.minion      :1432][INFO    ][26015] Starting a new job with PID 26015
2019-03-09 05:52:47,503 [salt.minion      :1711][INFO    ][26015] Returning information for job: 20190309055247459308
2019-03-09 05:52:48,832 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:682.0/900s
2019-03-09 05:52:53,898 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:677.0/900s
2019-03-09 05:52:58,963 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:672.0/900s
2019-03-09 05:53:04,030 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:667.0/900s
2019-03-09 05:53:09,104 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:662.0/900s
2019-03-09 05:53:14,164 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:657.0/900s
2019-03-09 05:53:17,515 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055317502083
2019-03-09 05:53:17,536 [salt.minion      :1432][INFO    ][26046] Starting a new job with PID 26046
2019-03-09 05:53:17,558 [salt.minion      :1711][INFO    ][26046] Returning information for job: 20190309055317502083
2019-03-09 05:53:19,230 [salt.loaded.ext.module.maasng:1600][INFO    ][25627] Waiting boot-resources import done
sleep for:5s Left:652.0/900s
2019-03-09 05:53:24,341 [salt.state       :300 ][INFO    ][25627] {'ret': True}
2019-03-09 05:53:24,341 [salt.state       :1951][INFO    ][25627] Completed state [maasng.boot_resources_import] at time 05:53:24.341406 duration_in_ms=253413.146
2019-03-09 05:53:24,342 [salt.state       :1780][INFO    ][25627] Running state [maas_region_boot_sources_selection_xenial] at time 05:53:24.342521
2019-03-09 05:53:24,343 [salt.state       :1813][INFO    ][25627] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-03-09 05:53:24,496 [salt.state       :300 ][INFO    ][25627] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-03-09 05:53:24,496 [salt.state       :1951][INFO    ][25627] Completed state [maas_region_boot_sources_selection_xenial] at time 05:53:24.496733 duration_in_ms=154.211
2019-03-09 05:53:24,498 [salt.state       :1780][INFO    ][25627] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 05:53:24.498219
2019-03-09 05:53:24,498 [salt.state       :1813][INFO    ][25627] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-03-09 05:53:24,499 [salt.utils.decorators:613 ][WARNING ][25627] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:53:24,499 [salt.loaded.ext.module.maasng:1771][INFO    ][25627] boot-sources sync initiated for ALL Rack's
2019-03-09 05:53:24,837 [salt.loaded.ext.module.maasng:1878][INFO    ][25627] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:900.0/900s
2019-03-09 05:53:30,082 [salt.loaded.ext.module.maasng:1878][INFO    ][25627] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:895.0/900s
2019-03-09 05:53:35,310 [salt.loaded.ext.module.maasng:1878][INFO    ][25627] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:889.0/900s
2019-03-09 05:53:41,190 [salt.state       :300 ][INFO    ][25627] {'ret': True}
2019-03-09 05:53:41,191 [salt.state       :1951][INFO    ][25627] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 05:53:41.191541 duration_in_ms=16693.319
2019-03-09 05:53:41,194 [salt.state       :1780][INFO    ][25627] Running state [maas.process_maas_config] at time 05:53:41.194164
2019-03-09 05:53:41,194 [salt.state       :1813][INFO    ][25627] Executing state module.run for [maas.process_maas_config]
2019-03-09 05:53:41,195 [salt.utils.decorators:613 ][WARNING ][25627] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:53:41,197 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=enable_http_proxy value=True
2019-03-09 05:53:41,259 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=upstream_dns value=8.8.8.8
2019-03-09 05:53:41,323 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=commissioning_distro_series value=xenial
2019-03-09 05:53:45,287 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=default_osystem value=ubuntu
2019-03-09 05:53:45,353 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=active_discovery_interval value=600
2019-03-09 05:53:45,415 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=dnssec_validation value=no
2019-03-09 05:53:45,473 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=maas_name value=mas01
2019-03-09 05:53:45,544 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=network_discovery value=enabled
2019-03-09 05:53:45,661 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=enable_third_party_drivers value=True
2019-03-09 05:53:45,715 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=default_storage_layout value=lvm
2019-03-09 05:53:45,763 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=ntp_external_only value=True
2019-03-09 05:53:45,812 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=disk_erase_with_secure_erase value=False
2019-03-09 05:53:45,864 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=default_distro_series value=xenial
2019-03-09 05:53:45,924 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-03-09 05:53:46,072 [salt.state       :300 ][INFO    ][25627] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-03-09 05:53:46,073 [salt.state       :1951][INFO    ][25627] Completed state [maas.process_maas_config] at time 05:53:46.073022 duration_in_ms=4878.857
2019-03-09 05:53:46,073 [salt.state       :1780][INFO    ][25627] Running state [pxe_admin] at time 05:53:46.073872
2019-03-09 05:53:46,074 [salt.state       :1813][INFO    ][25627] Executing state maasng.fabric_present for [pxe_admin]
2019-03-09 05:53:46,150 [salt.loaded.ext.module.maasng:945 ][INFO    ][25627] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'sky3dy', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-03-09 05:53:46,215 [salt.loaded.ext.module.maasng:1008][WARNING ][25627] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-03-09 05:53:46,215 [salt.loaded.ext.module.maasng:1011][WARNING ][25627] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-03-09 05:53:46,287 [salt.state       :300 ][INFO    ][25627] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-03-09 05:53:46,287 [salt.state       :1951][INFO    ][25627] Completed state [pxe_admin] at time 05:53:46.287758 duration_in_ms=213.885
2019-03-09 05:53:46,288 [salt.state       :1780][INFO    ][25627] Running state [vlan 0] at time 05:53:46.288312
2019-03-09 05:53:46,288 [salt.state       :1813][INFO    ][25627] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-03-09 05:53:46,352 [salt.loaded.ext.module.maasng:945 ][INFO    ][25627] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'sky3dy', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-03-09 05:53:46,460 [salt.loaded.ext.module.maasng:945 ][INFO    ][25627] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-09 05:53:46,727 [salt.loaded.ext.module.maasng:945 ][INFO    ][25627] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'sky3dy', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-03-09 05:53:46,822 [salt.state       :300 ][INFO    ][25627] {'new': 'Vlan untagged was updated'}
2019-03-09 05:53:46,823 [salt.state       :1951][INFO    ][25627] Completed state [vlan 0] at time 05:53:46.823251 duration_in_ms=534.94
2019-03-09 05:53:46,824 [salt.state       :1780][INFO    ][25627] Running state [192.168.11.0/24] at time 05:53:46.824266
2019-03-09 05:53:46,824 [salt.state       :1813][INFO    ][25627] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-03-09 05:53:47,011 [salt.loaded.ext.module.maasng:945 ][INFO    ][25627] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-09 05:53:47,012 [salt.loaded.ext.module.maasng:1235][WARNING ][25627] Ignoring parameter vlan:0
2019-03-09 05:53:47,090 [salt.state       :300 ][INFO    ][25627] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-03-09 05:53:47,091 [salt.state       :1951][INFO    ][25627] Completed state [192.168.11.0/24] at time 05:53:47.091012 duration_in_ms=266.745
2019-03-09 05:53:47,092 [salt.state       :1780][INFO    ][25627] Running state [maas_create_iprange_1] at time 05:53:47.092011
2019-03-09 05:53:47,092 [salt.state       :1813][INFO    ][25627] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-03-09 05:53:47,150 [salt.state       :300 ][INFO    ][25627] Iprange maas_create_iprange_1 already exist.
2019-03-09 05:53:47,151 [salt.state       :1951][INFO    ][25627] Completed state [maas_create_iprange_1] at time 05:53:47.151172 duration_in_ms=59.161
2019-03-09 05:53:47,151 [salt.state       :1780][INFO    ][25627] Running state [vlan 0] at time 05:53:47.151572
2019-03-09 05:53:47,151 [salt.state       :1813][INFO    ][25627] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-03-09 05:53:47,217 [salt.loaded.ext.module.maasng:945 ][INFO    ][25627] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'sky3dy', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-03-09 05:53:47,323 [salt.loaded.ext.module.maasng:945 ][INFO    ][25627] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-09 05:53:47,493 [salt.loaded.ext.module.maasng:945 ][INFO    ][25627] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'sky3dy', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-03-09 05:53:47,572 [salt.state       :300 ][INFO    ][25627] {'new': 'Vlan untagged was updated'}
2019-03-09 05:53:47,572 [salt.state       :1951][INFO    ][25627] Completed state [vlan 0] at time 05:53:47.572463 duration_in_ms=420.89
2019-03-09 05:53:47,573 [salt.state       :1780][INFO    ][25627] Running state [opnfv] at time 05:53:47.573201
2019-03-09 05:53:47,573 [salt.state       :1813][INFO    ][25627] Executing state maasng.sshkey_present for [opnfv]
2019-03-09 05:53:47,581 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055347569315
2019-03-09 05:53:47,599 [salt.minion      :1432][INFO    ][26331] Starting a new job with PID 26331
2019-03-09 05:53:47,613 [salt.loaded.ext.module.maasng:1903][INFO    ][25627] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-03-09 05:53:47,614 [salt.state       :300 ][INFO    ][25627] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-03-09 05:53:47,614 [salt.state       :1951][INFO    ][25627] Completed state [opnfv] at time 05:53:47.614265 duration_in_ms=41.064
2019-03-09 05:53:47,614 [salt.state       :1780][INFO    ][25627] Running state [maas.process_tags] at time 05:53:47.614845
2019-03-09 05:53:47,615 [salt.state       :1813][INFO    ][25627] Executing state module.run for [maas.process_tags]
2019-03-09 05:53:47,615 [salt.utils.decorators:613 ][WARNING ][25627] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:53:47,616 [salt.minion      :1711][INFO    ][26331] Returning information for job: 20190309055347569315
2019-03-09 05:53:47,655 [salt.loaded.ext.module.maas:92  ][INFO    ][25627] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-03-09 05:53:47,715 [salt.state       :300 ][INFO    ][25627] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-03-09 05:53:47,716 [salt.state       :1951][INFO    ][25627] Completed state [maas.process_tags] at time 05:53:47.716169 duration_in_ms=101.323
2019-03-09 05:53:47,720 [salt.minion      :1711][INFO    ][25627] Returning information for job: 20190309054901985760
2019-03-09 05:53:48,240 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command state.apply with jid 20190309055348223175
2019-03-09 05:53:48,257 [salt.minion      :1432][INFO    ][26347] Starting a new job with PID 26347
2019-03-09 05:53:51,744 [salt.state       :915 ][INFO    ][26347] Loading fresh modules for state activity
2019-03-09 05:53:51,804 [salt.fileclient  :1219][INFO    ][26347] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-03-09 05:53:51,846 [salt.state       :1780][INFO    ][26347] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:53:51.845950
2019-03-09 05:53:51,846 [salt.state       :1813][INFO    ][26347] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-09 05:53:51,848 [salt.loaded.int.module.cmdmod:395 ][INFO    ][26347] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-09 05:53:53,225 [salt.state       :300 ][INFO    ][26347] {'pid': 26370, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-09 05:53:53,226 [salt.state       :1951][INFO    ][26347] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:53:53.226281 duration_in_ms=1380.331
2019-03-09 05:53:53,228 [salt.state       :1780][INFO    ][26347] Running state [maas.process_machines] at time 05:53:53.228072
2019-03-09 05:53:53,228 [salt.state       :1813][INFO    ][26347] Executing state module.run for [maas.process_machines]
2019-03-09 05:53:53,228 [salt.utils.decorators:613 ][WARNING ][26347] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:53:53,296 [salt.loaded.ext.module.maas:412 ][WARNING ][26347] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-09 05:53:53,297 [salt.loaded.ext.module.maas:92  ][INFO    ][26347] machine hostname=cmp002 power_type=ipmi mac_addresses=00:25:b5:a0:00:6a power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-09 05:53:54,621 [salt.loaded.ext.module.maas:412 ][WARNING ][26347] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-09 05:53:54,621 [salt.loaded.ext.module.maas:92  ][INFO    ][26347] machine hostname=cmp001 power_type=ipmi mac_addresses=00:25:b5:a0:00:5a power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-09 05:53:55,896 [salt.loaded.ext.module.maas:412 ][WARNING ][26347] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-09 05:53:55,897 [salt.loaded.ext.module.maas:92  ][INFO    ][26347] machine hostname=kvm01 power_type=ipmi mac_addresses=00:25:b5:a0:00:2a power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-09 05:53:57,289 [salt.loaded.ext.module.maas:412 ][WARNING ][26347] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-09 05:53:57,290 [salt.loaded.ext.module.maas:92  ][INFO    ][26347] machine hostname=kvm03 power_type=ipmi mac_addresses=00:25:b5:a0:00:4a power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-09 05:53:58,655 [salt.loaded.ext.module.maas:412 ][WARNING ][26347] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-09 05:53:58,656 [salt.loaded.ext.module.maas:92  ][INFO    ][26347] machine hostname=kvm02 power_type=ipmi mac_addresses=00:25:b5:a0:00:3a power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-09 05:53:59,997 [salt.state       :300 ][INFO    ][26347] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-03-09 05:53:59,998 [salt.state       :1951][INFO    ][26347] Completed state [maas.process_machines] at time 05:53:59.998174 duration_in_ms=6770.1
2019-03-09 05:54:00,001 [salt.minion      :1711][INFO    ][26347] Returning information for job: 20190309055348223175
2019-03-09 05:54:31,026 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command state.apply with jid 20190309055431010750
2019-03-09 05:54:31,048 [salt.minion      :1432][INFO    ][26685] Starting a new job with PID 26685
2019-03-09 05:54:34,576 [salt.state       :915 ][INFO    ][26685] Loading fresh modules for state activity
2019-03-09 05:54:34,603 [salt.fileclient  :1219][INFO    ][26685] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-03-09 05:54:34,629 [salt.state       :1780][INFO    ][26685] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:54:34.629381
2019-03-09 05:54:34,629 [salt.state       :1813][INFO    ][26685] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-09 05:54:34,631 [salt.loaded.int.module.cmdmod:395 ][INFO    ][26685] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-09 05:54:36,099 [salt.state       :300 ][INFO    ][26685] {'pid': 26692, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-09 05:54:36,100 [salt.state       :1951][INFO    ][26685] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:54:36.100336 duration_in_ms=1470.955
2019-03-09 05:54:36,101 [salt.state       :1780][INFO    ][26685] Running state [maas.wait_for_machine_status] at time 05:54:36.101539
2019-03-09 05:54:36,101 [salt.state       :1813][INFO    ][26685] Executing state module.run for [maas.wait_for_machine_status]
2019-03-09 05:54:36,102 [salt.utils.decorators:613 ][WARNING ][26685] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:54:37,102 [salt.loaded.ext.module.maas:1023][INFO    ][26685] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.00513101s left)
2019-03-09 05:54:46,087 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055446074318
2019-03-09 05:54:46,109 [salt.minion      :1432][INFO    ][26708] Starting a new job with PID 26708
2019-03-09 05:54:46,134 [salt.minion      :1711][INFO    ][26708] Returning information for job: 20190309055446074318
2019-03-09 05:55:08,119 [salt.loaded.ext.module.maas:1023][INFO    ][26685] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1467.98784709s left)
2019-03-09 05:55:16,132 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055516119924
2019-03-09 05:55:16,154 [salt.minion      :1432][INFO    ][26759] Starting a new job with PID 26759
2019-03-09 05:55:16,179 [salt.minion      :1711][INFO    ][26759] Returning information for job: 20190309055516119924
2019-03-09 05:55:39,358 [salt.loaded.ext.module.maas:1023][INFO    ][26685] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.74819398s left)
2019-03-09 05:55:46,232 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055546220410
2019-03-09 05:55:46,251 [salt.minion      :1432][INFO    ][26926] Starting a new job with PID 26926
2019-03-09 05:55:46,274 [salt.minion      :1711][INFO    ][26926] Returning information for job: 20190309055546220410
2019-03-09 05:56:10,717 [salt.loaded.ext.module.maas:1023][INFO    ][26685] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.38995504s left)
2019-03-09 05:56:16,276 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055616263734
2019-03-09 05:56:16,299 [salt.minion      :1432][INFO    ][27064] Starting a new job with PID 27064
2019-03-09 05:56:16,322 [salt.minion      :1711][INFO    ][27064] Returning information for job: 20190309055616263734
2019-03-09 05:56:42,267 [salt.loaded.ext.module.maas:1023][INFO    ][26685] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.84003305s left)
2019-03-09 05:56:46,338 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055646325898
2019-03-09 05:56:46,361 [salt.minion      :1432][INFO    ][27473] Starting a new job with PID 27473
2019-03-09 05:56:46,385 [salt.minion      :1711][INFO    ][27473] Returning information for job: 20190309055646325898
2019-03-09 05:57:13,956 [salt.loaded.ext.module.maas:1023][INFO    ][26685] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.15025902s left)
2019-03-09 05:57:16,398 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055716384660
2019-03-09 05:57:16,421 [salt.minion      :1432][INFO    ][27686] Starting a new job with PID 27686
2019-03-09 05:57:16,444 [salt.minion      :1711][INFO    ][27686] Returning information for job: 20190309055716384660
2019-03-09 05:57:46,457 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055746448901
2019-03-09 05:57:46,474 [salt.minion      :1432][INFO    ][27998] Starting a new job with PID 27998
2019-03-09 05:57:46,492 [salt.minion      :1711][INFO    ][27998] Returning information for job: 20190309055746448901
2019-03-09 05:57:47,622 [salt.loaded.ext.module.maas:1023][INFO    ][26685] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03']
sleep for:30s Timeout:1500s (1308.48433113s left)
2019-03-09 05:58:16,508 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055816495328
2019-03-09 05:58:16,530 [salt.minion      :1432][INFO    ][28113] Starting a new job with PID 28113
2019-03-09 05:58:16,552 [salt.minion      :1711][INFO    ][28113] Returning information for job: 20190309055816495328
2019-03-09 05:58:21,140 [salt.state       :300 ][INFO    ][26685] {'ret': True}
2019-03-09 05:58:21,141 [salt.state       :1951][INFO    ][26685] Completed state [maas.wait_for_machine_status] at time 05:58:21.141044 duration_in_ms=225039.503
2019-03-09 05:58:21,144 [salt.minion      :1711][INFO    ][26685] Returning information for job: 20190309055431010750
2019-03-09 05:58:21,787 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command state.apply with jid 20190309055821774345
2019-03-09 05:58:21,809 [salt.minion      :1432][INFO    ][28182] Starting a new job with PID 28182
2019-03-09 05:58:25,228 [salt.state       :915 ][INFO    ][28182] Loading fresh modules for state activity
2019-03-09 05:58:25,256 [salt.fileclient  :1219][INFO    ][28182] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-03-09 05:58:25,311 [salt.state       :1780][INFO    ][28182] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:58:25.311491
2019-03-09 05:58:25,311 [salt.state       :1813][INFO    ][28182] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-09 05:58:25,312 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28182] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-09 05:58:26,794 [salt.state       :300 ][INFO    ][28182] {'pid': 28190, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-09 05:58:26,795 [salt.state       :1951][INFO    ][28182] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:58:26.795371 duration_in_ms=1483.879
2019-03-09 05:58:26,796 [salt.state       :1780][INFO    ][28182] Running state [maas_machines_storage_cmp002_lvm] at time 05:58:26.796827
2019-03-09 05:58:26,797 [salt.state       :1813][INFO    ][28182] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-03-09 05:58:28,115 [salt.loaded.ext.module.maasng:610 ][INFO    ][28182] y7sqce
2019-03-09 05:58:28,116 [salt.loaded.ext.module.maasng:626 ][INFO    ][28182] sda
2019-03-09 05:58:28,891 [salt.loaded.ext.module.maasng:361 ][INFO    ][28182] y7sqce
2019-03-09 05:58:29,030 [salt.loaded.ext.module.maasng:367 ][INFO    ][28182] [{u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/6/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'filesystem': None, u'name': u'sda', u'system_id': u'y7sqce', u'block_size': 4096, u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'af3ac390-de59-44f9-bce0-ef027ce3c428', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'y7sqce', u'device_id': 6, u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'af4d6422-17da-4cc5-a2d8-f1fc3c8aa5fa', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/6/partition/4', u'type': u'partition', u'id': 4, u'size': 2397992648704}], u'used_size': 2397998940160, u'id': 6, u'size': 2397998940160}, {u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/10/', u'uuid': u'591c8a32-5a02-455a-b369-8d0ff6851cde', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'033efadf-7327-4b22-abc8-1985388787a9', u'fstype': u'ext4', u'label': u'root'}, u'name': u'vgroot-lvroot', u'system_id': u'y7sqce', u'block_size': 4096, u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'partitions': [], u'used_size': 2397988454400, u'id': 10, u'size': 2397988454400}]
2019-03-09 05:58:29,030 [salt.loaded.ext.module.maasng:632 ][INFO    ][28182] vgroot
2019-03-09 05:58:29,031 [salt.loaded.ext.module.maasng:635 ][INFO    ][28182] lvroot
2019-03-09 05:58:29,031 [salt.loaded.ext.module.maasng:639 ][INFO    ][28182] 107374182400
2019-03-09 05:58:29,748 [salt.loaded.ext.module.maasng:645 ][INFO    ][28182] {u'hwe_kernel': u'', u'swap_size': None, u'ip_addresses': [u'192.168.11.42'], u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'partition_table_type': u'GPT', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 6, u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'y7sqce', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/6/', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160, u'type': u'physical', u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'45017806-fb6d-468a-a5f5-e39834cac827', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/6/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'y7sqce', u'filesystem': {u'uuid': u'40a2c383-4723-4f27-9763-6f110480f386', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 6, u'type': u'partition', u'id': 8, u'size': 2397992648704}]}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/y7sqce/', u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'y7sqce', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'owner_data': {}, u'blockdevice_set': [{u'partition_table_type': u'GPT', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 6, u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'y7sqce', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/6/', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160, u'type': u'physical', u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'45017806-fb6d-468a-a5f5-e39834cac827', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/6/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'y7sqce', u'filesystem': {u'uuid': u'40a2c383-4723-4f27-9763-6f110480f386', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 6, u'type': u'partition', u'id': 8, u'size': 2397992648704}]}, {u'partition_table_type': None, u'block_size': 4096, u'uuid': u'd11ccced-fd9b-4efa-a3dd-dba791150d56', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'id': 14, u'filesystem': {u'uuid': u'd2e50eec-a29a-4b74-ad64-674a7046e7d8', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'y7sqce', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/14/', u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'size': 107374182400, u'type': u'virtual', u'model': None, u'partitions': []}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'partition_table_type': u'GPT', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 6, u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'y7sqce', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/6/', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160, u'type': u'physical', u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'45017806-fb6d-468a-a5f5-e39834cac827', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/6/partition/8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'y7sqce', u'filesystem': {u'uuid': u'40a2c383-4723-4f27-9763-6f110480f386', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 6, u'type': u'partition', u'id': 8, u'size': 2397992648704}]}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'y7sqce', u'id': 8}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'mode': u'dhcp', u'id': 29}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'y7sqce', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/interfaces/4/'}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'mode': u'dhcp', u'id': 29}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'y7sqce', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/interfaces/4/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 31}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 17, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'y7sqce', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/interfaces/17/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 32}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 19, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'y7sqce', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/interfaces/19/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 33}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 23, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'y7sqce', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/interfaces/23/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'disable_ipv4': False, u'virtualblockdevice_set': [{u'partition_table_type': None, u'block_size': 4096, u'uuid': u'd11ccced-fd9b-4efa-a3dd-dba791150d56', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'id': 14, u'filesystem': {u'uuid': u'd2e50eec-a29a-4b74-ad64-674a7046e7d8', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'y7sqce', u'resource_uri': u'/MAAS/api/2.0/nodes/y7sqce/blockdevices/14/', u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'size': 107374182400, u'type': u'virtual', u'model': None, u'partitions': []}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-03-09 05:58:29,751 [salt.state       :300 ][INFO    ][28182] {'new': {'storage_layout': 'lvm'}}
2019-03-09 05:58:29,752 [salt.state       :1951][INFO    ][28182] Completed state [maas_machines_storage_cmp002_lvm] at time 05:58:29.752100 duration_in_ms=2955.27
2019-03-09 05:58:29,752 [salt.state       :1780][INFO    ][28182] Running state [maas_machines_storage_cmp001_lvm] at time 05:58:29.752662
2019-03-09 05:58:29,753 [salt.state       :1813][INFO    ][28182] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-03-09 05:58:31,051 [salt.loaded.ext.module.maasng:610 ][INFO    ][28182] xwh6sp
2019-03-09 05:58:31,052 [salt.loaded.ext.module.maasng:626 ][INFO    ][28182] sda
2019-03-09 05:58:31,775 [salt.loaded.ext.module.maasng:361 ][INFO    ][28182] xwh6sp
2019-03-09 05:58:31,902 [salt.loaded.ext.module.maasng:367 ][INFO    ][28182] [{u'partition_table_type': u'GPT', u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 2, u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'xwh6sp', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/2/', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160, u'type': u'physical', u'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'ed6a28c6-9555-47af-a11f-8608e305ff5e', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/2/partition/5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xwh6sp', u'filesystem': {u'uuid': u'ca57dcd2-a6be-4e94-9450-7dd665cdd389', u'fstype': u'lvm-pv', u'mount_point': None, u'mount_options': None, u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 5, u'size': 2397992648704}]}, {u'partition_table_type': None, u'block_size': 4096, u'uuid': u'87a9b584-6f09-44a7-ae8f-7922ee2925a1', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'id': 11, u'filesystem': {u'uuid': u'0214c42b-57d5-472e-8806-d13f2bf67471', u'fstype': u'ext4', u'mount_point': u'/', u'mount_options': None, u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'xwh6sp', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/11/', u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'size': 2397988454400, u'type': u'virtual', u'model': None, u'partitions': []}]
2019-03-09 05:58:31,903 [salt.loaded.ext.module.maasng:632 ][INFO    ][28182] vgroot
2019-03-09 05:58:31,903 [salt.loaded.ext.module.maasng:635 ][INFO    ][28182] lvroot
2019-03-09 05:58:31,904 [salt.loaded.ext.module.maasng:639 ][INFO    ][28182] 107374182400
2019-03-09 05:58:32,610 [salt.loaded.ext.module.maasng:645 ][INFO    ][28182] {u'hwe_kernel': u'', u'swap_size': None, u'ip_addresses': [u'192.168.11.38'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'boot_interface': {u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 35, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'id': 5, u'system_id': u'xwh6sp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/interfaces/5/'}, u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'partition_table_type': u'GPT', u'block_size': 4096, u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 2, u'name': u'sda', u'system_id': u'xwh6sp', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/2/', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'73448fbe-3824-409f-bb40-424ac0722f8c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xwh6sp', u'device_id': 2, u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'e3292438-ac2f-48ab-825d-ba5983c44241', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/2/partition/9', u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'type': u'physical', u'used_for': u'GPT partitioned with 1 partition', u'size': 2397998940160}, {u'model': None, u'partition_table_type': None, u'block_size': 4096, u'available_size': 0, u'uuid': u'd7806352-2f61-4a7c-b25a-7772543afa58', u'tags': [], u'used_size': 107374182400, u'id': 15, u'name': u'vgroot-lvroot', u'system_id': u'xwh6sp', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/15/', u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'f6b69da2-c2e2-4e76-8067-b0ab53e8f930', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'partitions': [], u'type': u'virtual', u'used_for': u'ext4 formatted filesystem mounted at /', u'size': 107374182400}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/xwh6sp/', u'disable_ipv4': False, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'xwh6sp', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'partition_table_type': u'GPT', u'block_size': 4096, u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 2, u'name': u'sda', u'system_id': u'xwh6sp', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/2/', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'73448fbe-3824-409f-bb40-424ac0722f8c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xwh6sp', u'device_id': 2, u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'e3292438-ac2f-48ab-825d-ba5983c44241', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/2/partition/9', u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'type': u'physical', u'used_for': u'GPT partitioned with 1 partition', u'size': 2397998940160}], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'xwh6sp', u'id': 9}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'model': u'UCSB-MRAID12G', u'partition_table_type': u'GPT', u'block_size': 4096, u'available_size': 0, u'uuid': None, u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 2, u'name': u'sda', u'system_id': u'xwh6sp', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/2/', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'73448fbe-3824-409f-bb40-424ac0722f8c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'xwh6sp', u'device_id': 2, u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'e3292438-ac2f-48ab-825d-ba5983c44241', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/2/partition/9', u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'type': u'physical', u'used_for': u'GPT partitioned with 1 partition', u'size': 2397998940160}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'memory_test_status_name': u'Unknown', u'virtualblockdevice_set': [{u'model': None, u'partition_table_type': None, u'block_size': 4096, u'available_size': 0, u'uuid': u'd7806352-2f61-4a7c-b25a-7772543afa58', u'tags': [], u'used_size': 107374182400, u'id': 15, u'name': u'vgroot-lvroot', u'system_id': u'xwh6sp', u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/blockdevices/15/', u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'f6b69da2-c2e2-4e76-8067-b0ab53e8f930', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'partitions': [], u'type': u'virtual', u'used_for': u'ext4 formatted filesystem mounted at /', u'size': 107374182400}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 35, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'sky3dy', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'id': 5, u'system_id': u'xwh6sp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/interfaces/5/'}, {u'discovered': None, u'name': u'enp7s0', u'links': [{u'id': 36, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'id': 14, u'system_id': u'xwh6sp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/interfaces/14/'}, {u'discovered': None, u'name': u'enp8s0', u'links': [{u'id': 37, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'id': 18, u'system_id': u'xwh6sp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/interfaces/18/'}, {u'discovered': None, u'name': u'enp9s0', u'links': [{u'id': 38, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'enabled': True, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'id': 22, u'system_id': u'xwh6sp', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/xwh6sp/interfaces/22/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'memory_test_status': -1}
2019-03-09 05:58:32,612 [salt.state       :300 ][INFO    ][28182] {'new': {'storage_layout': 'lvm'}}
2019-03-09 05:58:32,613 [salt.state       :1951][INFO    ][28182] Completed state [maas_machines_storage_cmp001_lvm] at time 05:58:32.613004 duration_in_ms=2860.341
2019-03-09 05:58:32,616 [salt.minion      :1711][INFO    ][28182] Returning information for job: 20190309055821774345
2019-03-09 05:58:33,199 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command state.apply with jid 20190309055833187073
2019-03-09 05:58:33,220 [salt.minion      :1432][INFO    ][28208] Starting a new job with PID 28208
2019-03-09 05:58:33,825 [salt.state       :915 ][INFO    ][28208] Loading fresh modules for state activity
2019-03-09 05:58:33,878 [salt.fileclient  :1219][INFO    ][28208] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-03-09 05:58:33,923 [salt.state       :1780][INFO    ][28208] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:58:33.923228
2019-03-09 05:58:33,923 [salt.state       :1813][INFO    ][28208] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-09 05:58:33,925 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28208] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-09 05:58:35,447 [salt.state       :300 ][INFO    ][28208] {'pid': 28215, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-09 05:58:35,448 [salt.state       :1951][INFO    ][28208] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:58:35.448311 duration_in_ms=1525.082
2019-03-09 05:58:35,451 [salt.state       :1780][INFO    ][28208] Running state [maas.deploy_machines] at time 05:58:35.451758
2019-03-09 05:58:35,452 [salt.state       :1813][INFO    ][28208] Executing state module.run for [maas.deploy_machines]
2019-03-09 05:58:35,453 [salt.utils.decorators:613 ][WARNING ][28208] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:58:36,174 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=y7sqce distro_series=xenial
2019-03-09 05:58:38,868 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=xwh6sp distro_series=xenial
2019-03-09 05:58:41,401 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=4fewga distro_series=xenial
2019-03-09 05:58:44,072 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=773npp distro_series=xenial
2019-03-09 05:58:46,631 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=ad7skc distro_series=xenial
2019-03-09 05:58:48,322 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055848310130
2019-03-09 05:58:48,341 [salt.minion      :1432][INFO    ][28496] Starting a new job with PID 28496
2019-03-09 05:58:48,362 [salt.minion      :1711][INFO    ][28496] Returning information for job: 20190309055848310130
2019-03-09 05:58:48,883 [salt.state       :300 ][INFO    ][28208] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-03-09 05:58:48,883 [salt.state       :1951][INFO    ][28208] Completed state [maas.deploy_machines] at time 05:58:48.883516 duration_in_ms=13431.757
2019-03-09 05:58:48,887 [salt.minion      :1711][INFO    ][28208] Returning information for job: 20190309055833187073
2019-03-09 05:58:49,537 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command state.apply with jid 20190309055849524472
2019-03-09 05:58:49,559 [salt.minion      :1432][INFO    ][28511] Starting a new job with PID 28511
2019-03-09 05:58:53,097 [salt.state       :915 ][INFO    ][28511] Loading fresh modules for state activity
2019-03-09 05:58:53,149 [salt.fileclient  :1219][INFO    ][28511] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-03-09 05:58:53,200 [salt.state       :1780][INFO    ][28511] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:58:53.200199
2019-03-09 05:58:53,200 [salt.state       :1813][INFO    ][28511] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-09 05:58:53,203 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28511] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-09 05:58:54,510 [salt.state       :300 ][INFO    ][28511] {'pid': 28523, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-09 05:58:54,511 [salt.state       :1951][INFO    ][28511] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 05:58:54.511755 duration_in_ms=1311.556
2019-03-09 05:58:54,514 [salt.state       :1780][INFO    ][28511] Running state [maas.wait_for_machine_status] at time 05:58:54.514392
2019-03-09 05:58:54,515 [salt.state       :1813][INFO    ][28511] Executing state module.run for [maas.wait_for_machine_status]
2019-03-09 05:58:54,515 [salt.utils.decorators:613 ][WARNING ][28511] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-09 05:58:58,090 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.43536997s left)
2019-03-09 05:59:04,612 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055904596990
2019-03-09 05:59:04,634 [salt.minion      :1432][INFO    ][28538] Starting a new job with PID 28538
2019-03-09 05:59:04,659 [salt.minion      :1711][INFO    ][28538] Returning information for job: 20190309055904596990
2019-03-09 05:59:31,713 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2212.81270885s left)
2019-03-09 05:59:34,669 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309055934656183
2019-03-09 05:59:34,691 [salt.minion      :1432][INFO    ][28577] Starting a new job with PID 28577
2019-03-09 05:59:34,714 [salt.minion      :1711][INFO    ][28577] Returning information for job: 20190309055934656183
2019-03-09 06:00:04,762 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060004750150
2019-03-09 06:00:04,784 [salt.minion      :1432][INFO    ][28613] Starting a new job with PID 28613
2019-03-09 06:00:04,807 [salt.minion      :1711][INFO    ][28613] Returning information for job: 20190309060004750150
2019-03-09 06:00:05,127 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.39850307s left)
2019-03-09 06:00:34,807 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060034794117
2019-03-09 06:00:34,826 [salt.minion      :1432][INFO    ][28742] Starting a new job with PID 28742
2019-03-09 06:00:34,846 [salt.minion      :1711][INFO    ][28742] Returning information for job: 20190309060034794117
2019-03-09 06:00:38,479 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.046561s left)
2019-03-09 06:01:04,851 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060104838584
2019-03-09 06:01:04,873 [salt.minion      :1432][INFO    ][28972] Starting a new job with PID 28972
2019-03-09 06:01:04,894 [salt.minion      :1711][INFO    ][28972] Returning information for job: 20190309060104838584
2019-03-09 06:01:11,845 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.68124485s left)
2019-03-09 06:01:34,903 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060134891084
2019-03-09 06:01:34,925 [salt.minion      :1432][INFO    ][29473] Starting a new job with PID 29473
2019-03-09 06:01:34,949 [salt.minion      :1711][INFO    ][29473] Returning information for job: 20190309060134891084
2019-03-09 06:01:44,250 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2080.27550292s left)
2019-03-09 06:02:04,961 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060204947753
2019-03-09 06:02:04,984 [salt.minion      :1432][INFO    ][29673] Starting a new job with PID 29673
2019-03-09 06:02:05,006 [salt.minion      :1711][INFO    ][29673] Returning information for job: 20190309060204947753
2019-03-09 06:02:17,685 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.84063697s left)
2019-03-09 06:02:35,021 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060235006204
2019-03-09 06:02:35,045 [salt.minion      :1432][INFO    ][29861] Starting a new job with PID 29861
2019-03-09 06:02:35,068 [salt.minion      :1711][INFO    ][29861] Returning information for job: 20190309060235006204
2019-03-09 06:02:51,368 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.15762496s left)
2019-03-09 06:03:05,096 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060305084010
2019-03-09 06:03:05,119 [salt.minion      :1432][INFO    ][29930] Starting a new job with PID 29930
2019-03-09 06:03:05,142 [salt.minion      :1711][INFO    ][29930] Returning information for job: 20190309060305084010
2019-03-09 06:03:24,890 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.635921s left)
2019-03-09 06:03:35,165 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060335153240
2019-03-09 06:03:35,187 [salt.minion      :1432][INFO    ][30138] Starting a new job with PID 30138
2019-03-09 06:03:35,210 [salt.minion      :1711][INFO    ][30138] Returning information for job: 20190309060335153240
2019-03-09 06:03:58,559 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1945.96684504s left)
2019-03-09 06:04:05,238 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060405225556
2019-03-09 06:04:05,260 [salt.minion      :1432][INFO    ][30255] Starting a new job with PID 30255
2019-03-09 06:04:05,284 [salt.minion      :1711][INFO    ][30255] Returning information for job: 20190309060405225556
2019-03-09 06:04:32,322 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1912.20370197s left)
2019-03-09 06:04:35,316 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060435304191
2019-03-09 06:04:35,336 [salt.minion      :1432][INFO    ][30545] Starting a new job with PID 30545
2019-03-09 06:04:35,359 [salt.minion      :1711][INFO    ][30545] Returning information for job: 20190309060435304191
2019-03-09 06:05:05,396 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060505383234
2019-03-09 06:05:05,416 [salt.minion      :1432][INFO    ][30635] Starting a new job with PID 30635
2019-03-09 06:05:05,438 [salt.minion      :1711][INFO    ][30635] Returning information for job: 20190309060505383234
2019-03-09 06:05:05,923 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1878.60280585s left)
2019-03-09 06:05:35,478 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060535465748
2019-03-09 06:05:35,499 [salt.minion      :1432][INFO    ][30689] Starting a new job with PID 30689
2019-03-09 06:05:35,522 [salt.minion      :1711][INFO    ][30689] Returning information for job: 20190309060535465748
2019-03-09 06:05:38,777 [salt.loaded.ext.module.maas:1023][INFO    ][28511] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1845.74916697s left)
2019-03-09 06:06:05,506 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command saltutil.find_job with jid 20190309060605498891
2019-03-09 06:06:05,522 [salt.minion      :1432][INFO    ][30898] Starting a new job with PID 30898
2019-03-09 06:06:05,542 [salt.minion      :1711][INFO    ][30898] Returning information for job: 20190309060605498891
2019-03-09 06:06:11,970 [salt.state       :300 ][INFO    ][28511] {'ret': True}
2019-03-09 06:06:11,971 [salt.state       :1951][INFO    ][28511] Completed state [maas.wait_for_machine_status] at time 06:06:11.971132 duration_in_ms=437456.738
2019-03-09 06:06:12,010 [salt.minion      :1711][INFO    ][28511] Returning information for job: 20190309055849524472
2019-03-09 06:48:58,219 [salt.utils.schedule:1377][INFO    ][25546] Running scheduled job: __mine_interval
2019-03-09 07:38:18,453 [salt.minion      :1308][INFO    ][25546] User sudo_ubuntu Executing command cp.push_dir with jid 20190309073818441667
2019-03-09 07:38:18,474 [salt.minion      :1432][INFO    ][5801] Starting a new job with PID 5801
