2019-05-08 07:35:25,566 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-08 07:36:15,610 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-08 07:37:05,652 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-08 07:37:55,696 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-08 07:38:45,744 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-08 07:40:56,207 [salt.utils.decorators:613 ][WARNING ][2846] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 07:40:56,782 [salt.utils.decorators:613 ][WARNING ][2846] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 07:40:58,749 [salt.loaded.int.states.file:2298][WARNING ][2985] 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-05-08 07:41:04,496 [salt.state       :2022][WARNING ][3095] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-08 07:41:07,102 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 07:56:20,084 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:26:20,892 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:41:21,208 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:47:21,657 [salt.loaded.ext.module.maas:160 ][ERROR   ][3095] Failed for object commissioning_distro_series reason Authorization Error: 'Expired timestamp: given 1557304884 and now 1557305241 has a greater difference than threshold 300'
2019-05-08 08:47:21,978 [salt.loaded.ext.module.maas:160 ][ERROR   ][3095] Failed for object default_osystem reason {"default_osystem": ["'ubuntu' is not a valid osystem.  It should be one of: '---'."]}
2019-05-08 08:47:23,620 [salt.loaded.ext.module.maas:160 ][ERROR   ][3095] Failed for object default_distro_series reason {"default_distro_series": ["'xenial' is not a valid release.  It should be one of: '---'."]}
2019-05-08 08:47:23,918 [salt.state       :302 ][ERROR   ][3095] Module function maas.process_maas_config threw an exception. Exception: {'updated': [], 'errors': {'commissioning_distro_series': "Authorization Error: 'Expired timestamp: given 1557304884 and now 1557305241 has a greater difference than threshold 300'", '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: \'---\'."]}'}, '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', 'default_min_hwe_kernel']}
2019-05-08 08:47:26,881 [salt.loaded.ext.module.maasng:1008][WARNING ][3095] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-08 08:47:26,881 [salt.loaded.ext.module.maasng:1011][WARNING ][3095] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-08 08:47:29,691 [salt.loaded.ext.module.maasng:1235][WARNING ][3095] Ignoring parameter vlan:0
2019-05-08 08:47:34,599 [salt.utils.decorators:613 ][WARNING ][3095] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:47:37,403 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25700] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-08 08:47:37,433 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25700] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-08 08:47:37,455 [salt.utils.parsers:1051][WARNING ][365] Minion received a SIGTERM. Exiting.
2019-05-08 08:47:38,490 [salt.cli.daemons :293 ][INFO    ][25765] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-05-08 08:47:38,570 [salt.cli.daemons :82  ][INFO    ][25765] Starting up the Salt Minion
2019-05-08 08:47:38,571 [salt.utils.event :1017][INFO    ][25765] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-05-08 08:47:39,459 [salt.minion      :976 ][INFO    ][25765] Creating minion process manager
2019-05-08 08:47:40,882 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][25765] Executing command ['date', '+%z'] in directory '/root'
2019-05-08 08:47:40,901 [salt.utils.schedule:568 ][INFO    ][25765] Updating job settings for scheduled job: __mine_interval
2019-05-08 08:47:40,903 [salt.minion      :1108][INFO    ][25765] Added mine.update to scheduler
2019-05-08 08:47:40,944 [salt.minion      :1975][INFO    ][25765] Minion is starting as user 'root'
2019-05-08 08:47:40,961 [salt.minion      :2336][INFO    ][25765] Minion is ready to receive requests!
2019-05-08 08:47:45,754 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508084745742096
2019-05-08 08:47:45,777 [salt.minion      :1432][INFO    ][25846] Starting a new job with PID 25846
2019-05-08 08:47:49,248 [salt.state       :915 ][INFO    ][25846] Loading fresh modules for state activity
2019-05-08 08:47:49,932 [salt.state       :1780][INFO    ][25846] Running state [maas-region-controller] at time 08:47:49.932665
2019-05-08 08:47:49,933 [salt.state       :1813][INFO    ][25846] Executing state pkg.installed for [maas-region-controller]
2019-05-08 08:47:49,933 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-08 08:47:50,024 [salt.state       :300 ][INFO    ][25846] All specified packages are already installed
2019-05-08 08:47:50,025 [salt.state       :1951][INFO    ][25846] Completed state [maas-region-controller] at time 08:47:50.025314 duration_in_ms=92.649
2019-05-08 08:47:50,025 [salt.state       :1780][INFO    ][25846] Running state [python-oauth] at time 08:47:50.025690
2019-05-08 08:47:50,026 [salt.state       :1813][INFO    ][25846] Executing state pkg.installed for [python-oauth]
2019-05-08 08:47:50,032 [salt.state       :300 ][INFO    ][25846] All specified packages are already installed
2019-05-08 08:47:50,033 [salt.state       :1951][INFO    ][25846] Completed state [python-oauth] at time 08:47:50.033014 duration_in_ms=7.324
2019-05-08 08:47:50,036 [salt.state       :1780][INFO    ][25846] Running state [/etc/maas/regiond.conf] at time 08:47:50.036247
2019-05-08 08:47:50,036 [salt.state       :1813][INFO    ][25846] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-08 08:47:50,074 [salt.state       :300 ][INFO    ][25846] No changes needed to be made
2019-05-08 08:47:50,075 [salt.state       :1951][INFO    ][25846] Completed state [/etc/maas/regiond.conf] at time 08:47:50.075252 duration_in_ms=39.005
2019-05-08 08:47:50,076 [salt.state       :1780][INFO    ][25846] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 08:47:50.076058
2019-05-08 08:47:50,076 [salt.state       :1813][INFO    ][25846] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-08 08:47:50,158 [salt.state       :300 ][INFO    ][25846] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-08 08:47:50,158 [salt.state       :1951][INFO    ][25846] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 08:47:50.158625 duration_in_ms=82.566
2019-05-08 08:47:50,159 [salt.state       :1780][INFO    ][25846] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:47:50.159267
2019-05-08 08:47:50,159 [salt.state       :1813][INFO    ][25846] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-08 08:47:50,172 [salt.state       :300 ][INFO    ][25846] No changes needed to be made
2019-05-08 08:47:50,172 [salt.state       :1951][INFO    ][25846] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:47:50.172456 duration_in_ms=13.189
2019-05-08 08:47:50,173 [salt.state       :1780][INFO    ][25846] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:47:50.173095
2019-05-08 08:47:50,173 [salt.state       :1813][INFO    ][25846] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-08 08:47:50,214 [salt.state       :300 ][INFO    ][25846] No changes needed to be made
2019-05-08 08:47:50,215 [salt.state       :1951][INFO    ][25846] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:47:50.215061 duration_in_ms=41.965
2019-05-08 08:47:50,215 [salt.state       :1780][INFO    ][25846] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 08:47:50.215869
2019-05-08 08:47:50,216 [salt.state       :1813][INFO    ][25846] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-08 08:47:50,254 [salt.state       :300 ][INFO    ][25846] No changes needed to be made
2019-05-08 08:47:50,254 [salt.state       :1951][INFO    ][25846] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 08:47:50.254777 duration_in_ms=38.908
2019-05-08 08:47:50,255 [salt.state       :1780][INFO    ][25846] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 08:47:50.255440
2019-05-08 08:47:50,255 [salt.state       :1813][INFO    ][25846] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-08 08:47:50,269 [salt.state       :300 ][INFO    ][25846] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-08 08:47:50,269 [salt.state       :1951][INFO    ][25846] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 08:47:50.269392 duration_in_ms=13.952
2019-05-08 08:47:50,271 [salt.state       :1780][INFO    ][25846] Running state [a2enmod headers] at time 08:47:50.271026
2019-05-08 08:47:50,271 [salt.state       :1813][INFO    ][25846] Executing state cmd.run for [a2enmod headers]
2019-05-08 08:47:50,272 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command 'a2enmod headers' in directory '/root'
2019-05-08 08:47:50,345 [salt.state       :300 ][INFO    ][25846] {'pid': 25865, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-08 08:47:50,346 [salt.state       :1951][INFO    ][25846] Completed state [a2enmod headers] at time 08:47:50.346757 duration_in_ms=75.73
2019-05-08 08:47:50,347 [salt.state       :1780][INFO    ][25846] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 08:47:50.347664
2019-05-08 08:47:50,348 [salt.state       :1813][INFO    ][25846] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-08 08:47:50,370 [salt.state       :300 ][INFO    ][25846] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-08 08:47:50,371 [salt.state       :1951][INFO    ][25846] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 08:47:50.371289 duration_in_ms=23.625
2019-05-08 08:47:50,372 [salt.state       :1780][INFO    ][25846] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 08:47:50.372340
2019-05-08 08:47:50,372 [salt.state       :1813][INFO    ][25846] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-08 08:47:50,447 [salt.state       :300 ][INFO    ][25846] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-08 08:47:50,447 [salt.state       :1951][INFO    ][25846] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 08:47:50.447735 duration_in_ms=75.396
2019-05-08 08:47:50,448 [salt.state       :1780][INFO    ][25846] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 08:47:50.448348
2019-05-08 08:47:50,448 [salt.state       :1813][INFO    ][25846] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-08 08:47:50,513 [salt.state       :300 ][INFO    ][25846] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-08 08:47:50,513 [salt.state       :1951][INFO    ][25846] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 08:47:50.513316 duration_in_ms=64.967
2019-05-08 08:47:50,514 [salt.state       :1780][INFO    ][25846] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 08:47:50.514010
2019-05-08 08:47:50,514 [salt.state       :1813][INFO    ][25846] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-08 08:47:50,572 [salt.state       :300 ][INFO    ][25846] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-08 08:47:50,573 [salt.state       :1951][INFO    ][25846] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 08:47:50.573159 duration_in_ms=59.15
2019-05-08 08:47:50,573 [salt.state       :1780][INFO    ][25846] Running state [/root/.pgpass] at time 08:47:50.573424
2019-05-08 08:47:50,573 [salt.state       :1813][INFO    ][25846] Executing state file.managed for [/root/.pgpass]
2019-05-08 08:47:50,614 [salt.state       :300 ][INFO    ][25846] File /root/.pgpass is in the correct state
2019-05-08 08:47:50,615 [salt.state       :1951][INFO    ][25846] Completed state [/root/.pgpass] at time 08:47:50.615008 duration_in_ms=41.584
2019-05-08 08:47:50,619 [salt.state       :1780][INFO    ][25846] Running state [maas-region syncdb --noinput] at time 08:47:50.619548
2019-05-08 08:47:50,619 [salt.state       :1813][INFO    ][25846] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-08 08:47:50,620 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-08 08:47:52,544 [salt.state       :300 ][INFO    ][25846] {'pid': 25879, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: contenttypes, sessions, metadataserver, piston3, auth, maasserver, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-08 08:47:52,544 [salt.state       :1951][INFO    ][25846] Completed state [maas-region syncdb --noinput] at time 08:47:52.544535 duration_in_ms=1924.987
2019-05-08 08:47:52,544 [salt.state       :2022][WARNING ][25846] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-08 08:47:52,545 [salt.state       :1780][INFO    ][25846] Running state [maas-regiond] at time 08:47:52.545781
2019-05-08 08:47:52,546 [salt.state       :1813][INFO    ][25846] Executing state service.running for [maas-regiond]
2019-05-08 08:47:52,546 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-08 08:47:52,579 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-08 08:47:52,594 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-08 08:47:52,609 [salt.state       :300 ][INFO    ][25846] The service maas-regiond is already running
2019-05-08 08:47:52,609 [salt.state       :1951][INFO    ][25846] Completed state [maas-regiond] at time 08:47:52.609840 duration_in_ms=64.059
2019-05-08 08:47:52,610 [salt.state       :1780][INFO    ][25846] Running state [bind9] at time 08:47:52.610851
2019-05-08 08:47:52,611 [salt.state       :1813][INFO    ][25846] Executing state service.running for [bind9]
2019-05-08 08:47:52,611 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-08 08:47:52,626 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-08 08:47:52,641 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-08 08:47:52,655 [salt.state       :300 ][INFO    ][25846] The service bind9 is already running
2019-05-08 08:47:52,655 [salt.state       :1951][INFO    ][25846] Completed state [bind9] at time 08:47:52.655746 duration_in_ms=44.895
2019-05-08 08:47:52,656 [salt.state       :1780][INFO    ][25846] Running state [apache2] at time 08:47:52.656805
2019-05-08 08:47:52,657 [salt.state       :1813][INFO    ][25846] Executing state service.running for [apache2]
2019-05-08 08:47:52,657 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-08 08:47:52,674 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-08 08:47:52,689 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-08 08:47:52,708 [salt.state       :300 ][INFO    ][25846] The service apache2 is already running
2019-05-08 08:47:52,709 [salt.state       :1951][INFO    ][25846] Completed state [apache2] at time 08:47:52.709045 duration_in_ms=52.239
2019-05-08 08:47:52,710 [salt.state       :1780][INFO    ][25846] Running state [maasng.wait_for_http_code] at time 08:47:52.710060
2019-05-08 08:47:52,710 [salt.state       :1813][INFO    ][25846] Executing state module.run for [maasng.wait_for_http_code]
2019-05-08 08:47:52,710 [salt.utils.decorators:613 ][WARNING ][25846] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:47:52,716 [salt.state       :300 ][INFO    ][25846] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-08 08:47:52,716 [salt.state       :1951][INFO    ][25846] Completed state [maasng.wait_for_http_code] at time 08:47:52.716802 duration_in_ms=6.742
2019-05-08 08:47:52,717 [salt.state       :1780][INFO    ][25846] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 08:47:52.717361
2019-05-08 08:47:52,717 [salt.state       :1813][INFO    ][25846] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-08 08:47:52,717 [salt.state       :300 ][INFO    ][25846] /var/lib/maas/.setup_admin exists
2019-05-08 08:47:52,718 [salt.state       :1951][INFO    ][25846] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 08:47:52.718087 duration_in_ms=0.726
2019-05-08 08:47:52,718 [salt.state       :1780][INFO    ][25846] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:47:52.718607
2019-05-08 08:47:52,718 [salt.state       :1813][INFO    ][25846] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 08:47:52,719 [salt.loaded.int.module.cmdmod:395 ][INFO    ][25846] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 08:47:54,053 [salt.state       :300 ][INFO    ][25846] {'pid': 25898, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 08:47:54,053 [salt.state       :1951][INFO    ][25846] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:47:54.053553 duration_in_ms=1334.946
2019-05-08 08:47:54,056 [salt.state       :1780][INFO    ][25846] Running state [maas_region_boot_source_resources_mirror] at time 08:47:54.056808
2019-05-08 08:47:54,057 [salt.state       :1813][INFO    ][25846] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-08 08:47:54,145 [salt.state       :300 ][INFO    ][25846] {'changes': {}}
2019-05-08 08:47:54,146 [salt.state       :1951][INFO    ][25846] Completed state [maas_region_boot_source_resources_mirror] at time 08:47:54.146179 duration_in_ms=89.367
2019-05-08 08:47:54,148 [salt.state       :1780][INFO    ][25846] Running state [maasng.boot_resources_import] at time 08:47:54.147972
2019-05-08 08:47:54,148 [salt.state       :1813][INFO    ][25846] Executing state module.run for [maasng.boot_resources_import]
2019-05-08 08:47:54,149 [salt.utils.decorators:613 ][WARNING ][25846] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:47:54,270 [salt.loaded.ext.module.maasng:1600][INFO    ][25846] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-08 08:47:59,328 [salt.loaded.ext.module.maasng:1600][INFO    ][25846] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-08 08:48:00,861 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508084800848102
2019-05-08 08:48:00,884 [salt.minion      :1432][INFO    ][25938] Starting a new job with PID 25938
2019-05-08 08:48:00,906 [salt.minion      :1711][INFO    ][25938] Returning information for job: 20190508084800848102
2019-05-08 08:48:04,388 [salt.loaded.ext.module.maasng:1600][INFO    ][25846] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-08 08:48:09,502 [salt.state       :300 ][INFO    ][25846] {'ret': True}
2019-05-08 08:48:09,503 [salt.state       :1951][INFO    ][25846] Completed state [maasng.boot_resources_import] at time 08:48:09.503016 duration_in_ms=15355.044
2019-05-08 08:48:09,504 [salt.state       :1780][INFO    ][25846] Running state [maas_region_boot_sources_selection_xenial] at time 08:48:09.504064
2019-05-08 08:48:09,504 [salt.state       :1813][INFO    ][25846] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-08 08:48:09,693 [salt.state       :300 ][INFO    ][25846] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-08 08:48:09,693 [salt.state       :1951][INFO    ][25846] Completed state [maas_region_boot_sources_selection_xenial] at time 08:48:09.693662 duration_in_ms=189.598
2019-05-08 08:48:09,695 [salt.state       :1780][INFO    ][25846] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 08:48:09.694976
2019-05-08 08:48:09,695 [salt.state       :1813][INFO    ][25846] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-08 08:48:09,696 [salt.utils.decorators:613 ][WARNING ][25846] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:48:09,696 [salt.loaded.ext.module.maasng:1771][INFO    ][25846] boot-sources sync initiated for ALL Rack's
2019-05-08 08:48:10,612 [salt.state       :300 ][INFO    ][25846] {'ret': True}
2019-05-08 08:48:10,612 [salt.state       :1951][INFO    ][25846] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 08:48:10.612432 duration_in_ms=917.456
2019-05-08 08:48:10,614 [salt.state       :1780][INFO    ][25846] Running state [maas.process_maas_config] at time 08:48:10.614596
2019-05-08 08:48:10,615 [salt.state       :1813][INFO    ][25846] Executing state module.run for [maas.process_maas_config]
2019-05-08 08:48:10,615 [salt.utils.decorators:613 ][WARNING ][25846] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:48:10,616 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=enable_http_proxy value=True
2019-05-08 08:48:10,677 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=upstream_dns value=8.8.8.8
2019-05-08 08:48:10,741 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=commissioning_distro_series value=xenial
2019-05-08 08:48:10,801 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=default_osystem value=ubuntu
2019-05-08 08:48:10,843 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=active_discovery_interval value=600
2019-05-08 08:48:10,885 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=dnssec_validation value=no
2019-05-08 08:48:10,933 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=maas_name value=mas01
2019-05-08 08:48:10,981 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=network_discovery value=enabled
2019-05-08 08:48:11,089 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=enable_third_party_drivers value=True
2019-05-08 08:48:11,137 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=default_storage_layout value=lvm
2019-05-08 08:48:11,197 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=ntp_external_only value=True
2019-05-08 08:48:11,251 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-08 08:48:13,476 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=default_distro_series value=xenial
2019-05-08 08:48:13,538 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-08 08:48:13,677 [salt.state       :300 ][INFO    ][25846] {'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-05-08 08:48:13,678 [salt.state       :1951][INFO    ][25846] Completed state [maas.process_maas_config] at time 08:48:13.677919 duration_in_ms=3063.321
2019-05-08 08:48:13,679 [salt.state       :1780][INFO    ][25846] Running state [pxe_admin] at time 08:48:13.679082
2019-05-08 08:48:13,679 [salt.state       :1813][INFO    ][25846] Executing state maasng.fabric_present for [pxe_admin]
2019-05-08 08:48:13,754 [salt.loaded.ext.module.maasng:945 ][INFO    ][25846] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], 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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 08:48:13,852 [salt.loaded.ext.module.maasng:1008][WARNING ][25846] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-08 08:48:13,852 [salt.loaded.ext.module.maasng:1011][WARNING ][25846] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-08 08:48:13,948 [salt.state       :300 ][INFO    ][25846] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-08 08:48:13,948 [salt.state       :1951][INFO    ][25846] Completed state [pxe_admin] at time 08:48:13.948354 duration_in_ms=269.272
2019-05-08 08:48:13,948 [salt.state       :1780][INFO    ][25846] Running state [vlan 0] at time 08:48:13.948824
2019-05-08 08:48:13,949 [salt.state       :1813][INFO    ][25846] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-08 08:48:14,012 [salt.loaded.ext.module.maasng:945 ][INFO    ][25846] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], 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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 08:48:14,132 [salt.loaded.ext.module.maasng:945 ][INFO    ][25846] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 08:48:14,425 [salt.loaded.ext.module.maasng:945 ][INFO    ][25846] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 08:48:14,521 [salt.state       :300 ][INFO    ][25846] {'new': 'Vlan untagged was updated'}
2019-05-08 08:48:14,521 [salt.state       :1951][INFO    ][25846] Completed state [vlan 0] at time 08:48:14.521333 duration_in_ms=572.51
2019-05-08 08:48:14,522 [salt.state       :1780][INFO    ][25846] Running state [192.168.11.0/24] at time 08:48:14.522617
2019-05-08 08:48:14,523 [salt.state       :1813][INFO    ][25846] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-08 08:48:14,743 [salt.loaded.ext.module.maasng:945 ][INFO    ][25846] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 08:48:14,743 [salt.loaded.ext.module.maasng:1235][WARNING ][25846] Ignoring parameter vlan:0
2019-05-08 08:48:14,815 [salt.state       :300 ][INFO    ][25846] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-08 08:48:14,815 [salt.state       :1951][INFO    ][25846] Completed state [192.168.11.0/24] at time 08:48:14.815486 duration_in_ms=292.86
2019-05-08 08:48:14,816 [salt.state       :1780][INFO    ][25846] Running state [maas_create_iprange_1] at time 08:48:14.816424
2019-05-08 08:48:14,816 [salt.state       :1813][INFO    ][25846] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-08 08:48:14,886 [salt.state       :300 ][INFO    ][25846] Iprange maas_create_iprange_1 already exist.
2019-05-08 08:48:14,887 [salt.state       :1951][INFO    ][25846] Completed state [maas_create_iprange_1] at time 08:48:14.887308 duration_in_ms=70.883
2019-05-08 08:48:14,887 [salt.state       :1780][INFO    ][25846] Running state [vlan 0] at time 08:48:14.887630
2019-05-08 08:48:14,887 [salt.state       :1813][INFO    ][25846] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-08 08:48:14,952 [salt.loaded.ext.module.maasng:945 ][INFO    ][25846] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], 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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 08:48:15,042 [salt.loaded.ext.module.maasng:945 ][INFO    ][25846] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, 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': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, 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': 1}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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/', u'id': 2}]
2019-05-08 08:48:15,263 [salt.loaded.ext.module.maasng:945 ][INFO    ][25846] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], 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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 08:48:15,366 [salt.state       :300 ][INFO    ][25846] {'new': 'Vlan untagged was updated'}
2019-05-08 08:48:15,366 [salt.state       :1951][INFO    ][25846] Completed state [vlan 0] at time 08:48:15.366351 duration_in_ms=478.72
2019-05-08 08:48:15,367 [salt.state       :1780][INFO    ][25846] Running state [opnfv] at time 08:48:15.367307
2019-05-08 08:48:15,367 [salt.state       :1813][INFO    ][25846] Executing state maasng.sshkey_present for [opnfv]
2019-05-08 08:48:15,425 [salt.loaded.ext.module.maasng:1903][INFO    ][25846] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-08 08:48:15,426 [salt.state       :300 ][INFO    ][25846] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-08 08:48:15,426 [salt.state       :1951][INFO    ][25846] Completed state [opnfv] at time 08:48:15.426782 duration_in_ms=59.475
2019-05-08 08:48:15,427 [salt.state       :1780][INFO    ][25846] Running state [maas.process_tags] at time 08:48:15.427676
2019-05-08 08:48:15,428 [salt.state       :1813][INFO    ][25846] Executing state module.run for [maas.process_tags]
2019-05-08 08:48:15,428 [salt.utils.decorators:613 ][WARNING ][25846] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:48:15,497 [salt.loaded.ext.module.maas:92  ][INFO    ][25846] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-05-08 08:48:15,551 [salt.state       :300 ][INFO    ][25846] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-05-08 08:48:15,551 [salt.state       :1951][INFO    ][25846] Completed state [maas.process_tags] at time 08:48:15.551547 duration_in_ms=123.87
2019-05-08 08:48:15,556 [salt.minion      :1711][INFO    ][25846] Returning information for job: 20190508084745742096
2019-05-08 08:48:16,111 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508084816101909
2019-05-08 08:48:16,130 [salt.minion      :1432][INFO    ][26336] Starting a new job with PID 26336
2019-05-08 08:48:19,724 [salt.state       :915 ][INFO    ][26336] Loading fresh modules for state activity
2019-05-08 08:48:19,783 [salt.fileclient  :1219][INFO    ][26336] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-05-08 08:48:19,827 [salt.state       :1780][INFO    ][26336] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:48:19.826925
2019-05-08 08:48:19,827 [salt.state       :1813][INFO    ][26336] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 08:48:19,829 [salt.loaded.int.module.cmdmod:395 ][INFO    ][26336] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 08:48:21,287 [salt.state       :300 ][INFO    ][26336] {'pid': 26382, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 08:48:21,287 [salt.state       :1951][INFO    ][26336] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:48:21.287555 duration_in_ms=1460.631
2019-05-08 08:48:21,289 [salt.state       :1780][INFO    ][26336] Running state [maas.process_machines] at time 08:48:21.289069
2019-05-08 08:48:21,289 [salt.state       :1813][INFO    ][26336] Executing state module.run for [maas.process_machines]
2019-05-08 08:48:21,289 [salt.utils.decorators:613 ][WARNING ][26336] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:48:21,354 [salt.loaded.ext.module.maas:412 ][WARNING ][26336] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 08:48:21,354 [salt.loaded.ext.module.maas:92  ][INFO    ][26336] 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-05-08 08:48:22,703 [salt.loaded.ext.module.maas:412 ][WARNING ][26336] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 08:48:22,704 [salt.loaded.ext.module.maas:92  ][INFO    ][26336] 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-05-08 08:48:23,871 [salt.loaded.ext.module.maas:412 ][WARNING ][26336] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 08:48:23,872 [salt.loaded.ext.module.maas:92  ][INFO    ][26336] 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-05-08 08:48:24,949 [salt.loaded.ext.module.maas:412 ][WARNING ][26336] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 08:48:24,950 [salt.loaded.ext.module.maas:92  ][INFO    ][26336] 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-05-08 08:48:26,339 [salt.loaded.ext.module.maas:412 ][WARNING ][26336] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 08:48:26,339 [salt.loaded.ext.module.maas:92  ][INFO    ][26336] 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-05-08 08:48:27,759 [salt.state       :300 ][INFO    ][26336] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-08 08:48:27,759 [salt.state       :1951][INFO    ][26336] Completed state [maas.process_machines] at time 08:48:27.759668 duration_in_ms=6470.596
2019-05-08 08:48:27,763 [salt.minion      :1711][INFO    ][26336] Returning information for job: 20190508084816101909
2019-05-08 08:48:58,837 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508084858824633
2019-05-08 08:48:58,858 [salt.minion      :1432][INFO    ][26678] Starting a new job with PID 26678
2019-05-08 08:49:02,782 [salt.state       :915 ][INFO    ][26678] Loading fresh modules for state activity
2019-05-08 08:49:02,836 [salt.fileclient  :1219][INFO    ][26678] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-08 08:49:02,881 [salt.state       :1780][INFO    ][26678] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:49:02.881431
2019-05-08 08:49:02,881 [salt.state       :1813][INFO    ][26678] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 08:49:02,884 [salt.loaded.int.module.cmdmod:395 ][INFO    ][26678] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 08:49:04,299 [salt.state       :300 ][INFO    ][26678] {'pid': 26700, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 08:49:04,300 [salt.state       :1951][INFO    ][26678] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:49:04.300375 duration_in_ms=1418.945
2019-05-08 08:49:04,301 [salt.state       :1780][INFO    ][26678] Running state [maas.wait_for_machine_status] at time 08:49:04.301862
2019-05-08 08:49:04,302 [salt.state       :1813][INFO    ][26678] Executing state module.run for [maas.wait_for_machine_status]
2019-05-08 08:49:04,302 [salt.utils.decorators:613 ][WARNING ][26678] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:49:05,233 [salt.loaded.ext.module.maas:1023][INFO    ][26678] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.0729351s left)
2019-05-08 08:49:13,953 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508084913940407
2019-05-08 08:49:13,972 [salt.minion      :1432][INFO    ][26738] Starting a new job with PID 26738
2019-05-08 08:49:13,993 [salt.minion      :1711][INFO    ][26738] Returning information for job: 20190508084913940407
2019-05-08 08:49:36,223 [salt.loaded.ext.module.maas:1023][INFO    ][26678] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.08359909s left)
2019-05-08 08:49:43,998 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508084943986624
2019-05-08 08:49:44,021 [salt.minion      :1432][INFO    ][26758] Starting a new job with PID 26758
2019-05-08 08:49:44,046 [salt.minion      :1711][INFO    ][26758] Returning information for job: 20190508084943986624
2019-05-08 08:50:07,278 [salt.loaded.ext.module.maas:1023][INFO    ][26678] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.02820206s left)
2019-05-08 08:50:14,042 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085014037574
2019-05-08 08:50:14,062 [salt.minion      :1432][INFO    ][26923] Starting a new job with PID 26923
2019-05-08 08:50:14,085 [salt.minion      :1711][INFO    ][26923] Returning information for job: 20190508085014037574
2019-05-08 08:50:38,924 [salt.loaded.ext.module.maas:1023][INFO    ][26678] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.38281417s left)
2019-05-08 08:50:44,084 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085044071112
2019-05-08 08:50:44,106 [salt.minion      :1432][INFO    ][27038] Starting a new job with PID 27038
2019-05-08 08:50:44,131 [salt.minion      :1711][INFO    ][27038] Returning information for job: 20190508085044071112
2019-05-08 08:51:10,002 [salt.loaded.ext.module.maas:1023][INFO    ][26678] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.30450416s left)
2019-05-08 08:51:14,141 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085114129240
2019-05-08 08:51:14,164 [salt.minion      :1432][INFO    ][27792] Starting a new job with PID 27792
2019-05-08 08:51:14,187 [salt.minion      :1711][INFO    ][27792] Returning information for job: 20190508085114129240
2019-05-08 08:51:41,892 [salt.loaded.ext.module.maas:1023][INFO    ][26678] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.41479611s left)
2019-05-08 08:51:44,192 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085144179996
2019-05-08 08:51:44,215 [salt.minion      :1432][INFO    ][27821] Starting a new job with PID 27821
2019-05-08 08:51:44,239 [salt.minion      :1711][INFO    ][27821] Returning information for job: 20190508085144179996
2019-05-08 08:52:14,259 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085214245978
2019-05-08 08:52:14,283 [salt.minion      :1432][INFO    ][28132] Starting a new job with PID 28132
2019-05-08 08:52:14,306 [salt.minion      :1711][INFO    ][28132] Returning information for job: 20190508085214245978
2019-05-08 08:52:15,482 [salt.state       :300 ][INFO    ][26678] {'ret': True}
2019-05-08 08:52:15,483 [salt.state       :1951][INFO    ][26678] Completed state [maas.wait_for_machine_status] at time 08:52:15.483165 duration_in_ms=191181.3
2019-05-08 08:52:15,487 [salt.minion      :1711][INFO    ][26678] Returning information for job: 20190508084858824633
2019-05-08 08:52:16,137 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508085216124097
2019-05-08 08:52:16,159 [salt.minion      :1432][INFO    ][28141] Starting a new job with PID 28141
2019-05-08 08:52:19,892 [salt.state       :915 ][INFO    ][28141] Loading fresh modules for state activity
2019-05-08 08:52:19,944 [salt.fileclient  :1219][INFO    ][28141] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-08 08:52:20,035 [salt.state       :1780][INFO    ][28141] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:20.035415
2019-05-08 08:52:20,035 [salt.state       :1813][INFO    ][28141] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 08:52:20,037 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28141] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 08:52:21,648 [salt.state       :300 ][INFO    ][28141] {'pid': 28148, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 08:52:21,649 [salt.state       :1951][INFO    ][28141] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:21.649251 duration_in_ms=1613.835
2019-05-08 08:52:21,651 [salt.state       :1780][INFO    ][28141] Running state [maas_machines_storage_cmp002_lvm] at time 08:52:21.651762
2019-05-08 08:52:21,652 [salt.state       :1813][INFO    ][28141] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-08 08:52:23,013 [salt.loaded.ext.module.maasng:610 ][INFO    ][28141] qybh6k
2019-05-08 08:52:23,014 [salt.loaded.ext.module.maasng:626 ][INFO    ][28141] sda
2019-05-08 08:52:23,698 [salt.loaded.ext.module.maasng:361 ][INFO    ][28141] qybh6k
2019-05-08 08:52:23,836 [salt.loaded.ext.module.maasng:367 ][INFO    ][28141] [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/3/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'34fb7028-6655-4ebe-b823-7cd92e933f4e', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'qybh6k', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'3d53268e-97cc-40da-b1a1-cb7141568c8f', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/3/partition/5', u'type': u'partition', u'id': 5, u'device_id': 3}], u'id': 3, u'path': u'/dev/disk/by-dname/sda', u'system_id': u'qybh6k', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}, {u'size': 2397988454400, u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/10/', u'uuid': u'266b599a-6e76-4fb3-8600-7c70918c7ff1', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'id': 10, u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'qybh6k', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'd4451882-7d26-4520-ae24-e19f265a8b85', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'serial': None, u'name': u'vgroot-lvroot'}]
2019-05-08 08:52:23,836 [salt.loaded.ext.module.maasng:632 ][INFO    ][28141] vgroot
2019-05-08 08:52:23,837 [salt.loaded.ext.module.maasng:635 ][INFO    ][28141] lvroot
2019-05-08 08:52:23,837 [salt.loaded.ext.module.maasng:639 ][INFO    ][28141] 107374182400
2019-05-08 08:52:24,532 [salt.loaded.ext.module.maasng:645 ][INFO    ][28141] {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'swap_size': None, u'memory_test_status': -1, 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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': 32}], u'tags': [], u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'qybh6k', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/interfaces/4/'}, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'status_action': u'modules-final', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'blockdevice_set': [{u'size': 2397998940160, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'system_id': u'qybh6k', u'type': u'physical', u'partitions': [{u'uuid': u'7a3b4b97-dee4-433b-bafc-3d53a5fddd16', u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/3/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'qybh6k', u'filesystem': {u'mount_options': None, u'uuid': u'f308ff69-e7c8-41c7-8427-517ddf4272f3', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'id': 3, u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/3/'}, {u'size': 107374182400, u'available_size': 0, u'uuid': u'bd1f0e5c-85da-4fd7-a429-975fe8eff8ef', u'name': u'vgroot-lvroot', u'tags': [], u'system_id': u'qybh6k', u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'id': 14, u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'd0477b1c-9fbe-4e0f-96c8-1b800ef731bf', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/14/'}], 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/qybh6k/', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'qybh6k', u'power_state': u'on', 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"'cloudinit' running modules for final", u'physicalblockdevice_set': [{u'size': 2397998940160, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'system_id': u'qybh6k', u'type': u'physical', u'partitions': [{u'uuid': u'7a3b4b97-dee4-433b-bafc-3d53a5fddd16', u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/3/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'qybh6k', u'filesystem': {u'mount_options': None, u'uuid': u'f308ff69-e7c8-41c7-8427-517ddf4272f3', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'id': 3, u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/3/'}], u'architecture': u'amd64/generic', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'ip_addresses': [u'192.168.11.42'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'qybh6k', u'id': 9}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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': 32}], u'tags': [], u'vlan': {u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'qybh6k', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/interfaces/4/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 33}], u'tags': [], u'vlan': {u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 14, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'qybh6k', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/interfaces/14/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 35}], u'tags': [], u'vlan': {u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 16, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'qybh6k', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/interfaces/16/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 36}], u'tags': [], u'vlan': {u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'id': 9, u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'qybh6k', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/interfaces/9/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'size': 107374182400, u'available_size': 0, u'uuid': u'bd1f0e5c-85da-4fd7-a429-975fe8eff8ef', u'name': u'vgroot-lvroot', u'tags': [], u'system_id': u'qybh6k', u'type': u'virtual', u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'id': 14, u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'd0477b1c-9fbe-4e0f-96c8-1b800ef731bf', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/14/'}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'current_commissioning_result_id': 2, u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'size': 2397998940160, u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'system_id': u'qybh6k', u'type': u'physical', u'partitions': [{u'uuid': u'7a3b4b97-dee4-433b-bafc-3d53a5fddd16', u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/3/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'qybh6k', u'filesystem': {u'mount_options': None, u'uuid': u'f308ff69-e7c8-41c7-8427-517ddf4272f3', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 3, u'type': u'partition', u'id': 9, u'size': 2397992648704}], u'used_for': u'GPT partitioned with 1 partition', u'id': 3, u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/qybh6k/blockdevices/3/'}}
2019-05-08 08:52:24,534 [salt.state       :300 ][INFO    ][28141] {'new': {'storage_layout': 'lvm'}}
2019-05-08 08:52:24,534 [salt.state       :1951][INFO    ][28141] Completed state [maas_machines_storage_cmp002_lvm] at time 08:52:24.534685 duration_in_ms=2882.922
2019-05-08 08:52:24,535 [salt.state       :1780][INFO    ][28141] Running state [maas_machines_storage_cmp001_lvm] at time 08:52:24.535141
2019-05-08 08:52:24,535 [salt.state       :1813][INFO    ][28141] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-08 08:52:25,529 [salt.loaded.ext.module.maasng:610 ][INFO    ][28141] 8h46gc
2019-05-08 08:52:25,530 [salt.loaded.ext.module.maasng:626 ][INFO    ][28141] sda
2019-05-08 08:52:26,238 [salt.loaded.ext.module.maasng:361 ][INFO    ][28141] 8h46gc
2019-05-08 08:52:26,344 [salt.loaded.ext.module.maasng:367 ][INFO    ][28141] [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/4/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'6202480f-564d-4761-a295-d4f9b1ba7dd4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8h46gc', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'9f19b04d-bb19-40da-92eb-7aaa27249897', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/4/partition/8', u'type': u'partition', u'id': 8, u'device_id': 4}], u'id': 4, u'path': u'/dev/disk/by-dname/sda', u'system_id': u'8h46gc', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e72837274f1901cc7889705aa1b02', u'name': u'sda'}, {u'size': 2397988454400, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/13/', u'uuid': u'47fa68b2-01bb-45bb-8252-a0256d1ab6d2', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'id': 13, u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'8h46gc', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'e8e9eb1f-bc03-4e7a-b489-cb4d0d95bfa1', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'serial': None, u'name': u'vgroot-lvroot'}]
2019-05-08 08:52:26,345 [salt.loaded.ext.module.maasng:632 ][INFO    ][28141] vgroot
2019-05-08 08:52:26,345 [salt.loaded.ext.module.maasng:635 ][INFO    ][28141] lvroot
2019-05-08 08:52:26,346 [salt.loaded.ext.module.maasng:639 ][INFO    ][28141] 107374182400
2019-05-08 08:52:26,971 [salt.loaded.ext.module.maasng:645 ][INFO    ][28141] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.38'], u'storage_test_status_name': u'Passed', u'owner_data': {}, 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'fqdn': u'cmp001.maas', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'commissioning_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'blockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/4/', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'e704378c-47cf-4e52-bec0-59c9587ff5cf', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8h46gc', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'34b9c0a7-7780-4db9-b3da-fb4230c8d993', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/4/partition/10', u'type': u'partition', u'id': 10, u'device_id': 4}], u'id': 4, u'path': u'/dev/disk/by-dname/sda', u'system_id': u'8h46gc', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'serial': u'618e72837274f1901cc7889705aa1b02', u'name': u'sda'}, {u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/15/', u'uuid': u'99ab293e-c222-4bbd-92ae-cf8664ba0d59', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'id': 15, u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'8h46gc', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'6181d8cd-b582-4e98-8cf0-c9e263a7f0f8', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'serial': None, u'name': u'vgroot-lvroot'}], 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/8h46gc/', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'8h46gc', 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'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'uuid': u'99ab293e-c222-4bbd-92ae-cf8664ba0d59', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'6181d8cd-b582-4e98-8cf0-c9e263a7f0f8', u'fstype': u'ext4'}, u'name': u'vgroot-lvroot', u'system_id': u'8h46gc', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/15/'}], u'architecture': u'amd64/generic', u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'off', u'power_type': u'ipmi', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'e704378c-47cf-4e52-bec0-59c9587ff5cf', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8h46gc', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'34b9c0a7-7780-4db9-b3da-fb4230c8d993', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/4/partition/10', u'type': u'partition', u'id': 10, u'device_id': 4}], u'filesystem': None, u'name': u'sda', u'system_id': u'8h46gc', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/4/'}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'8h46gc', u'id': 10}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'status_action': u'', u'disable_ipv4': False, u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, 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.38', u'id': 47, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], 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'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, 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.38'}], u'system_id': u'8h46gc', u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/interfaces/5/'}, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, 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.38', u'id': 47, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], 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'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, 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.38'}], u'system_id': u'8h46gc', u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'id': 48, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'8h46gc', u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/interfaces/18/'}, {u'name': u'enp8s0', u'links': [{u'id': 49, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'8h46gc', u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/interfaces/19/'}, {u'name': u'enp7s0', u'links': [{u'id': 50, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'enabled': True, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'system_id': u'8h46gc', u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/interfaces/20/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'e704378c-47cf-4e52-bec0-59c9587ff5cf', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'8h46gc', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'34b9c0a7-7780-4db9-b3da-fb4230c8d993', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/4/partition/10', u'type': u'partition', u'id': 10, u'device_id': 4}], u'filesystem': None, u'name': u'sda', u'system_id': u'8h46gc', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/8h46gc/blockdevices/4/'}}
2019-05-08 08:52:26,973 [salt.state       :300 ][INFO    ][28141] {'new': {'storage_layout': 'lvm'}}
2019-05-08 08:52:26,974 [salt.state       :1951][INFO    ][28141] Completed state [maas_machines_storage_cmp001_lvm] at time 08:52:26.974266 duration_in_ms=2439.124
2019-05-08 08:52:26,977 [salt.minion      :1711][INFO    ][28141] Returning information for job: 20190508085216124097
2019-05-08 08:52:27,452 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508085227445611
2019-05-08 08:52:27,468 [salt.minion      :1432][INFO    ][28208] Starting a new job with PID 28208
2019-05-08 08:52:28,198 [salt.state       :915 ][INFO    ][28208] Loading fresh modules for state activity
2019-05-08 08:52:28,246 [salt.fileclient  :1219][INFO    ][28208] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-08 08:52:28,283 [salt.state       :1780][INFO    ][28208] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:28.283875
2019-05-08 08:52:28,284 [salt.state       :1813][INFO    ][28208] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 08:52:28,286 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28208] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 08:52:29,833 [salt.state       :300 ][INFO    ][28208] {'pid': 28215, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 08:52:29,834 [salt.state       :1951][INFO    ][28208] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:29.834679 duration_in_ms=1550.804
2019-05-08 08:52:29,837 [salt.state       :1780][INFO    ][28208] Running state [maas.deploy_machines] at time 08:52:29.837276
2019-05-08 08:52:29,837 [salt.state       :1813][INFO    ][28208] Executing state module.run for [maas.deploy_machines]
2019-05-08 08:52:29,839 [salt.utils.decorators:613 ][WARNING ][28208] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:52:30,634 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=qybh6k distro_series=xenial
2019-05-08 08:52:32,980 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=8h46gc distro_series=xenial
2019-05-08 08:52:35,256 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=hwrdwc distro_series=xenial
2019-05-08 08:52:37,795 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=prg4dt distro_series=xenial
2019-05-08 08:52:40,436 [salt.loaded.ext.module.maas:684 ][INFO    ][28208] deploymachines hwe_kernel=hwe-16.04 system_id=qgddxx distro_series=xenial
2019-05-08 08:52:42,466 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085242457136
2019-05-08 08:52:42,484 [salt.minion      :1432][INFO    ][28479] Starting a new job with PID 28479
2019-05-08 08:52:42,502 [salt.minion      :1711][INFO    ][28479] Returning information for job: 20190508085242457136
2019-05-08 08:52:43,162 [salt.state       :300 ][INFO    ][28208] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-08 08:52:43,163 [salt.state       :1951][INFO    ][28208] Completed state [maas.deploy_machines] at time 08:52:43.163349 duration_in_ms=13326.071
2019-05-08 08:52:43,167 [salt.minion      :1711][INFO    ][28208] Returning information for job: 20190508085227445611
2019-05-08 08:52:43,811 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508085243798789
2019-05-08 08:52:43,833 [salt.minion      :1432][INFO    ][28492] Starting a new job with PID 28492
2019-05-08 08:52:47,501 [salt.state       :915 ][INFO    ][28492] Loading fresh modules for state activity
2019-05-08 08:52:47,549 [salt.fileclient  :1219][INFO    ][28492] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-08 08:52:47,585 [salt.state       :1780][INFO    ][28492] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:47.585168
2019-05-08 08:52:47,585 [salt.state       :1813][INFO    ][28492] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 08:52:47,587 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28492] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 08:52:49,035 [salt.state       :300 ][INFO    ][28492] {'pid': 28506, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 08:52:49,035 [salt.state       :1951][INFO    ][28492] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:49.035867 duration_in_ms=1450.698
2019-05-08 08:52:49,038 [salt.state       :1780][INFO    ][28492] Running state [maas.wait_for_machine_status] at time 08:52:49.038880
2019-05-08 08:52:49,039 [salt.state       :1813][INFO    ][28492] Executing state module.run for [maas.wait_for_machine_status]
2019-05-08 08:52:49,040 [salt.utils.decorators:613 ][WARNING ][28492] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 08:52:52,651 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.39792204s left)
2019-05-08 08:52:58,900 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085258886419
2019-05-08 08:52:58,923 [salt.minion      :1432][INFO    ][28518] Starting a new job with PID 28518
2019-05-08 08:52:58,946 [salt.minion      :1711][INFO    ][28518] Returning information for job: 20190508085258886419
2019-05-08 08:53:26,407 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2212.64268398s left)
2019-05-08 08:53:28,955 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085328942399
2019-05-08 08:53:28,978 [salt.minion      :1432][INFO    ][28573] Starting a new job with PID 28573
2019-05-08 08:53:29,000 [salt.minion      :1711][INFO    ][28573] Returning information for job: 20190508085328942399
2019-05-08 08:53:59,049 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085359036238
2019-05-08 08:53:59,072 [salt.minion      :1432][INFO    ][28596] Starting a new job with PID 28596
2019-05-08 08:53:59,095 [salt.minion      :1711][INFO    ][28596] Returning information for job: 20190508085359036238
2019-05-08 08:53:59,995 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.05418491s left)
2019-05-08 08:54:29,096 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085429083680
2019-05-08 08:54:29,118 [salt.minion      :1432][INFO    ][28735] Starting a new job with PID 28735
2019-05-08 08:54:29,143 [salt.minion      :1711][INFO    ][28735] Returning information for job: 20190508085429083680
2019-05-08 08:54:32,794 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.25490403s left)
2019-05-08 08:54:59,146 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085459134661
2019-05-08 08:54:59,169 [salt.minion      :1432][INFO    ][28902] Starting a new job with PID 28902
2019-05-08 08:54:59,192 [salt.minion      :1711][INFO    ][28902] Returning information for job: 20190508085459134661
2019-05-08 08:55:06,077 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.97237802s left)
2019-05-08 08:55:29,197 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085529184534
2019-05-08 08:55:29,220 [salt.minion      :1432][INFO    ][29559] Starting a new job with PID 29559
2019-05-08 08:55:29,243 [salt.minion      :1711][INFO    ][29559] Returning information for job: 20190508085529184534
2019-05-08 08:55:39,111 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.93816209s left)
2019-05-08 08:55:59,247 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085559233979
2019-05-08 08:55:59,270 [salt.minion      :1432][INFO    ][29580] Starting a new job with PID 29580
2019-05-08 08:55:59,294 [salt.minion      :1711][INFO    ][29580] Returning information for job: 20190508085559233979
2019-05-08 08:56:12,999 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.05065989s left)
2019-05-08 08:56:29,310 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085629297929
2019-05-08 08:56:29,333 [salt.minion      :1432][INFO    ][29856] Starting a new job with PID 29856
2019-05-08 08:56:29,356 [salt.minion      :1711][INFO    ][29856] Returning information for job: 20190508085629297929
2019-05-08 08:56:45,687 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.36255312s left)
2019-05-08 08:56:59,367 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085659355610
2019-05-08 08:56:59,390 [salt.minion      :1432][INFO    ][29887] Starting a new job with PID 29887
2019-05-08 08:56:59,413 [salt.minion      :1711][INFO    ][29887] Returning information for job: 20190508085659355610
2019-05-08 08:57:18,910 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1980.13935208s left)
2019-05-08 08:57:29,436 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085729422577
2019-05-08 08:57:29,459 [salt.minion      :1432][INFO    ][30368] Starting a new job with PID 30368
2019-05-08 08:57:29,482 [salt.minion      :1711][INFO    ][30368] Returning information for job: 20190508085729422577
2019-05-08 08:57:51,910 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1947.13927603s left)
2019-05-08 08:57:59,506 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085759493543
2019-05-08 08:57:59,528 [salt.minion      :1432][INFO    ][30395] Starting a new job with PID 30395
2019-05-08 08:57:59,552 [salt.minion      :1711][INFO    ][30395] Returning information for job: 20190508085759493543
2019-05-08 08:58:25,426 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.623209s left)
2019-05-08 08:58:29,580 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085829568271
2019-05-08 08:58:29,604 [salt.minion      :1432][INFO    ][30931] Starting a new job with PID 30931
2019-05-08 08:58:29,628 [salt.minion      :1711][INFO    ][30931] Returning information for job: 20190508085829568271
2019-05-08 08:58:58,977 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1880.07255411s left)
2019-05-08 08:58:59,661 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085859649083
2019-05-08 08:58:59,684 [salt.minion      :1432][INFO    ][30952] Starting a new job with PID 30952
2019-05-08 08:58:59,706 [salt.minion      :1711][INFO    ][30952] Returning information for job: 20190508085859649083
2019-05-08 08:59:29,742 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085929729707
2019-05-08 08:59:29,766 [salt.minion      :1432][INFO    ][31009] Starting a new job with PID 31009
2019-05-08 08:59:29,790 [salt.minion      :1711][INFO    ][31009] Returning information for job: 20190508085929729707
2019-05-08 08:59:32,439 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.61069703s left)
2019-05-08 08:59:59,836 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508085959823598
2019-05-08 08:59:59,852 [salt.minion      :1432][INFO    ][31160] Starting a new job with PID 31160
2019-05-08 08:59:59,864 [salt.minion      :1711][INFO    ][31160] Returning information for job: 20190508085959823598
2019-05-08 09:00:05,969 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01', 'kvm03']
sleep for:30s Timeout:2250s (1813.07973909s left)
2019-05-08 09:00:30,048 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090030035915
2019-05-08 09:00:30,070 [salt.minion      :1432][INFO    ][31489] Starting a new job with PID 31489
2019-05-08 09:00:30,094 [salt.minion      :1711][INFO    ][31489] Returning information for job: 20190508090030035915
2019-05-08 09:00:39,381 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1779.66786599s left)
2019-05-08 09:01:00,149 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090100136920
2019-05-08 09:01:00,171 [salt.minion      :1432][INFO    ][31511] Starting a new job with PID 31511
2019-05-08 09:01:00,202 [salt.minion      :1711][INFO    ][31511] Returning information for job: 20190508090100136920
2019-05-08 09:01:12,361 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1746.68861294s left)
2019-05-08 09:01:30,268 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090130254634
2019-05-08 09:01:30,290 [salt.minion      :1432][INFO    ][31820] Starting a new job with PID 31820
2019-05-08 09:01:30,314 [salt.minion      :1711][INFO    ][31820] Returning information for job: 20190508090130254634
2019-05-08 09:01:45,841 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1713.20781803s left)
2019-05-08 09:02:00,385 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090200372232
2019-05-08 09:02:00,405 [salt.minion      :1432][INFO    ][31850] Starting a new job with PID 31850
2019-05-08 09:02:00,428 [salt.minion      :1711][INFO    ][31850] Returning information for job: 20190508090200372232
2019-05-08 09:02:19,351 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1679.69871807s left)
2019-05-08 09:02:30,506 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090230494949
2019-05-08 09:02:30,529 [salt.minion      :1432][INFO    ][31897] Starting a new job with PID 31897
2019-05-08 09:02:30,548 [salt.minion      :1711][INFO    ][31897] Returning information for job: 20190508090230494949
2019-05-08 09:02:52,938 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1646.11090493s left)
2019-05-08 09:03:00,637 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090300624795
2019-05-08 09:03:00,661 [salt.minion      :1432][INFO    ][31928] Starting a new job with PID 31928
2019-05-08 09:03:00,684 [salt.minion      :1711][INFO    ][31928] Returning information for job: 20190508090300624795
2019-05-08 09:03:26,533 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1612.51641393s left)
2019-05-08 09:03:30,785 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090330771954
2019-05-08 09:03:30,807 [salt.minion      :1432][INFO    ][31975] Starting a new job with PID 31975
2019-05-08 09:03:30,831 [salt.minion      :1711][INFO    ][31975] Returning information for job: 20190508090330771954
2019-05-08 09:04:00,297 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1578.75229406s left)
2019-05-08 09:04:00,939 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090400926578
2019-05-08 09:04:00,962 [salt.minion      :1432][INFO    ][32011] Starting a new job with PID 32011
2019-05-08 09:04:00,986 [salt.minion      :1711][INFO    ][32011] Returning information for job: 20190508090400926578
2019-05-08 09:04:31,099 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090431089859
2019-05-08 09:04:31,120 [salt.minion      :1432][INFO    ][32060] Starting a new job with PID 32060
2019-05-08 09:04:31,142 [salt.minion      :1711][INFO    ][32060] Returning information for job: 20190508090431089859
2019-05-08 09:04:33,990 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1545.05959702s left)
2019-05-08 09:05:01,272 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090501260533
2019-05-08 09:05:01,295 [salt.minion      :1432][INFO    ][32094] Starting a new job with PID 32094
2019-05-08 09:05:01,318 [salt.minion      :1711][INFO    ][32094] Returning information for job: 20190508090501260533
2019-05-08 09:05:07,681 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1511.36826611s left)
2019-05-08 09:05:31,451 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090531439509
2019-05-08 09:05:31,474 [salt.minion      :1432][INFO    ][32142] Starting a new job with PID 32142
2019-05-08 09:05:31,499 [salt.minion      :1711][INFO    ][32142] Returning information for job: 20190508090531439509
2019-05-08 09:05:41,249 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1477.80040693s left)
2019-05-08 09:06:01,640 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090601628046
2019-05-08 09:06:01,663 [salt.minion      :1432][INFO    ][32297] Starting a new job with PID 32297
2019-05-08 09:06:01,687 [salt.minion      :1711][INFO    ][32297] Returning information for job: 20190508090601628046
2019-05-08 09:06:14,979 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1444.06983995s left)
2019-05-08 09:06:31,838 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090631825314
2019-05-08 09:06:31,860 [salt.minion      :1432][INFO    ][32347] Starting a new job with PID 32347
2019-05-08 09:06:31,883 [salt.minion      :1711][INFO    ][32347] Returning information for job: 20190508090631825314
2019-05-08 09:06:48,446 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1410.60276413s left)
2019-05-08 09:07:02,046 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090702033137
2019-05-08 09:07:02,069 [salt.minion      :1432][INFO    ][32377] Starting a new job with PID 32377
2019-05-08 09:07:02,092 [salt.minion      :1711][INFO    ][32377] Returning information for job: 20190508090702033137
2019-05-08 09:07:21,958 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1377.09174395s left)
2019-05-08 09:07:32,262 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090732250179
2019-05-08 09:07:32,284 [salt.minion      :1432][INFO    ][32426] Starting a new job with PID 32426
2019-05-08 09:07:32,309 [salt.minion      :1711][INFO    ][32426] Returning information for job: 20190508090732250179
2019-05-08 09:07:55,414 [salt.loaded.ext.module.maas:1023][INFO    ][28492] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1343.63509798s left)
2019-05-08 09:08:02,282 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090802269418
2019-05-08 09:08:02,306 [salt.minion      :1432][INFO    ][32459] Starting a new job with PID 32459
2019-05-08 09:08:02,328 [salt.minion      :1711][INFO    ][32459] Returning information for job: 20190508090802269418
2019-05-08 09:08:27,551 [salt.loaded.ext.module.maas:993 ][INFO    ][28492] Machine hwrdwc mark broken
2019-05-08 09:08:28,316 [salt.loaded.ext.module.maas:996 ][INFO    ][28492] Machine hwrdwc mark fixed
2019-05-08 09:08:29,169 [salt.loaded.ext.module.maas:684 ][INFO    ][28492] deploymachines hwe_kernel=hwe-16.04 system_id=hwrdwc distro_series=xenial
2019-05-08 09:08:31,376 [salt.loaded.ext.module.maas:160 ][ERROR   ][28492] Failed for object kvm01 reason Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node.
2019-05-08 09:08:31,378 [salt.state       :302 ][ERROR   ][28492] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm03', 'kvm02'], 'errors': {'kvm01': "Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node."}, 'success': []}
2019-05-08 09:08:31,378 [salt.state       :1951][INFO    ][28492] Completed state [maas.wait_for_machine_status] at time 09:08:31.378845 duration_in_ms=942339.961
2019-05-08 09:08:31,385 [salt.minion      :1711][INFO    ][28492] Returning information for job: 20190508085243798789
2019-05-08 09:08:42,083 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command pillar.get with jid 20190508090842069317
2019-05-08 09:08:42,101 [salt.minion      :1432][INFO    ][32582] Starting a new job with PID 32582
2019-05-08 09:08:42,106 [salt.minion      :1711][INFO    ][32582] Returning information for job: 20190508090842069317
2019-05-08 09:08:42,587 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command service.status with jid 20190508090842572225
2019-05-08 09:08:42,607 [salt.minion      :1432][INFO    ][32587] Starting a new job with PID 32587
2019-05-08 09:08:42,984 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][32587] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-08 09:08:43,017 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][32587] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-08 09:08:43,032 [salt.minion      :1711][INFO    ][32587] Returning information for job: 20190508090842572225
2019-05-08 09:08:43,581 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508090843569031
2019-05-08 09:08:43,601 [salt.minion      :1432][INFO    ][32598] Starting a new job with PID 32598
2019-05-08 09:08:47,145 [salt.state       :915 ][INFO    ][32598] Loading fresh modules for state activity
2019-05-08 09:08:47,555 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command 'salt-minion --version' in directory '/root'
2019-05-08 09:08:47,918 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command 'salt-minion --version' in directory '/root'
2019-05-08 09:08:48,783 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command 'salt-minion --version' in directory '/root'
2019-05-08 09:08:49,034 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command 'salt-minion --version' in directory '/root'
2019-05-08 09:08:50,396 [salt.state       :1780][INFO    ][32598] Running state [salt-minion] at time 09:08:50.396180
2019-05-08 09:08:50,396 [salt.state       :1813][INFO    ][32598] Executing state pkg.installed for [salt-minion]
2019-05-08 09:08:50,396 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-08 09:08:50,491 [salt.state       :300 ][INFO    ][32598] All specified packages are already installed
2019-05-08 09:08:50,492 [salt.state       :1951][INFO    ][32598] Completed state [salt-minion] at time 09:08:50.491956 duration_in_ms=95.775
2019-05-08 09:08:50,492 [salt.state       :1780][INFO    ][32598] Running state [salt_minion_dependency_packages] at time 09:08:50.492351
2019-05-08 09:08:50,492 [salt.state       :1813][INFO    ][32598] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-08 09:08:50,500 [salt.state       :300 ][INFO    ][32598] All specified packages are already installed
2019-05-08 09:08:50,500 [salt.state       :1951][INFO    ][32598] Completed state [salt_minion_dependency_packages] at time 09:08:50.500547 duration_in_ms=8.196
2019-05-08 09:08:50,504 [salt.state       :1780][INFO    ][32598] Running state [/etc/salt/minion.d/minion.conf] at time 09:08:50.504195
2019-05-08 09:08:50,504 [salt.state       :1813][INFO    ][32598] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-08 09:08:50,701 [salt.state       :300 ][INFO    ][32598] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-08 09:08:50,701 [salt.state       :1951][INFO    ][32598] Completed state [/etc/salt/minion.d/minion.conf] at time 09:08:50.701948 duration_in_ms=197.753
2019-05-08 09:08:50,702 [salt.state       :1780][INFO    ][32598] Running state [python-netaddr] at time 09:08:50.702129
2019-05-08 09:08:50,702 [salt.state       :1813][INFO    ][32598] Executing state pkg.installed for [python-netaddr]
2019-05-08 09:08:50,706 [salt.state       :300 ][INFO    ][32598] All specified packages are already installed
2019-05-08 09:08:50,706 [salt.state       :1951][INFO    ][32598] Completed state [python-netaddr] at time 09:08:50.706732 duration_in_ms=4.602
2019-05-08 09:08:50,708 [salt.state       :1780][INFO    ][32598] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 09:08:50.708739
2019-05-08 09:08:50,708 [salt.state       :1813][INFO    ][32598] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-08 09:08:50,717 [salt.state       :300 ][INFO    ][32598] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-08 09:08:50,717 [salt.state       :1951][INFO    ][32598] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 09:08:50.717641 duration_in_ms=8.902
2019-05-08 09:08:50,718 [salt.state       :1780][INFO    ][32598] Running state [salt-minion] at time 09:08:50.718262
2019-05-08 09:08:50,718 [salt.state       :1813][INFO    ][32598] Executing state service.running for [salt-minion]
2019-05-08 09:08:50,718 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-08 09:08:50,754 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-08 09:08:50,771 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-08 09:08:50,787 [salt.state       :300 ][INFO    ][32598] The service salt-minion is already running
2019-05-08 09:08:50,787 [salt.state       :1951][INFO    ][32598] Completed state [salt-minion] at time 09:08:50.787590 duration_in_ms=69.327
2019-05-08 09:08:50,789 [salt.state       :1780][INFO    ][32598] Running state [/etc/salt/grains.d] at time 09:08:50.789071
2019-05-08 09:08:50,789 [salt.state       :1813][INFO    ][32598] Executing state file.directory for [/etc/salt/grains.d]
2019-05-08 09:08:50,790 [salt.state       :300 ][INFO    ][32598] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-08 09:08:50,790 [salt.state       :1951][INFO    ][32598] Completed state [/etc/salt/grains.d] at time 09:08:50.790561 duration_in_ms=1.49
2019-05-08 09:08:50,791 [salt.state       :1780][INFO    ][32598] Running state [/etc/salt/grains] at time 09:08:50.791221
2019-05-08 09:08:50,791 [salt.state       :1813][INFO    ][32598] Executing state file.managed for [/etc/salt/grains]
2019-05-08 09:08:50,792 [salt.state       :300 ][INFO    ][32598] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-08 09:08:50,792 [salt.state       :1951][INFO    ][32598] Completed state [/etc/salt/grains] at time 09:08:50.792282 duration_in_ms=1.061
2019-05-08 09:08:50,792 [salt.state       :1780][INFO    ][32598] Running state [/etc/salt/grains.d/placeholder] at time 09:08:50.792742
2019-05-08 09:08:50,793 [salt.state       :1813][INFO    ][32598] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-08 09:08:50,793 [salt.state       :300 ][INFO    ][32598] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-08 09:08:50,793 [salt.state       :1951][INFO    ][32598] Completed state [/etc/salt/grains.d/placeholder] at time 09:08:50.793753 duration_in_ms=1.011
2019-05-08 09:08:50,794 [salt.state       :1780][INFO    ][32598] Running state [/etc/salt/grains.d/sphinx] at time 09:08:50.794199
2019-05-08 09:08:50,794 [salt.state       :1813][INFO    ][32598] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-08 09:08:50,803 [salt.state       :300 ][INFO    ][32598] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-08 09:08:50,803 [salt.state       :1951][INFO    ][32598] Completed state [/etc/salt/grains.d/sphinx] at time 09:08:50.803835 duration_in_ms=9.636
2019-05-08 09:08:50,806 [salt.state       :1780][INFO    ][32598] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 09:08:50.806059
2019-05-08 09:08:50,806 [salt.state       :1813][INFO    ][32598] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-08 09:08:50,806 [salt.state       :300 ][INFO    ][32598] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-08 09:08:50,806 [salt.state       :1951][INFO    ][32598] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 09:08:50.806942 duration_in_ms=0.884
2019-05-08 09:08:50,807 [salt.state       :1780][INFO    ][32598] Running state [/etc/salt/grains.d/dns_records] at time 09:08:50.807410
2019-05-08 09:08:50,807 [salt.state       :1813][INFO    ][32598] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-08 09:08:50,815 [salt.state       :300 ][INFO    ][32598] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-08 09:08:50,815 [salt.state       :1951][INFO    ][32598] Completed state [/etc/salt/grains.d/dns_records] at time 09:08:50.815703 duration_in_ms=8.293
2019-05-08 09:08:50,816 [salt.state       :1780][INFO    ][32598] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 09:08:50.816622
2019-05-08 09:08:50,816 [salt.state       :1813][INFO    ][32598] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-08 09:08:50,817 [salt.state       :300 ][INFO    ][32598] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-08 09:08:50,817 [salt.state       :1951][INFO    ][32598] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 09:08:50.817474 duration_in_ms=0.852
2019-05-08 09:08:50,818 [salt.state       :1780][INFO    ][32598] Running state [/etc/salt/grains.d/salt] at time 09:08:50.817968
2019-05-08 09:08:50,818 [salt.state       :1813][INFO    ][32598] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-08 09:08:50,827 [salt.state       :300 ][INFO    ][32598] File /etc/salt/grains.d/salt is in the correct state
2019-05-08 09:08:50,827 [salt.state       :1951][INFO    ][32598] Completed state [/etc/salt/grains.d/salt] at time 09:08:50.827604 duration_in_ms=9.635
2019-05-08 09:08:50,828 [salt.state       :1780][INFO    ][32598] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 09:08:50.828457
2019-05-08 09:08:50,828 [salt.state       :1813][INFO    ][32598] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-08 09:08:50,829 [salt.state       :300 ][INFO    ][32598] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-08 09:08:50,829 [salt.state       :1951][INFO    ][32598] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 09:08:50.829308 duration_in_ms=0.851
2019-05-08 09:08:50,831 [salt.state       :1780][INFO    ][32598] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 09:08:50.831173
2019-05-08 09:08:50,831 [salt.state       :1813][INFO    ][32598] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-08 09:08:50,831 [salt.state       :300 ][INFO    ][32598] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-08 09:08:50,832 [salt.state       :1951][INFO    ][32598] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 09:08:50.832052 duration_in_ms=0.878
2019-05-08 09:08:50,832 [salt.state       :1780][INFO    ][32598] Running state [mine.update] at time 09:08:50.832726
2019-05-08 09:08:50,833 [salt.state       :1813][INFO    ][32598] Executing state module.wait for [mine.update]
2019-05-08 09:08:50,833 [salt.state       :300 ][INFO    ][32598] No changes made for mine.update
2019-05-08 09:08:50,833 [salt.state       :1951][INFO    ][32598] Completed state [mine.update] at time 09:08:50.833533 duration_in_ms=0.807
2019-05-08 09:08:50,833 [salt.state       :1780][INFO    ][32598] Running state [ca-certificates] at time 09:08:50.833786
2019-05-08 09:08:50,834 [salt.state       :1813][INFO    ][32598] Executing state pkg.installed for [ca-certificates]
2019-05-08 09:08:50,841 [salt.state       :300 ][INFO    ][32598] All specified packages are already installed
2019-05-08 09:08:50,841 [salt.state       :1951][INFO    ][32598] Completed state [ca-certificates] at time 09:08:50.841460 duration_in_ms=7.674
2019-05-08 09:08:50,842 [salt.state       :1780][INFO    ][32598] Running state [update-ca-certificates] at time 09:08:50.842141
2019-05-08 09:08:50,842 [salt.state       :1813][INFO    ][32598] Executing state cmd.wait for [update-ca-certificates]
2019-05-08 09:08:50,842 [salt.state       :300 ][INFO    ][32598] No changes made for update-ca-certificates
2019-05-08 09:08:50,842 [salt.state       :1951][INFO    ][32598] Completed state [update-ca-certificates] at time 09:08:50.842935 duration_in_ms=0.794
2019-05-08 09:08:50,843 [salt.state       :1780][INFO    ][32598] Running state [iptables] at time 09:08:50.843168
2019-05-08 09:08:50,843 [salt.state       :1813][INFO    ][32598] Executing state pkg.installed for [iptables]
2019-05-08 09:08:50,850 [salt.state       :300 ][INFO    ][32598] All specified packages are already installed
2019-05-08 09:08:50,850 [salt.state       :1951][INFO    ][32598] Completed state [iptables] at time 09:08:50.850227 duration_in_ms=7.059
2019-05-08 09:08:50,850 [salt.state       :1780][INFO    ][32598] Running state [iptables-persistent] at time 09:08:50.850463
2019-05-08 09:08:50,850 [salt.state       :1813][INFO    ][32598] Executing state pkg.installed for [iptables-persistent]
2019-05-08 09:08:50,857 [salt.state       :300 ][INFO    ][32598] All specified packages are already installed
2019-05-08 09:08:50,857 [salt.state       :1951][INFO    ][32598] Completed state [iptables-persistent] at time 09:08:50.857277 duration_in_ms=6.814
2019-05-08 09:08:50,858 [salt.state       :1780][INFO    ][32598] Running state [iptables_modules_v4_load] at time 09:08:50.858222
2019-05-08 09:08:50,858 [salt.state       :1813][INFO    ][32598] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-08 09:08:50,859 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command 'lsmod' in directory '/root'
2019-05-08 09:08:50,881 [salt.state       :300 ][INFO    ][32598] Kernel modules iptable_filter, ip_tables are already present
2019-05-08 09:08:50,881 [salt.state       :1951][INFO    ][32598] Completed state [iptables_modules_v4_load] at time 09:08:50.881840 duration_in_ms=23.618
2019-05-08 09:08:50,882 [salt.state       :1780][INFO    ][32598] Running state [/etc/iptables/rules.v4] at time 09:08:50.882426
2019-05-08 09:08:50,882 [salt.state       :1813][INFO    ][32598] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-08 09:08:50,965 [salt.state       :300 ][INFO    ][32598] File /etc/iptables/rules.v4 is in the correct state
2019-05-08 09:08:50,965 [salt.state       :1951][INFO    ][32598] Completed state [/etc/iptables/rules.v4] at time 09:08:50.965470 duration_in_ms=83.044
2019-05-08 09:08:50,966 [salt.state       :1780][INFO    ][32598] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 09:08:50.966355
2019-05-08 09:08:50,966 [salt.state       :1813][INFO    ][32598] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-08 09:08:50,967 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-08 09:08:50,987 [salt.state       :300 ][INFO    ][32598] onlyif execution failed
2019-05-08 09:08:50,987 [salt.state       :1951][INFO    ][32598] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 09:08:50.987550 duration_in_ms=21.195
2019-05-08 09:08:50,988 [salt.state       :1780][INFO    ][32598] Running state [netfilter-persistent] at time 09:08:50.988334
2019-05-08 09:08:50,988 [salt.state       :1813][INFO    ][32598] Executing state service.running for [netfilter-persistent]
2019-05-08 09:08:50,989 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-08 09:08:51,008 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-08 09:08:51,025 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-08 09:08:51,042 [salt.state       :300 ][INFO    ][32598] The service netfilter-persistent is already running
2019-05-08 09:08:51,043 [salt.state       :1951][INFO    ][32598] Completed state [netfilter-persistent] at time 09:08:51.043090 duration_in_ms=54.756
2019-05-08 09:08:51,043 [salt.state       :1780][INFO    ][32598] Running state [iptables_extra.remove_stale_tables] at time 09:08:51.043882
2019-05-08 09:08:51,044 [salt.state       :1813][INFO    ][32598] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-08 09:08:51,044 [salt.state       :300 ][INFO    ][32598] No changes made for iptables_extra.remove_stale_tables
2019-05-08 09:08:51,044 [salt.state       :1951][INFO    ][32598] Completed state [iptables_extra.remove_stale_tables] at time 09:08:51.044788 duration_in_ms=0.906
2019-05-08 09:08:51,045 [salt.state       :1780][INFO    ][32598] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 09:08:51.045038
2019-05-08 09:08:51,045 [salt.state       :1813][INFO    ][32598] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-08 09:08:51,045 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32598] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-08 09:08:51,060 [salt.state       :300 ][INFO    ][32598] onlyif execution failed
2019-05-08 09:08:51,061 [salt.state       :1951][INFO    ][32598] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 09:08:51.061083 duration_in_ms=16.045
2019-05-08 09:08:51,062 [salt.state       :1780][INFO    ][32598] Running state [/etc/iptables/rules.v6] at time 09:08:51.062338
2019-05-08 09:08:51,062 [salt.state       :1813][INFO    ][32598] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-08 09:08:51,063 [salt.state       :300 ][INFO    ][32598] File /etc/iptables/rules.v6 is not present
2019-05-08 09:08:51,063 [salt.state       :1951][INFO    ][32598] Completed state [/etc/iptables/rules.v6] at time 09:08:51.063668 duration_in_ms=1.329
2019-05-08 09:08:51,064 [salt.state       :1780][INFO    ][32598] Running state [iptables_extra.flush_all] at time 09:08:51.064553
2019-05-08 09:08:51,064 [salt.state       :1813][INFO    ][32598] Executing state module.wait for [iptables_extra.flush_all]
2019-05-08 09:08:51,065 [salt.state       :300 ][INFO    ][32598] No changes made for iptables_extra.flush_all
2019-05-08 09:08:51,065 [salt.state       :1951][INFO    ][32598] Completed state [iptables_extra.flush_all] at time 09:08:51.065599 duration_in_ms=1.046
2019-05-08 09:08:51,069 [salt.minion      :1711][INFO    ][32598] Returning information for job: 20190508090843569031
2019-05-08 09:08:51,652 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508090851642567
2019-05-08 09:08:51,670 [salt.minion      :1432][INFO    ][32677] Starting a new job with PID 32677
2019-05-08 09:08:52,438 [salt.state       :915 ][INFO    ][32677] Loading fresh modules for state activity
2019-05-08 09:08:53,044 [salt.state       :1780][INFO    ][32677] Running state [maas-rack-controller] at time 09:08:53.044885
2019-05-08 09:08:53,045 [salt.state       :1813][INFO    ][32677] Executing state pkg.installed for [maas-rack-controller]
2019-05-08 09:08:53,045 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32677] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-08 09:08:53,147 [salt.state       :300 ][INFO    ][32677] All specified packages are already installed
2019-05-08 09:08:53,148 [salt.state       :1951][INFO    ][32677] Completed state [maas-rack-controller] at time 09:08:53.148154 duration_in_ms=103.269
2019-05-08 09:08:53,148 [salt.state       :1780][INFO    ][32677] Running state [ipmitool] at time 09:08:53.148511
2019-05-08 09:08:53,148 [salt.state       :1813][INFO    ][32677] Executing state pkg.installed for [ipmitool]
2019-05-08 09:08:53,155 [salt.state       :300 ][INFO    ][32677] All specified packages are already installed
2019-05-08 09:08:53,155 [salt.state       :1951][INFO    ][32677] Completed state [ipmitool] at time 09:08:53.155595 duration_in_ms=7.084
2019-05-08 09:08:53,158 [salt.state       :1780][INFO    ][32677] Running state [/etc/maas/rackd.conf] at time 09:08:53.158704
2019-05-08 09:08:53,159 [salt.state       :1813][INFO    ][32677] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-08 09:08:53,160 [salt.state       :300 ][INFO    ][32677] No changes needed to be made
2019-05-08 09:08:53,160 [salt.state       :1951][INFO    ][32677] Completed state [/etc/maas/rackd.conf] at time 09:08:53.160264 duration_in_ms=1.56
2019-05-08 09:08:53,160 [salt.state       :1780][INFO    ][32677] Running state [/etc/maas/rackd.conf] at time 09:08:53.160517
2019-05-08 09:08:53,160 [salt.state       :1813][INFO    ][32677] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-08 09:08:53,161 [salt.loaded.int.states.file:2298][WARNING ][32677] 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-05-08 09:08:53,161 [salt.state       :300 ][INFO    ][32677] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-08 09:08:53,161 [salt.state       :1951][INFO    ][32677] Completed state [/etc/maas/rackd.conf] at time 09:08:53.161804 duration_in_ms=1.287
2019-05-08 09:08:53,162 [salt.state       :1780][INFO    ][32677] Running state [maas-rackd] at time 09:08:53.162770
2019-05-08 09:08:53,163 [salt.state       :1813][INFO    ][32677] Executing state service.running for [maas-rackd]
2019-05-08 09:08:53,163 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32677] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-08 09:08:53,197 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32677] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-08 09:08:53,214 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32677] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-08 09:08:53,231 [salt.state       :300 ][INFO    ][32677] The service maas-rackd is already running
2019-05-08 09:08:53,232 [salt.state       :1951][INFO    ][32677] Completed state [maas-rackd] at time 09:08:53.232027 duration_in_ms=69.257
2019-05-08 09:08:53,233 [salt.minion      :1711][INFO    ][32677] Returning information for job: 20190508090851642567
2019-05-08 09:08:53,822 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508090853808394
2019-05-08 09:08:53,844 [salt.minion      :1432][INFO    ][32700] Starting a new job with PID 32700
2019-05-08 09:08:54,589 [salt.state       :915 ][INFO    ][32700] Loading fresh modules for state activity
2019-05-08 09:08:55,252 [salt.state       :1780][INFO    ][32700] Running state [maas-region-controller] at time 09:08:55.252314
2019-05-08 09:08:55,252 [salt.state       :1813][INFO    ][32700] Executing state pkg.installed for [maas-region-controller]
2019-05-08 09:08:55,253 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-08 09:08:55,354 [salt.state       :300 ][INFO    ][32700] All specified packages are already installed
2019-05-08 09:08:55,354 [salt.state       :1951][INFO    ][32700] Completed state [maas-region-controller] at time 09:08:55.354848 duration_in_ms=102.533
2019-05-08 09:08:55,355 [salt.state       :1780][INFO    ][32700] Running state [python-oauth] at time 09:08:55.355246
2019-05-08 09:08:55,355 [salt.state       :1813][INFO    ][32700] Executing state pkg.installed for [python-oauth]
2019-05-08 09:08:55,363 [salt.state       :300 ][INFO    ][32700] All specified packages are already installed
2019-05-08 09:08:55,363 [salt.state       :1951][INFO    ][32700] Completed state [python-oauth] at time 09:08:55.363781 duration_in_ms=8.535
2019-05-08 09:08:55,367 [salt.state       :1780][INFO    ][32700] Running state [/etc/maas/regiond.conf] at time 09:08:55.367440
2019-05-08 09:08:55,367 [salt.state       :1813][INFO    ][32700] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-08 09:08:55,385 [salt.state       :300 ][INFO    ][32700] No changes needed to be made
2019-05-08 09:08:55,385 [salt.state       :1951][INFO    ][32700] Completed state [/etc/maas/regiond.conf] at time 09:08:55.385583 duration_in_ms=18.142
2019-05-08 09:08:55,386 [salt.state       :1780][INFO    ][32700] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:08:55.386108
2019-05-08 09:08:55,386 [salt.state       :1813][INFO    ][32700] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-08 09:08:55,450 [salt.state       :300 ][INFO    ][32700] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-08 09:08:55,450 [salt.state       :1951][INFO    ][32700] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:08:55.450837 duration_in_ms=64.729
2019-05-08 09:08:55,451 [salt.state       :1780][INFO    ][32700] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:08:55.451327
2019-05-08 09:08:55,451 [salt.state       :1813][INFO    ][32700] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-08 09:08:55,463 [salt.state       :300 ][INFO    ][32700] No changes needed to be made
2019-05-08 09:08:55,464 [salt.state       :1951][INFO    ][32700] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:08:55.464051 duration_in_ms=12.723
2019-05-08 09:08:55,464 [salt.state       :1780][INFO    ][32700] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:08:55.464532
2019-05-08 09:08:55,464 [salt.state       :1813][INFO    ][32700] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-08 09:08:55,524 [salt.state       :300 ][INFO    ][32700] No changes needed to be made
2019-05-08 09:08:55,524 [salt.state       :1951][INFO    ][32700] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:08:55.524787 duration_in_ms=60.253
2019-05-08 09:08:55,525 [salt.state       :1780][INFO    ][32700] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:08:55.525607
2019-05-08 09:08:55,526 [salt.state       :1813][INFO    ][32700] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-08 09:08:55,562 [salt.state       :300 ][INFO    ][32700] No changes needed to be made
2019-05-08 09:08:55,563 [salt.state       :1951][INFO    ][32700] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:08:55.563044 duration_in_ms=37.438
2019-05-08 09:08:55,563 [salt.state       :1780][INFO    ][32700] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:08:55.563731
2019-05-08 09:08:55,564 [salt.state       :1813][INFO    ][32700] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-08 09:08:55,577 [salt.state       :300 ][INFO    ][32700] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-08 09:08:55,577 [salt.state       :1951][INFO    ][32700] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:08:55.577545 duration_in_ms=13.814
2019-05-08 09:08:55,579 [salt.state       :1780][INFO    ][32700] Running state [a2enmod headers] at time 09:08:55.579183
2019-05-08 09:08:55,579 [salt.state       :1813][INFO    ][32700] Executing state cmd.run for [a2enmod headers]
2019-05-08 09:08:55,580 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command 'a2enmod headers' in directory '/root'
2019-05-08 09:08:55,640 [salt.state       :300 ][INFO    ][32700] {'pid': 32719, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-08 09:08:55,641 [salt.state       :1951][INFO    ][32700] Completed state [a2enmod headers] at time 09:08:55.641300 duration_in_ms=62.117
2019-05-08 09:08:55,641 [salt.state       :1780][INFO    ][32700] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:08:55.641779
2019-05-08 09:08:55,642 [salt.state       :1813][INFO    ][32700] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-08 09:08:55,658 [salt.state       :300 ][INFO    ][32700] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-08 09:08:55,658 [salt.state       :1951][INFO    ][32700] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:08:55.658910 duration_in_ms=17.131
2019-05-08 09:08:55,659 [salt.state       :1780][INFO    ][32700] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:08:55.659564
2019-05-08 09:08:55,659 [salt.state       :1813][INFO    ][32700] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-08 09:08:55,732 [salt.state       :300 ][INFO    ][32700] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-08 09:08:55,732 [salt.state       :1951][INFO    ][32700] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:08:55.732861 duration_in_ms=73.298
2019-05-08 09:08:55,733 [salt.state       :1780][INFO    ][32700] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:08:55.733522
2019-05-08 09:08:55,733 [salt.state       :1813][INFO    ][32700] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-08 09:08:55,786 [salt.state       :300 ][INFO    ][32700] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-08 09:08:55,786 [salt.state       :1951][INFO    ][32700] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:08:55.786217 duration_in_ms=52.695
2019-05-08 09:08:55,786 [salt.state       :1780][INFO    ][32700] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:08:55.786630
2019-05-08 09:08:55,786 [salt.state       :1813][INFO    ][32700] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-08 09:08:55,840 [salt.state       :300 ][INFO    ][32700] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-08 09:08:55,840 [salt.state       :1951][INFO    ][32700] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:08:55.840248 duration_in_ms=53.618
2019-05-08 09:08:55,840 [salt.state       :1780][INFO    ][32700] Running state [/root/.pgpass] at time 09:08:55.840472
2019-05-08 09:08:55,840 [salt.state       :1813][INFO    ][32700] Executing state file.managed for [/root/.pgpass]
2019-05-08 09:08:55,881 [salt.state       :300 ][INFO    ][32700] File /root/.pgpass is in the correct state
2019-05-08 09:08:55,882 [salt.state       :1951][INFO    ][32700] Completed state [/root/.pgpass] at time 09:08:55.882072 duration_in_ms=41.599
2019-05-08 09:08:55,886 [salt.state       :1780][INFO    ][32700] Running state [maas-region syncdb --noinput] at time 09:08:55.885985
2019-05-08 09:08:55,886 [salt.state       :1813][INFO    ][32700] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-08 09:08:55,886 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-08 09:08:57,805 [salt.state       :300 ][INFO    ][32700] {'pid': 32732, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: metadataserver, sites, maasserver, auth, contenttypes, piston3, sessions\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-08 09:08:57,805 [salt.state       :1951][INFO    ][32700] Completed state [maas-region syncdb --noinput] at time 09:08:57.805886 duration_in_ms=1919.901
2019-05-08 09:08:57,806 [salt.state       :2022][WARNING ][32700] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-08 09:08:57,807 [salt.state       :1780][INFO    ][32700] Running state [maas-regiond] at time 09:08:57.807074
2019-05-08 09:08:57,807 [salt.state       :1813][INFO    ][32700] Executing state service.running for [maas-regiond]
2019-05-08 09:08:57,807 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-08 09:08:57,839 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-08 09:08:57,852 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-08 09:08:57,868 [salt.state       :300 ][INFO    ][32700] The service maas-regiond is already running
2019-05-08 09:08:57,869 [salt.state       :1951][INFO    ][32700] Completed state [maas-regiond] at time 09:08:57.869270 duration_in_ms=62.195
2019-05-08 09:08:57,871 [salt.state       :1780][INFO    ][32700] Running state [bind9] at time 09:08:57.871723
2019-05-08 09:08:57,872 [salt.state       :1813][INFO    ][32700] Executing state service.running for [bind9]
2019-05-08 09:08:57,873 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-08 09:08:57,890 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-08 09:08:57,906 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-08 09:08:57,924 [salt.state       :300 ][INFO    ][32700] The service bind9 is already running
2019-05-08 09:08:57,925 [salt.state       :1951][INFO    ][32700] Completed state [bind9] at time 09:08:57.925244 duration_in_ms=53.522
2019-05-08 09:08:57,927 [salt.state       :1780][INFO    ][32700] Running state [apache2] at time 09:08:57.927869
2019-05-08 09:08:57,928 [salt.state       :1813][INFO    ][32700] Executing state service.running for [apache2]
2019-05-08 09:08:57,929 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-08 09:08:57,948 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-08 09:08:57,962 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-08 09:08:57,983 [salt.state       :300 ][INFO    ][32700] The service apache2 is already running
2019-05-08 09:08:57,984 [salt.state       :1951][INFO    ][32700] Completed state [apache2] at time 09:08:57.984394 duration_in_ms=56.525
2019-05-08 09:08:57,986 [salt.state       :1780][INFO    ][32700] Running state [maasng.wait_for_http_code] at time 09:08:57.986224
2019-05-08 09:08:57,986 [salt.state       :1813][INFO    ][32700] Executing state module.run for [maasng.wait_for_http_code]
2019-05-08 09:08:57,987 [salt.utils.decorators:613 ][WARNING ][32700] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 09:08:58,089 [salt.state       :300 ][INFO    ][32700] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-08 09:08:58,090 [salt.state       :1951][INFO    ][32700] Completed state [maasng.wait_for_http_code] at time 09:08:58.090137 duration_in_ms=103.911
2019-05-08 09:08:58,091 [salt.state       :1780][INFO    ][32700] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:08:58.091025
2019-05-08 09:08:58,091 [salt.state       :1813][INFO    ][32700] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-08 09:08:58,091 [salt.state       :300 ][INFO    ][32700] /var/lib/maas/.setup_admin exists
2019-05-08 09:08:58,092 [salt.state       :1951][INFO    ][32700] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:08:58.092033 duration_in_ms=1.007
2019-05-08 09:08:58,092 [salt.state       :1780][INFO    ][32700] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:08:58.092700
2019-05-08 09:08:58,093 [salt.state       :1813][INFO    ][32700] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 09:08:58,093 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32700] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 09:08:59,449 [salt.state       :300 ][INFO    ][32700] {'pid': 32753, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 09:08:59,449 [salt.state       :1951][INFO    ][32700] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:08:59.449813 duration_in_ms=1357.112
2019-05-08 09:08:59,453 [salt.state       :1780][INFO    ][32700] Running state [maas_region_boot_source_resources_mirror] at time 09:08:59.453216
2019-05-08 09:08:59,453 [salt.state       :1813][INFO    ][32700] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-08 09:08:59,536 [salt.state       :300 ][INFO    ][32700] {'changes': {}}
2019-05-08 09:08:59,537 [salt.state       :1951][INFO    ][32700] Completed state [maas_region_boot_source_resources_mirror] at time 09:08:59.537202 duration_in_ms=83.983
2019-05-08 09:08:59,538 [salt.state       :1780][INFO    ][32700] Running state [maasng.boot_resources_import] at time 09:08:59.538691
2019-05-08 09:08:59,539 [salt.state       :1813][INFO    ][32700] Executing state module.run for [maasng.boot_resources_import]
2019-05-08 09:08:59,540 [salt.utils.decorators:613 ][WARNING ][32700] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 09:08:59,675 [salt.loaded.ext.module.maasng:1600][INFO    ][32700] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-08 09:09:04,743 [salt.loaded.ext.module.maasng:1600][INFO    ][32700] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-08 09:09:08,859 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090908846042
2019-05-08 09:09:08,881 [salt.minion      :1432][INFO    ][354] Starting a new job with PID 354
2019-05-08 09:09:08,902 [salt.minion      :1711][INFO    ][354] Returning information for job: 20190508090908846042
2019-05-08 09:09:09,807 [salt.loaded.ext.module.maasng:1600][INFO    ][32700] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-08 09:09:14,869 [salt.loaded.ext.module.maasng:1600][INFO    ][32700] Waiting boot-resources import done
sleep for:5s Left:885.0/900s
2019-05-08 09:09:19,929 [salt.loaded.ext.module.maasng:1600][INFO    ][32700] Waiting boot-resources import done
sleep for:5s Left:880.0/900s
2019-05-08 09:09:24,994 [salt.loaded.ext.module.maasng:1600][INFO    ][32700] Waiting boot-resources import done
sleep for:5s Left:875.0/900s
2019-05-08 09:09:30,067 [salt.loaded.ext.module.maasng:1600][INFO    ][32700] Waiting boot-resources import done
sleep for:5s Left:870.0/900s
2019-05-08 09:09:35,168 [salt.state       :300 ][INFO    ][32700] {'ret': True}
2019-05-08 09:09:35,169 [salt.state       :1951][INFO    ][32700] Completed state [maasng.boot_resources_import] at time 09:09:35.169059 duration_in_ms=35630.369
2019-05-08 09:09:35,169 [salt.state       :1780][INFO    ][32700] Running state [maas_region_boot_sources_selection_xenial] at time 09:09:35.169517
2019-05-08 09:09:35,169 [salt.state       :1813][INFO    ][32700] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-08 09:09:35,359 [salt.state       :300 ][INFO    ][32700] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-08 09:09:35,359 [salt.state       :1951][INFO    ][32700] Completed state [maas_region_boot_sources_selection_xenial] at time 09:09:35.359474 duration_in_ms=189.955
2019-05-08 09:09:35,361 [salt.state       :1780][INFO    ][32700] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 09:09:35.360949
2019-05-08 09:09:35,361 [salt.state       :1813][INFO    ][32700] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-08 09:09:35,362 [salt.utils.decorators:613 ][WARNING ][32700] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 09:09:35,362 [salt.loaded.ext.module.maasng:1771][INFO    ][32700] boot-sources sync initiated for ALL Rack's
2019-05-08 09:09:36,275 [salt.state       :300 ][INFO    ][32700] {'ret': True}
2019-05-08 09:09:36,275 [salt.state       :1951][INFO    ][32700] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 09:09:36.275754 duration_in_ms=914.806
2019-05-08 09:09:36,276 [salt.state       :1780][INFO    ][32700] Running state [maas.process_maas_config] at time 09:09:36.276650
2019-05-08 09:09:36,276 [salt.state       :1813][INFO    ][32700] Executing state module.run for [maas.process_maas_config]
2019-05-08 09:09:36,277 [salt.utils.decorators:613 ][WARNING ][32700] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 09:09:36,277 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=enable_http_proxy value=True
2019-05-08 09:09:36,332 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=upstream_dns value=8.8.8.8
2019-05-08 09:09:36,389 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=commissioning_distro_series value=xenial
2019-05-08 09:09:38,903 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508090938890709
2019-05-08 09:09:38,926 [salt.minion      :1432][INFO    ][663] Starting a new job with PID 663
2019-05-08 09:09:38,949 [salt.minion      :1711][INFO    ][663] Returning information for job: 20190508090938890709
2019-05-08 09:09:46,033 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=default_osystem value=ubuntu
2019-05-08 09:09:46,084 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=active_discovery_interval value=600
2019-05-08 09:09:46,132 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=dnssec_validation value=no
2019-05-08 09:09:46,186 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=maas_name value=mas01
2019-05-08 09:09:46,241 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=network_discovery value=enabled
2019-05-08 09:09:46,348 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=enable_third_party_drivers value=True
2019-05-08 09:09:46,406 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=default_storage_layout value=lvm
2019-05-08 09:09:46,454 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=ntp_external_only value=True
2019-05-08 09:09:46,502 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-08 09:09:46,556 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=default_distro_series value=xenial
2019-05-08 09:09:46,624 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-08 09:09:46,768 [salt.state       :300 ][INFO    ][32700] {'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-05-08 09:09:46,768 [salt.state       :1951][INFO    ][32700] Completed state [maas.process_maas_config] at time 09:09:46.768659 duration_in_ms=10492.007
2019-05-08 09:09:46,769 [salt.state       :1780][INFO    ][32700] Running state [pxe_admin] at time 09:09:46.769624
2019-05-08 09:09:46,770 [salt.state       :1813][INFO    ][32700] Executing state maasng.fabric_present for [pxe_admin]
2019-05-08 09:09:46,839 [salt.loaded.ext.module.maasng:945 ][INFO    ][32700] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, 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': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, 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': 1}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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/', u'id': 2}]
2019-05-08 09:09:46,911 [salt.loaded.ext.module.maasng:1008][WARNING ][32700] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-08 09:09:46,911 [salt.loaded.ext.module.maasng:1011][WARNING ][32700] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-08 09:09:46,977 [salt.state       :300 ][INFO    ][32700] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-08 09:09:46,977 [salt.state       :1951][INFO    ][32700] Completed state [pxe_admin] at time 09:09:46.977862 duration_in_ms=208.237
2019-05-08 09:09:46,978 [salt.state       :1780][INFO    ][32700] Running state [vlan 0] at time 09:09:46.978315
2019-05-08 09:09:46,978 [salt.state       :1813][INFO    ][32700] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-08 09:09:47,041 [salt.loaded.ext.module.maasng:945 ][INFO    ][32700] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], 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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 09:09:47,154 [salt.loaded.ext.module.maasng:945 ][INFO    ][32700] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, 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': 0}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, 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': 1}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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/', u'id': 2}]
2019-05-08 09:09:47,412 [salt.loaded.ext.module.maasng:945 ][INFO    ][32700] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 09:09:47,515 [salt.state       :300 ][INFO    ][32700] {'new': 'Vlan untagged was updated'}
2019-05-08 09:09:47,515 [salt.state       :1951][INFO    ][32700] Completed state [vlan 0] at time 09:09:47.515865 duration_in_ms=537.549
2019-05-08 09:09:47,517 [salt.state       :1780][INFO    ][32700] Running state [192.168.11.0/24] at time 09:09:47.517375
2019-05-08 09:09:47,517 [salt.state       :1813][INFO    ][32700] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-08 09:09:47,714 [salt.loaded.ext.module.maasng:945 ][INFO    ][32700] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', 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'external_dhcp': None, u'fabric': u'fabric-0', 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'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', 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'external_dhcp': None, u'fabric': u'fabric-1', 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'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', 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'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'x3tpnw', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-05-08 09:09:47,715 [salt.loaded.ext.module.maasng:1235][WARNING ][32700] Ignoring parameter vlan:0
2019-05-08 09:09:47,798 [salt.state       :300 ][INFO    ][32700] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-08 09:09:47,798 [salt.state       :1951][INFO    ][32700] Completed state [192.168.11.0/24] at time 09:09:47.798864 duration_in_ms=281.489
2019-05-08 09:09:47,800 [salt.state       :1780][INFO    ][32700] Running state [maas_create_iprange_1] at time 09:09:47.800067
2019-05-08 09:09:47,800 [salt.state       :1813][INFO    ][32700] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-08 09:09:47,863 [salt.state       :300 ][INFO    ][32700] Iprange maas_create_iprange_1 already exist.
2019-05-08 09:09:47,864 [salt.state       :1951][INFO    ][32700] Completed state [maas_create_iprange_1] at time 09:09:47.863939 duration_in_ms=63.872
2019-05-08 09:09:47,864 [salt.state       :1780][INFO    ][32700] Running state [vlan 0] at time 09:09:47.864252
2019-05-08 09:09:47,864 [salt.state       :1813][INFO    ][32700] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-08 09:09:47,942 [salt.loaded.ext.module.maasng:945 ][INFO    ][32700] [{u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', 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'external_dhcp': None, u'fabric': u'fabric-0', 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'id': 0, u'name': u'fabric-0', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', 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'external_dhcp': None, u'fabric': u'fabric-1', 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'id': 1, u'name': u'fabric-1', u'class_type': None}, {u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', 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'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'x3tpnw', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'class_type': u''}]
2019-05-08 09:09:48,042 [salt.loaded.ext.module.maasng:945 ][INFO    ][32700] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'primary_rack': u'x3tpnw', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 09:09:48,263 [salt.loaded.ext.module.maasng:945 ][INFO    ][32700] [{u'id': 0, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', 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'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], 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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', 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'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], 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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'x3tpnw', 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'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-08 09:09:48,347 [salt.state       :300 ][INFO    ][32700] {'new': 'Vlan untagged was updated'}
2019-05-08 09:09:48,348 [salt.state       :1951][INFO    ][32700] Completed state [vlan 0] at time 09:09:48.347946 duration_in_ms=483.692
2019-05-08 09:09:48,349 [salt.state       :1780][INFO    ][32700] Running state [opnfv] at time 09:09:48.348995
2019-05-08 09:09:48,349 [salt.state       :1813][INFO    ][32700] Executing state maasng.sshkey_present for [opnfv]
2019-05-08 09:09:48,382 [salt.loaded.ext.module.maasng:1903][INFO    ][32700] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-08 09:09:48,383 [salt.state       :300 ][INFO    ][32700] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-08 09:09:48,383 [salt.state       :1951][INFO    ][32700] Completed state [opnfv] at time 09:09:48.383577 duration_in_ms=34.581
2019-05-08 09:09:48,384 [salt.state       :1780][INFO    ][32700] Running state [maas.process_tags] at time 09:09:48.384506
2019-05-08 09:09:48,384 [salt.state       :1813][INFO    ][32700] Executing state module.run for [maas.process_tags]
2019-05-08 09:09:48,385 [salt.utils.decorators:613 ][WARNING ][32700] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 09:09:48,431 [salt.loaded.ext.module.maas:92  ][INFO    ][32700] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-05-08 09:09:48,510 [salt.state       :300 ][INFO    ][32700] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-05-08 09:09:48,511 [salt.state       :1951][INFO    ][32700] Completed state [maas.process_tags] at time 09:09:48.511371 duration_in_ms=126.864
2019-05-08 09:09:48,516 [salt.minion      :1711][INFO    ][32700] Returning information for job: 20190508090853808394
2019-05-08 09:09:49,027 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508090949014297
2019-05-08 09:09:49,046 [salt.minion      :1432][INFO    ][752] Starting a new job with PID 752
2019-05-08 09:09:52,651 [salt.state       :915 ][INFO    ][752] Loading fresh modules for state activity
2019-05-08 09:09:52,745 [salt.state       :1780][INFO    ][752] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:52.745100
2019-05-08 09:09:52,745 [salt.state       :1813][INFO    ][752] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 09:09:52,747 [salt.loaded.int.module.cmdmod:395 ][INFO    ][752] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 09:09:54,287 [salt.state       :300 ][INFO    ][752] {'pid': 797, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 09:09:54,288 [salt.state       :1951][INFO    ][752] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:54.288480 duration_in_ms=1543.379
2019-05-08 09:09:54,291 [salt.state       :1780][INFO    ][752] Running state [maas.process_machines] at time 09:09:54.291164
2019-05-08 09:09:54,291 [salt.state       :1813][INFO    ][752] Executing state module.run for [maas.process_machines]
2019-05-08 09:09:54,293 [salt.utils.decorators:613 ][WARNING ][752] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 09:09:54,770 [salt.loaded.ext.module.maas:412 ][WARNING ][752] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 09:09:54,771 [salt.loaded.ext.module.maas:92  ][INFO    ][752] 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 system_id=qybh6k architecture=amd64/generic power_parameters_power_user=admin
2019-05-08 09:09:55,838 [salt.loaded.ext.module.maas:412 ][WARNING ][752] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 09:09:55,839 [salt.loaded.ext.module.maas:92  ][INFO    ][752] 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 system_id=8h46gc architecture=amd64/generic power_parameters_power_user=admin
2019-05-08 09:09:57,204 [salt.loaded.ext.module.maas:412 ][WARNING ][752] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 09:09:57,205 [salt.loaded.ext.module.maas:92  ][INFO    ][752] 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 system_id=hwrdwc architecture=amd64/generic power_parameters_power_user=admin
2019-05-08 09:09:58,348 [salt.loaded.ext.module.maas:412 ][WARNING ][752] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 09:09:58,349 [salt.loaded.ext.module.maas:92  ][INFO    ][752] 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 system_id=prg4dt architecture=amd64/generic power_parameters_power_user=admin
2019-05-08 09:09:59,599 [salt.loaded.ext.module.maas:412 ][WARNING ][752] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-08 09:09:59,600 [salt.loaded.ext.module.maas:92  ][INFO    ][752] 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 system_id=qgddxx architecture=amd64/generic power_parameters_power_user=admin
2019-05-08 09:10:00,971 [salt.state       :300 ][INFO    ][752] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-08 09:10:00,972 [salt.state       :1951][INFO    ][752] Completed state [maas.process_machines] at time 09:10:00.972336 duration_in_ms=6681.169
2019-05-08 09:10:00,976 [salt.minion      :1711][INFO    ][752] Returning information for job: 20190508090949014297
2019-05-08 09:10:34,201 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508091034188211
2019-05-08 09:10:34,225 [salt.minion      :1432][INFO    ][1070] Starting a new job with PID 1070
2019-05-08 09:10:37,585 [salt.state       :915 ][INFO    ][1070] Loading fresh modules for state activity
2019-05-08 09:10:37,670 [salt.state       :1780][INFO    ][1070] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:10:37.670409
2019-05-08 09:10:37,670 [salt.state       :1813][INFO    ][1070] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 09:10:37,673 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1070] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 09:10:39,008 [salt.state       :300 ][INFO    ][1070] {'pid': 1078, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 09:10:39,009 [salt.state       :1951][INFO    ][1070] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:10:39.009463 duration_in_ms=1339.054
2019-05-08 09:10:39,011 [salt.state       :1780][INFO    ][1070] Running state [maas.wait_for_machine_status] at time 09:10:39.011891
2019-05-08 09:10:39,012 [salt.state       :1813][INFO    ][1070] Executing state module.run for [maas.wait_for_machine_status]
2019-05-08 09:10:39,013 [salt.utils.decorators:613 ][WARNING ][1070] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 09:10:40,920 [salt.loaded.ext.module.maas:993 ][INFO    ][1070] Machine hwrdwc mark broken
2019-05-08 09:10:41,471 [salt.loaded.ext.module.maas:996 ][INFO    ][1070] Machine hwrdwc mark fixed
2019-05-08 09:10:42,682 [salt.loaded.ext.module.maas:684 ][INFO    ][1070] deploymachines hwe_kernel=hwe-16.04 system_id=hwrdwc distro_series=xenial
2019-05-08 09:10:46,495 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1492.52516198s left)
2019-05-08 09:10:49,267 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091049210245
2019-05-08 09:10:49,289 [salt.minion      :1432][INFO    ][1149] Starting a new job with PID 1149
2019-05-08 09:10:49,313 [salt.minion      :1711][INFO    ][1149] Returning information for job: 20190508091049210245
2019-05-08 09:11:19,318 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091119306139
2019-05-08 09:11:19,339 [salt.minion      :1432][INFO    ][1217] Starting a new job with PID 1217
2019-05-08 09:11:19,367 [salt.minion      :1711][INFO    ][1217] Returning information for job: 20190508091119306139
2019-05-08 09:11:19,960 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1459.06076694s left)
2019-05-08 09:11:49,365 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091149352005
2019-05-08 09:11:49,388 [salt.minion      :1432][INFO    ][1242] Starting a new job with PID 1242
2019-05-08 09:11:49,412 [salt.minion      :1711][INFO    ][1242] Returning information for job: 20190508091149352005
2019-05-08 09:11:53,075 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.94550395s left)
2019-05-08 09:12:19,415 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091219402342
2019-05-08 09:12:19,437 [salt.minion      :1432][INFO    ][1295] Starting a new job with PID 1295
2019-05-08 09:12:19,461 [salt.minion      :1711][INFO    ][1295] Returning information for job: 20190508091219402342
2019-05-08 09:12:26,264 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.75631094s left)
2019-05-08 09:12:49,461 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091249448254
2019-05-08 09:12:49,482 [salt.minion      :1432][INFO    ][1368] Starting a new job with PID 1368
2019-05-08 09:12:49,508 [salt.minion      :1711][INFO    ][1368] Returning information for job: 20190508091249448254
2019-05-08 09:12:59,703 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1359.31795692s left)
2019-05-08 09:13:19,516 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091319503451
2019-05-08 09:13:19,540 [salt.minion      :1432][INFO    ][1542] Starting a new job with PID 1542
2019-05-08 09:13:19,567 [salt.minion      :1711][INFO    ][1542] Returning information for job: 20190508091319503451
2019-05-08 09:13:33,309 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1325.71108103s left)
2019-05-08 09:13:49,577 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091349564557
2019-05-08 09:13:49,600 [salt.minion      :1432][INFO    ][1566] Starting a new job with PID 1566
2019-05-08 09:13:49,627 [salt.minion      :1711][INFO    ][1566] Returning information for job: 20190508091349564557
2019-05-08 09:14:06,701 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1292.31901789s left)
2019-05-08 09:14:19,645 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091419632524
2019-05-08 09:14:19,668 [salt.minion      :1432][INFO    ][1685] Starting a new job with PID 1685
2019-05-08 09:14:19,693 [salt.minion      :1711][INFO    ][1685] Returning information for job: 20190508091419632524
2019-05-08 09:14:40,342 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.67821193s left)
2019-05-08 09:14:49,708 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091449695694
2019-05-08 09:14:49,730 [salt.minion      :1432][INFO    ][1707] Starting a new job with PID 1707
2019-05-08 09:14:49,756 [salt.minion      :1711][INFO    ][1707] Returning information for job: 20190508091449695694
2019-05-08 09:15:13,327 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1225.69347906s left)
2019-05-08 09:15:19,784 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091519771080
2019-05-08 09:15:19,807 [salt.minion      :1432][INFO    ][1839] Starting a new job with PID 1839
2019-05-08 09:15:19,833 [salt.minion      :1711][INFO    ][1839] Returning information for job: 20190508091519771080
2019-05-08 09:15:46,810 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1192.21089196s left)
2019-05-08 09:15:49,859 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091549846201
2019-05-08 09:15:49,882 [salt.minion      :1432][INFO    ][1861] Starting a new job with PID 1861
2019-05-08 09:15:49,907 [salt.minion      :1711][INFO    ][1861] Returning information for job: 20190508091549846201
2019-05-08 09:16:19,938 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091619925178
2019-05-08 09:16:19,961 [salt.minion      :1432][INFO    ][2025] Starting a new job with PID 2025
2019-05-08 09:16:19,985 [salt.minion      :1711][INFO    ][2025] Returning information for job: 20190508091619925178
2019-05-08 09:16:20,116 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1158.90425801s left)
2019-05-08 09:16:50,022 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091650009636
2019-05-08 09:16:50,045 [salt.minion      :1432][INFO    ][2039] Starting a new job with PID 2039
2019-05-08 09:16:50,071 [salt.minion      :1711][INFO    ][2039] Returning information for job: 20190508091650009636
2019-05-08 09:16:53,843 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1125.17779708s left)
2019-05-08 09:17:20,111 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091720098461
2019-05-08 09:17:20,135 [salt.minion      :1432][INFO    ][2104] Starting a new job with PID 2104
2019-05-08 09:17:20,159 [salt.minion      :1711][INFO    ][2104] Returning information for job: 20190508091720098461
2019-05-08 09:17:27,329 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1091.69195986s left)
2019-05-08 09:17:50,209 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091750196041
2019-05-08 09:17:50,232 [salt.minion      :1432][INFO    ][2146] Starting a new job with PID 2146
2019-05-08 09:17:50,258 [salt.minion      :1711][INFO    ][2146] Returning information for job: 20190508091750196041
2019-05-08 09:18:00,844 [salt.loaded.ext.module.maas:1023][INFO    ][1070] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1058.17664695s left)
2019-05-08 09:18:20,272 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command saltutil.find_job with jid 20190508091820259654
2019-05-08 09:18:20,294 [salt.minion      :1432][INFO    ][2273] Starting a new job with PID 2273
2019-05-08 09:18:20,319 [salt.minion      :1711][INFO    ][2273] Returning information for job: 20190508091820259654
2019-05-08 09:18:34,570 [salt.state       :300 ][INFO    ][1070] {'ret': True}
2019-05-08 09:18:34,570 [salt.state       :1951][INFO    ][1070] Completed state [maas.wait_for_machine_status] at time 09:18:34.570741 duration_in_ms=475558.846
2019-05-08 09:18:34,574 [salt.minion      :1711][INFO    ][1070] Returning information for job: 20190508091034188211
2019-05-08 09:18:35,248 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508091835235408
2019-05-08 09:18:35,270 [salt.minion      :1432][INFO    ][2307] Starting a new job with PID 2307
2019-05-08 09:18:38,974 [salt.state       :915 ][INFO    ][2307] Loading fresh modules for state activity
2019-05-08 09:18:39,110 [salt.state       :1780][INFO    ][2307] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:39.110050
2019-05-08 09:18:39,110 [salt.state       :1813][INFO    ][2307] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 09:18:39,112 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2307] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 09:18:40,569 [salt.state       :300 ][INFO    ][2307] {'pid': 2315, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 09:18:40,570 [salt.state       :1951][INFO    ][2307] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:40.570285 duration_in_ms=1460.236
2019-05-08 09:18:40,571 [salt.state       :1780][INFO    ][2307] Running state [maas_machines_storage_cmp002_lvm] at time 09:18:40.571814
2019-05-08 09:18:40,572 [salt.state       :1813][INFO    ][2307] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-08 09:18:41,319 [salt.state       :300 ][INFO    ][2307] Machine cmp002 is not in Ready state.
2019-05-08 09:18:41,319 [salt.state       :1951][INFO    ][2307] Completed state [maas_machines_storage_cmp002_lvm] at time 09:18:41.319351 duration_in_ms=747.535
2019-05-08 09:18:41,319 [salt.state       :1780][INFO    ][2307] Running state [maas_machines_storage_cmp001_lvm] at time 09:18:41.319894
2019-05-08 09:18:41,320 [salt.state       :1813][INFO    ][2307] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-08 09:18:42,041 [salt.state       :300 ][INFO    ][2307] Machine cmp001 is not in Ready state.
2019-05-08 09:18:42,041 [salt.state       :1951][INFO    ][2307] Completed state [maas_machines_storage_cmp001_lvm] at time 09:18:42.041757 duration_in_ms=721.862
2019-05-08 09:18:42,045 [salt.minion      :1711][INFO    ][2307] Returning information for job: 20190508091835235408
2019-05-08 09:18:42,668 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508091842652887
2019-05-08 09:18:42,693 [salt.minion      :1432][INFO    ][2325] Starting a new job with PID 2325
2019-05-08 09:18:43,422 [salt.state       :915 ][INFO    ][2325] Loading fresh modules for state activity
2019-05-08 09:18:43,512 [salt.state       :1780][INFO    ][2325] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:43.512306
2019-05-08 09:18:43,512 [salt.state       :1813][INFO    ][2325] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 09:18:43,515 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2325] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 09:18:44,955 [salt.state       :300 ][INFO    ][2325] {'pid': 2332, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 09:18:44,956 [salt.state       :1951][INFO    ][2325] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:44.955941 duration_in_ms=1443.637
2019-05-08 09:18:44,957 [salt.state       :1780][INFO    ][2325] Running state [maas.deploy_machines] at time 09:18:44.957167
2019-05-08 09:18:44,957 [salt.state       :1813][INFO    ][2325] Executing state module.run for [maas.deploy_machines]
2019-05-08 09:18:44,958 [salt.utils.decorators:613 ][WARNING ][2325] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 09:18:45,697 [salt.state       :300 ][INFO    ][2325] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-08 09:18:45,698 [salt.state       :1951][INFO    ][2325] Completed state [maas.deploy_machines] at time 09:18:45.698086 duration_in_ms=740.916
2019-05-08 09:18:45,701 [salt.minion      :1711][INFO    ][2325] Returning information for job: 20190508091842652887
2019-05-08 09:18:46,342 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command state.apply with jid 20190508091846328224
2019-05-08 09:18:46,365 [salt.minion      :1432][INFO    ][2342] Starting a new job with PID 2342
2019-05-08 09:18:47,108 [salt.state       :915 ][INFO    ][2342] Loading fresh modules for state activity
2019-05-08 09:18:47,200 [salt.state       :1780][INFO    ][2342] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:47.200360
2019-05-08 09:18:47,200 [salt.state       :1813][INFO    ][2342] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-08 09:18:47,203 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2342] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-08 09:18:48,655 [salt.state       :300 ][INFO    ][2342] {'pid': 2349, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-08 09:18:48,656 [salt.state       :1951][INFO    ][2342] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:48.655995 duration_in_ms=1455.634
2019-05-08 09:18:48,659 [salt.state       :1780][INFO    ][2342] Running state [maas.wait_for_machine_status] at time 09:18:48.659165
2019-05-08 09:18:48,659 [salt.state       :1813][INFO    ][2342] Executing state module.run for [maas.wait_for_machine_status]
2019-05-08 09:18:48,660 [salt.utils.decorators:613 ][WARNING ][2342] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-08 09:18:52,331 [salt.state       :300 ][INFO    ][2342] {'ret': True}
2019-05-08 09:18:52,331 [salt.state       :1951][INFO    ][2342] Completed state [maas.wait_for_machine_status] at time 09:18:52.331460 duration_in_ms=3672.294
2019-05-08 09:18:52,335 [salt.minion      :1711][INFO    ][2342] Returning information for job: 20190508091846328224
2019-05-08 09:47:41,964 [salt.utils.schedule:1377][INFO    ][25765] Running scheduled job: __mine_interval
2019-05-08 10:45:51,982 [salt.minion      :1308][INFO    ][25765] User sudo_ubuntu Executing command cp.push_dir with jid 20190508104551970335
2019-05-08 10:45:52,001 [salt.minion      :1432][INFO    ][8876] Starting a new job with PID 8876
