2019-03-14 09:02:25,719 [salt.utils.decorators:613 ][WARNING ][2215] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:02:26,143 [salt.utils.decorators:613 ][WARNING ][2215] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:02:28,034 [salt.loaded.int.states.file:2298][WARNING ][2522] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-03-14 09:02:54,967 [salt.state       :2022][WARNING ][3209] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-03-14 09:02:58,977 [salt.utils.decorators:613 ][WARNING ][3209] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:03:33,168 [salt.utils.decorators:613 ][WARNING ][3209] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:03:33,174 [salt.state       :302 ][ERROR   ][3209] Module function maasng.boot_resources_import threw an exception. Exception: HTTP Error 503: Service Unavailable
2019-03-14 09:03:47,472 [salt.loaded.ext.module.maasng:1008][WARNING ][3209] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-03-14 09:03:47,473 [salt.loaded.ext.module.maasng:1011][WARNING ][3209] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-03-14 09:03:48,288 [salt.loaded.ext.module.maasng:1235][WARNING ][3209] Ignoring parameter vlan:0
2019-03-14 09:03:49,356 [salt.utils.decorators:613 ][WARNING ][3209] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:03:52,309 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5746] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-03-14 09:03:52,341 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5746] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-03-14 09:03:52,364 [salt.utils.parsers:1051][WARNING ][365] Minion received a SIGTERM. Exiting.
2019-03-14 09:03:53,438 [salt.cli.daemons :293 ][INFO    ][5800] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-03-14 09:03:53,537 [salt.cli.daemons :82  ][INFO    ][5800] Starting up the Salt Minion
2019-03-14 09:03:53,537 [salt.utils.event :1017][INFO    ][5800] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-03-14 09:03:54,445 [salt.minion      :976 ][INFO    ][5800] Creating minion process manager
2019-03-14 09:03:55,764 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][5800] Executing command ['date', '+%z'] in directory '/root'
2019-03-14 09:03:55,784 [salt.utils.schedule:568 ][INFO    ][5800] Updating job settings for scheduled job: __mine_interval
2019-03-14 09:03:55,816 [salt.minion      :1108][INFO    ][5800] Added mine.update to scheduler
2019-03-14 09:03:55,821 [salt.minion      :1975][INFO    ][5800] Minion is starting as user 'root'
2019-03-14 09:03:55,839 [salt.minion      :2336][INFO    ][5800] Minion is ready to receive requests!
2019-03-14 09:04:00,015 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314090400006396
2019-03-14 09:04:00,034 [salt.minion      :1432][INFO    ][5896] Starting a new job with PID 5896
2019-03-14 09:04:03,521 [salt.state       :915 ][INFO    ][5896] Loading fresh modules for state activity
2019-03-14 09:04:05,289 [salt.state       :1780][INFO    ][5896] Running state [maas-region-controller] at time 09:04:05.289073
2019-03-14 09:04:05,289 [salt.state       :1813][INFO    ][5896] Executing state pkg.installed for [maas-region-controller]
2019-03-14 09:04:05,289 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-03-14 09:04:05,388 [salt.state       :300 ][INFO    ][5896] All specified packages are already installed
2019-03-14 09:04:05,389 [salt.state       :1951][INFO    ][5896] Completed state [maas-region-controller] at time 09:04:05.389154 duration_in_ms=100.08
2019-03-14 09:04:05,389 [salt.state       :1780][INFO    ][5896] Running state [python-oauth] at time 09:04:05.389569
2019-03-14 09:04:05,389 [salt.state       :1813][INFO    ][5896] Executing state pkg.installed for [python-oauth]
2019-03-14 09:04:05,400 [salt.state       :300 ][INFO    ][5896] All specified packages are already installed
2019-03-14 09:04:05,400 [salt.state       :1951][INFO    ][5896] Completed state [python-oauth] at time 09:04:05.400263 duration_in_ms=10.693
2019-03-14 09:04:05,403 [salt.state       :1780][INFO    ][5896] Running state [/etc/maas/regiond.conf] at time 09:04:05.403902
2019-03-14 09:04:05,404 [salt.state       :1813][INFO    ][5896] Executing state file.replace for [/etc/maas/regiond.conf]
2019-03-14 09:04:05,499 [salt.state       :300 ][INFO    ][5896] No changes needed to be made
2019-03-14 09:04:05,500 [salt.state       :1951][INFO    ][5896] Completed state [/etc/maas/regiond.conf] at time 09:04:05.500116 duration_in_ms=96.214
2019-03-14 09:04:05,501 [salt.state       :1780][INFO    ][5896] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:04:05.500929
2019-03-14 09:04:05,501 [salt.state       :1813][INFO    ][5896] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-03-14 09:04:05,618 [salt.state       :300 ][INFO    ][5896] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-03-14 09:04:05,619 [salt.state       :1951][INFO    ][5896] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:04:05.619023 duration_in_ms=118.094
2019-03-14 09:04:05,619 [salt.state       :1780][INFO    ][5896] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:04:05.619852
2019-03-14 09:04:05,620 [salt.state       :1813][INFO    ][5896] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-03-14 09:04:05,675 [salt.state       :300 ][INFO    ][5896] No changes needed to be made
2019-03-14 09:04:05,675 [salt.state       :1951][INFO    ][5896] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:04:05.675609 duration_in_ms=55.757
2019-03-14 09:04:05,676 [salt.state       :1780][INFO    ][5896] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:04:05.676398
2019-03-14 09:04:05,676 [salt.state       :1813][INFO    ][5896] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-03-14 09:04:05,742 [salt.state       :300 ][INFO    ][5896] No changes needed to be made
2019-03-14 09:04:05,743 [salt.state       :1951][INFO    ][5896] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:04:05.742952 duration_in_ms=66.554
2019-03-14 09:04:05,743 [salt.state       :1780][INFO    ][5896] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:04:05.743771
2019-03-14 09:04:05,744 [salt.state       :1813][INFO    ][5896] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-03-14 09:04:05,785 [salt.state       :300 ][INFO    ][5896] No changes needed to be made
2019-03-14 09:04:05,785 [salt.state       :1951][INFO    ][5896] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:04:05.785846 duration_in_ms=42.074
2019-03-14 09:04:05,786 [salt.state       :1780][INFO    ][5896] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:04:05.786812
2019-03-14 09:04:05,787 [salt.state       :1813][INFO    ][5896] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-03-14 09:04:05,802 [salt.state       :300 ][INFO    ][5896] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-03-14 09:04:05,803 [salt.state       :1951][INFO    ][5896] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:04:05.803220 duration_in_ms=16.409
2019-03-14 09:04:05,805 [salt.state       :1780][INFO    ][5896] Running state [a2enmod headers] at time 09:04:05.805791
2019-03-14 09:04:05,806 [salt.state       :1813][INFO    ][5896] Executing state cmd.run for [a2enmod headers]
2019-03-14 09:04:05,807 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command 'a2enmod headers' in directory '/root'
2019-03-14 09:04:05,879 [salt.state       :300 ][INFO    ][5896] {'pid': 5918, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-03-14 09:04:05,879 [salt.state       :1951][INFO    ][5896] Completed state [a2enmod headers] at time 09:04:05.879890 duration_in_ms=74.099
2019-03-14 09:04:05,880 [salt.state       :1780][INFO    ][5896] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:04:05.880355
2019-03-14 09:04:05,880 [salt.state       :1813][INFO    ][5896] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-03-14 09:04:05,896 [salt.state       :300 ][INFO    ][5896] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-03-14 09:04:05,896 [salt.state       :1951][INFO    ][5896] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:04:05.896774 duration_in_ms=16.419
2019-03-14 09:04:05,897 [salt.state       :1780][INFO    ][5896] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:04:05.897374
2019-03-14 09:04:05,897 [salt.state       :1813][INFO    ][5896] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-03-14 09:04:06,003 [salt.state       :300 ][INFO    ][5896] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-03-14 09:04:06,003 [salt.state       :1951][INFO    ][5896] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:04:06.003780 duration_in_ms=106.407
2019-03-14 09:04:06,004 [salt.state       :1780][INFO    ][5896] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:04:06.004497
2019-03-14 09:04:06,005 [salt.state       :1813][INFO    ][5896] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-03-14 09:04:06,117 [salt.state       :300 ][INFO    ][5896] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-03-14 09:04:06,117 [salt.state       :1951][INFO    ][5896] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:04:06.117890 duration_in_ms=113.412
2019-03-14 09:04:06,118 [salt.state       :1780][INFO    ][5896] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:04:06.118725
2019-03-14 09:04:06,119 [salt.state       :1813][INFO    ][5896] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-03-14 09:04:06,237 [salt.state       :300 ][INFO    ][5896] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-03-14 09:04:06,238 [salt.state       :1951][INFO    ][5896] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:04:06.237955 duration_in_ms=119.23
2019-03-14 09:04:06,238 [salt.state       :1780][INFO    ][5896] Running state [/root/.pgpass] at time 09:04:06.238380
2019-03-14 09:04:06,238 [salt.state       :1813][INFO    ][5896] Executing state file.managed for [/root/.pgpass]
2019-03-14 09:04:06,339 [salt.state       :300 ][INFO    ][5896] File /root/.pgpass is in the correct state
2019-03-14 09:04:06,339 [salt.state       :1951][INFO    ][5896] Completed state [/root/.pgpass] at time 09:04:06.339783 duration_in_ms=101.403
2019-03-14 09:04:06,348 [salt.state       :1780][INFO    ][5896] Running state [maas-region syncdb --noinput] at time 09:04:06.348435
2019-03-14 09:04:06,348 [salt.state       :1813][INFO    ][5896] Executing state cmd.run for [maas-region syncdb --noinput]
2019-03-14 09:04:06,349 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-03-14 09:04:08,353 [salt.state       :300 ][INFO    ][5896] {'pid': 5931, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: contenttypes, metadataserver, auth, maasserver, piston3, sessions, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-03-14 09:04:08,353 [salt.state       :1951][INFO    ][5896] Completed state [maas-region syncdb --noinput] at time 09:04:08.353655 duration_in_ms=2005.221
2019-03-14 09:04:08,353 [salt.state       :2022][WARNING ][5896] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-03-14 09:04:08,354 [salt.state       :1780][INFO    ][5896] Running state [maas-regiond] at time 09:04:08.354921
2019-03-14 09:04:08,355 [salt.state       :1813][INFO    ][5896] Executing state service.running for [maas-regiond]
2019-03-14 09:04:08,355 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-03-14 09:04:08,389 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-03-14 09:04:08,405 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-03-14 09:04:08,420 [salt.state       :300 ][INFO    ][5896] The service maas-regiond is already running
2019-03-14 09:04:08,421 [salt.state       :1951][INFO    ][5896] Completed state [maas-regiond] at time 09:04:08.421106 duration_in_ms=66.185
2019-03-14 09:04:08,422 [salt.state       :1780][INFO    ][5896] Running state [bind9] at time 09:04:08.422259
2019-03-14 09:04:08,422 [salt.state       :1813][INFO    ][5896] Executing state service.running for [bind9]
2019-03-14 09:04:08,423 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-03-14 09:04:08,439 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-03-14 09:04:08,454 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-03-14 09:04:08,469 [salt.state       :300 ][INFO    ][5896] The service bind9 is already running
2019-03-14 09:04:08,469 [salt.state       :1951][INFO    ][5896] Completed state [bind9] at time 09:04:08.469679 duration_in_ms=47.42
2019-03-14 09:04:08,470 [salt.state       :1780][INFO    ][5896] Running state [apache2] at time 09:04:08.470937
2019-03-14 09:04:08,471 [salt.state       :1813][INFO    ][5896] Executing state service.running for [apache2]
2019-03-14 09:04:08,471 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-03-14 09:04:08,487 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-03-14 09:04:08,502 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-03-14 09:04:08,521 [salt.state       :300 ][INFO    ][5896] The service apache2 is already running
2019-03-14 09:04:08,522 [salt.state       :1951][INFO    ][5896] Completed state [apache2] at time 09:04:08.522227 duration_in_ms=51.289
2019-03-14 09:04:08,523 [salt.state       :1780][INFO    ][5896] Running state [maasng.wait_for_http_code] at time 09:04:08.523536
2019-03-14 09:04:08,523 [salt.state       :1813][INFO    ][5896] Executing state module.run for [maasng.wait_for_http_code]
2019-03-14 09:04:08,524 [salt.utils.decorators:613 ][WARNING ][5896] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:04:08,532 [salt.state       :300 ][INFO    ][5896] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-03-14 09:04:08,532 [salt.state       :1951][INFO    ][5896] Completed state [maasng.wait_for_http_code] at time 09:04:08.532598 duration_in_ms=9.061
2019-03-14 09:04:08,534 [salt.state       :1780][INFO    ][5896] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:04:08.533993
2019-03-14 09:04:08,534 [salt.state       :1813][INFO    ][5896] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-03-14 09:04:08,535 [salt.state       :300 ][INFO    ][5896] /var/lib/maas/.setup_admin exists
2019-03-14 09:04:08,535 [salt.state       :1951][INFO    ][5896] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:04:08.535595 duration_in_ms=1.603
2019-03-14 09:04:08,536 [salt.state       :1780][INFO    ][5896] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:04:08.536682
2019-03-14 09:04:08,537 [salt.state       :1813][INFO    ][5896] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:04:08,538 [salt.loaded.int.module.cmdmod:395 ][INFO    ][5896] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:04:09,979 [salt.state       :300 ][INFO    ][5896] {'pid': 5950, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:04:09,980 [salt.state       :1951][INFO    ][5896] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:04:09.980657 duration_in_ms=1443.975
2019-03-14 09:04:09,987 [salt.state       :1780][INFO    ][5896] Running state [maas_region_boot_source_resources_mirror] at time 09:04:09.987906
2019-03-14 09:04:09,988 [salt.state       :1813][INFO    ][5896] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-03-14 09:04:10,092 [salt.state       :300 ][INFO    ][5896] {'changes': {}}
2019-03-14 09:04:10,093 [salt.state       :1951][INFO    ][5896] Completed state [maas_region_boot_source_resources_mirror] at time 09:04:10.093191 duration_in_ms=105.284
2019-03-14 09:04:10,094 [salt.state       :1780][INFO    ][5896] Running state [maasng.boot_resources_import] at time 09:04:10.094258
2019-03-14 09:04:10,094 [salt.state       :1813][INFO    ][5896] Executing state module.run for [maasng.boot_resources_import]
2019-03-14 09:04:10,095 [salt.utils.decorators:613 ][WARNING ][5896] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:04:10,234 [salt.loaded.ext.module.maasng:1600][INFO    ][5896] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-03-14 09:04:15,143 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090415129091
2019-03-14 09:04:15,165 [salt.minion      :1432][INFO    ][5970] Starting a new job with PID 5970
2019-03-14 09:04:15,189 [salt.minion      :1711][INFO    ][5970] Returning information for job: 20190314090415129091
2019-03-14 09:04:15,310 [salt.loaded.ext.module.maasng:1600][INFO    ][5896] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-03-14 09:04:20,369 [salt.loaded.ext.module.maasng:1600][INFO    ][5896] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-03-14 09:04:25,507 [salt.state       :300 ][INFO    ][5896] {'ret': True}
2019-03-14 09:04:25,507 [salt.state       :1951][INFO    ][5896] Completed state [maasng.boot_resources_import] at time 09:04:25.507913 duration_in_ms=15413.655
2019-03-14 09:04:25,509 [salt.state       :1780][INFO    ][5896] Running state [maas_region_boot_sources_selection_xenial] at time 09:04:25.509125
2019-03-14 09:04:25,509 [salt.state       :1813][INFO    ][5896] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-03-14 09:04:25,697 [salt.state       :300 ][INFO    ][5896] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-03-14 09:04:25,698 [salt.state       :1951][INFO    ][5896] Completed state [maas_region_boot_sources_selection_xenial] at time 09:04:25.698307 duration_in_ms=189.182
2019-03-14 09:04:25,699 [salt.state       :1780][INFO    ][5896] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 09:04:25.699708
2019-03-14 09:04:25,700 [salt.state       :1813][INFO    ][5896] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-03-14 09:04:25,700 [salt.utils.decorators:613 ][WARNING ][5896] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:04:25,701 [salt.loaded.ext.module.maasng:1771][INFO    ][5896] boot-sources sync initiated for ALL Rack's
2019-03-14 09:04:26,122 [salt.loaded.ext.module.maasng:1878][INFO    ][5896] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:900.0/900s
2019-03-14 09:04:31,344 [salt.loaded.ext.module.maasng:1878][INFO    ][5896] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:895.0/900s
2019-03-14 09:04:36,943 [salt.loaded.ext.module.maasng:1878][INFO    ][5896] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:889.0/900s
2019-03-14 09:04:42,859 [salt.state       :300 ][INFO    ][5896] {'ret': True}
2019-03-14 09:04:42,860 [salt.state       :1951][INFO    ][5896] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 09:04:42.860152 duration_in_ms=17160.444
2019-03-14 09:04:42,862 [salt.state       :1780][INFO    ][5896] Running state [maas.process_maas_config] at time 09:04:42.862170
2019-03-14 09:04:42,862 [salt.state       :1813][INFO    ][5896] Executing state module.run for [maas.process_maas_config]
2019-03-14 09:04:42,863 [salt.utils.decorators:613 ][WARNING ][5896] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:04:42,864 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=enable_http_proxy value=True
2019-03-14 09:04:42,927 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=upstream_dns value=8.8.8.8
2019-03-14 09:04:43,015 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=commissioning_distro_series value=xenial
2019-03-14 09:04:45,197 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090445182697
2019-03-14 09:04:45,220 [salt.minion      :1432][INFO    ][6185] Starting a new job with PID 6185
2019-03-14 09:04:45,243 [salt.minion      :1711][INFO    ][6185] Returning information for job: 20190314090445182697
2019-03-14 09:04:45,977 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=default_osystem value=ubuntu
2019-03-14 09:04:46,043 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=active_discovery_interval value=600
2019-03-14 09:04:46,104 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=dnssec_validation value=no
2019-03-14 09:04:46,157 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=maas_name value=mas01
2019-03-14 09:04:46,226 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=network_discovery value=enabled
2019-03-14 09:04:46,370 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=enable_third_party_drivers value=True
2019-03-14 09:04:46,429 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=default_storage_layout value=lvm
2019-03-14 09:04:46,481 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=ntp_external_only value=True
2019-03-14 09:04:46,544 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=disk_erase_with_secure_erase value=False
2019-03-14 09:04:46,603 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=default_distro_series value=xenial
2019-03-14 09:04:46,687 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-03-14 09:04:46,834 [salt.state       :300 ][INFO    ][5896] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-03-14 09:04:46,834 [salt.state       :1951][INFO    ][5896] Completed state [maas.process_maas_config] at time 09:04:46.834552 duration_in_ms=3972.382
2019-03-14 09:04:46,835 [salt.state       :1780][INFO    ][5896] Running state [pxe_admin] at time 09:04:46.835257
2019-03-14 09:04:46,835 [salt.state       :1813][INFO    ][5896] Executing state maasng.fabric_present for [pxe_admin]
2019-03-14 09:04:46,883 [salt.loaded.ext.module.maasng:945 ][INFO    ][5896] [{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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rywqst', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-14 09:04:46,943 [salt.loaded.ext.module.maasng:1008][WARNING ][5896] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-03-14 09:04:46,944 [salt.loaded.ext.module.maasng:1011][WARNING ][5896] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-03-14 09:04:47,001 [salt.state       :300 ][INFO    ][5896] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-03-14 09:04:47,001 [salt.state       :1951][INFO    ][5896] Completed state [pxe_admin] at time 09:04:47.001514 duration_in_ms=166.256
2019-03-14 09:04:47,002 [salt.state       :1780][INFO    ][5896] Running state [vlan 0] at time 09:04:47.001962
2019-03-14 09:04:47,002 [salt.state       :1813][INFO    ][5896] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-03-14 09:04:47,048 [salt.loaded.ext.module.maasng:945 ][INFO    ][5896] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-14 09:04:47,144 [salt.loaded.ext.module.maasng:945 ][INFO    ][5896] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-14 09:04:47,391 [salt.loaded.ext.module.maasng:945 ][INFO    ][5896] [{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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 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'rywqst', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-03-14 09:04:47,477 [salt.state       :300 ][INFO    ][5896] {'new': 'Vlan untagged was updated'}
2019-03-14 09:04:47,477 [salt.state       :1951][INFO    ][5896] Completed state [vlan 0] at time 09:04:47.477272 duration_in_ms=475.311
2019-03-14 09:04:47,478 [salt.state       :1780][INFO    ][5896] Running state [192.168.11.0/24] at time 09:04:47.478199
2019-03-14 09:04:47,478 [salt.state       :1813][INFO    ][5896] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-03-14 09:04:47,645 [salt.loaded.ext.module.maasng:945 ][INFO    ][5896] [{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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 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'rywqst', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-03-14 09:04:47,646 [salt.loaded.ext.module.maasng:1235][WARNING ][5896] Ignoring parameter vlan:0
2019-03-14 09:04:47,693 [salt.state       :300 ][INFO    ][5896] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-03-14 09:04:47,693 [salt.state       :1951][INFO    ][5896] Completed state [192.168.11.0/24] at time 09:04:47.693748 duration_in_ms=215.548
2019-03-14 09:04:47,694 [salt.state       :1780][INFO    ][5896] Running state [maas_create_iprange_1] at time 09:04:47.694876
2019-03-14 09:04:47,695 [salt.state       :1813][INFO    ][5896] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-03-14 09:04:47,737 [salt.state       :300 ][INFO    ][5896] Iprange maas_create_iprange_1 already exist.
2019-03-14 09:04:47,737 [salt.state       :1951][INFO    ][5896] Completed state [maas_create_iprange_1] at time 09:04:47.737897 duration_in_ms=43.02
2019-03-14 09:04:47,738 [salt.state       :1780][INFO    ][5896] Running state [vlan 0] at time 09:04:47.738262
2019-03-14 09:04:47,738 [salt.state       :1813][INFO    ][5896] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-03-14 09:04:47,773 [salt.loaded.ext.module.maasng:945 ][INFO    ][5896] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-03-14 09:04:47,875 [salt.loaded.ext.module.maasng:945 ][INFO    ][5896] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-14 09:04:48,127 [salt.loaded.ext.module.maasng:945 ][INFO    ][5896] [{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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 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'rywqst', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-03-14 09:04:48,232 [salt.state       :300 ][INFO    ][5896] {'new': 'Vlan untagged was updated'}
2019-03-14 09:04:48,232 [salt.state       :1951][INFO    ][5896] Completed state [vlan 0] at time 09:04:48.232450 duration_in_ms=494.187
2019-03-14 09:04:48,233 [salt.state       :1780][INFO    ][5896] Running state [opnfv] at time 09:04:48.233387
2019-03-14 09:04:48,233 [salt.state       :1813][INFO    ][5896] Executing state maasng.sshkey_present for [opnfv]
2019-03-14 09:04:48,291 [salt.loaded.ext.module.maasng:1903][INFO    ][5896] [{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-03-14 09:04:48,292 [salt.state       :300 ][INFO    ][5896] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-03-14 09:04:48,292 [salt.state       :1951][INFO    ][5896] Completed state [opnfv] at time 09:04:48.292759 duration_in_ms=59.371
2019-03-14 09:04:48,293 [salt.state       :1780][INFO    ][5896] Running state [maas.process_tags] at time 09:04:48.293722
2019-03-14 09:04:48,294 [salt.state       :1813][INFO    ][5896] Executing state module.run for [maas.process_tags]
2019-03-14 09:04:48,294 [salt.utils.decorators:613 ][WARNING ][5896] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:04:48,348 [salt.loaded.ext.module.maas:92  ][INFO    ][5896] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-03-14 09:04:48,421 [salt.state       :300 ][INFO    ][5896] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-03-14 09:04:48,421 [salt.state       :1951][INFO    ][5896] Completed state [maas.process_tags] at time 09:04:48.421490 duration_in_ms=127.753
2019-03-14 09:04:48,445 [salt.minion      :1711][INFO    ][5896] Returning information for job: 20190314090400006396
2019-03-14 09:04:48,938 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314090448926016
2019-03-14 09:04:48,954 [salt.minion      :1432][INFO    ][6297] Starting a new job with PID 6297
2019-03-14 09:04:52,435 [salt.state       :915 ][INFO    ][6297] Loading fresh modules for state activity
2019-03-14 09:04:52,498 [salt.fileclient  :1219][INFO    ][6297] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-03-14 09:04:52,541 [salt.state       :1780][INFO    ][6297] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:04:52.541012
2019-03-14 09:04:52,541 [salt.state       :1813][INFO    ][6297] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:04:52,543 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6297] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:04:54,132 [salt.state       :300 ][INFO    ][6297] {'pid': 6333, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:04:54,132 [salt.state       :1951][INFO    ][6297] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:04:54.132557 duration_in_ms=1591.546
2019-03-14 09:04:54,133 [salt.state       :1780][INFO    ][6297] Running state [maas.process_machines] at time 09:04:54.133687
2019-03-14 09:04:54,133 [salt.state       :1813][INFO    ][6297] Executing state module.run for [maas.process_machines]
2019-03-14 09:04:54,134 [salt.utils.decorators:613 ][WARNING ][6297] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:04:54,208 [salt.loaded.ext.module.maas:412 ][WARNING ][6297] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:04:54,208 [salt.loaded.ext.module.maas:92  ][INFO    ][6297] machine hostname=cmp002 power_type=ipmi mac_addresses=00:25:b5:a0:00:6a power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:04:55,811 [salt.loaded.ext.module.maas:412 ][WARNING ][6297] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:04:55,812 [salt.loaded.ext.module.maas:92  ][INFO    ][6297] machine hostname=cmp001 power_type=ipmi mac_addresses=00:25:b5:a0:00:5a power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:04:57,008 [salt.loaded.ext.module.maas:412 ][WARNING ][6297] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:04:57,009 [salt.loaded.ext.module.maas:92  ][INFO    ][6297] machine hostname=kvm01 power_type=ipmi mac_addresses=00:25:b5:a0:00:2a power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:04:58,416 [salt.loaded.ext.module.maas:412 ][WARNING ][6297] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:04:58,416 [salt.loaded.ext.module.maas:92  ][INFO    ][6297] machine hostname=kvm03 power_type=ipmi mac_addresses=00:25:b5:a0:00:4a power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:04:59,874 [salt.loaded.ext.module.maas:412 ][WARNING ][6297] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:04:59,875 [salt.loaded.ext.module.maas:92  ][INFO    ][6297] machine hostname=kvm02 power_type=ipmi mac_addresses=00:25:b5:a0:00:3a power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:05:01,264 [salt.state       :300 ][INFO    ][6297] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-03-14 09:05:01,264 [salt.state       :1951][INFO    ][6297] Completed state [maas.process_machines] at time 09:05:01.264647 duration_in_ms=7130.958
2019-03-14 09:05:01,286 [salt.minion      :1711][INFO    ][6297] Returning information for job: 20190314090448926016
2019-03-14 09:05:32,380 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314090532371509
2019-03-14 09:05:32,403 [salt.minion      :1432][INFO    ][6648] Starting a new job with PID 6648
2019-03-14 09:05:36,030 [salt.state       :915 ][INFO    ][6648] Loading fresh modules for state activity
2019-03-14 09:05:36,061 [salt.fileclient  :1219][INFO    ][6648] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-03-14 09:05:36,087 [salt.state       :1780][INFO    ][6648] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:05:36.087715
2019-03-14 09:05:36,087 [salt.state       :1813][INFO    ][6648] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:05:36,089 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6648] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:05:37,534 [salt.state       :300 ][INFO    ][6648] {'pid': 6666, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:05:37,535 [salt.state       :1951][INFO    ][6648] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:05:37.535385 duration_in_ms=1447.67
2019-03-14 09:05:37,536 [salt.state       :1780][INFO    ][6648] Running state [maas.wait_for_machine_status] at time 09:05:37.536558
2019-03-14 09:05:37,536 [salt.state       :1813][INFO    ][6648] Executing state module.run for [maas.wait_for_machine_status]
2019-03-14 09:05:37,537 [salt.utils.decorators:613 ][WARNING ][6648] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:05:38,554 [salt.loaded.ext.module.maas:1023][INFO    ][6648] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1498.98749495s left)
2019-03-14 09:05:47,432 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090547419542
2019-03-14 09:05:47,455 [salt.minion      :1432][INFO    ][6681] Starting a new job with PID 6681
2019-03-14 09:05:47,478 [salt.minion      :1711][INFO    ][6681] Returning information for job: 20190314090547419542
2019-03-14 09:06:09,476 [salt.loaded.ext.module.maas:1023][INFO    ][6648] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.0661099s left)
2019-03-14 09:06:17,490 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090617474777
2019-03-14 09:06:17,512 [salt.minion      :1432][INFO    ][6717] Starting a new job with PID 6717
2019-03-14 09:06:17,534 [salt.minion      :1711][INFO    ][6717] Returning information for job: 20190314090617474777
2019-03-14 09:06:40,796 [salt.loaded.ext.module.maas:1023][INFO    ][6648] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.74566388s left)
2019-03-14 09:06:47,541 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090647528823
2019-03-14 09:06:47,561 [salt.minion      :1432][INFO    ][6869] Starting a new job with PID 6869
2019-03-14 09:06:47,582 [salt.minion      :1711][INFO    ][6869] Returning information for job: 20190314090647528823
2019-03-14 09:07:12,065 [salt.loaded.ext.module.maas:1023][INFO    ][6648] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.47630286s left)
2019-03-14 09:07:17,587 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090717574217
2019-03-14 09:07:17,609 [salt.minion      :1432][INFO    ][7003] Starting a new job with PID 7003
2019-03-14 09:07:17,632 [salt.minion      :1711][INFO    ][7003] Returning information for job: 20190314090717574217
2019-03-14 09:07:43,713 [salt.loaded.ext.module.maas:1023][INFO    ][6648] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1373.82884598s left)
2019-03-14 09:07:47,643 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090747630372
2019-03-14 09:07:47,665 [salt.minion      :1432][INFO    ][7320] Starting a new job with PID 7320
2019-03-14 09:07:47,688 [salt.minion      :1711][INFO    ][7320] Returning information for job: 20190314090747630372
2019-03-14 09:08:15,449 [salt.loaded.ext.module.maas:1023][INFO    ][6648] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.09239697s left)
2019-03-14 09:08:17,703 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090817686827
2019-03-14 09:08:17,725 [salt.minion      :1432][INFO    ][7767] Starting a new job with PID 7767
2019-03-14 09:08:17,748 [salt.minion      :1711][INFO    ][7767] Returning information for job: 20190314090817686827
2019-03-14 09:08:47,764 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090847748498
2019-03-14 09:08:47,786 [salt.minion      :1432][INFO    ][7907] Starting a new job with PID 7907
2019-03-14 09:08:47,808 [salt.minion      :1711][INFO    ][7907] Returning information for job: 20190314090847748498
2019-03-14 09:08:48,980 [salt.state       :300 ][INFO    ][6648] {'ret': True}
2019-03-14 09:08:48,980 [salt.state       :1951][INFO    ][6648] Completed state [maas.wait_for_machine_status] at time 09:08:48.980632 duration_in_ms=191444.071
2019-03-14 09:08:48,984 [salt.minion      :1711][INFO    ][6648] Returning information for job: 20190314090532371509
2019-03-14 09:08:49,621 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314090849611952
2019-03-14 09:08:49,643 [salt.minion      :1432][INFO    ][7928] Starting a new job with PID 7928
2019-03-14 09:08:53,073 [salt.state       :915 ][INFO    ][7928] Loading fresh modules for state activity
2019-03-14 09:08:53,126 [salt.fileclient  :1219][INFO    ][7928] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-03-14 09:08:53,218 [salt.state       :1780][INFO    ][7928] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:08:53.218361
2019-03-14 09:08:53,218 [salt.state       :1813][INFO    ][7928] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:08:53,220 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7928] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:08:54,666 [salt.state       :300 ][INFO    ][7928] {'pid': 7935, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:08:54,667 [salt.state       :1951][INFO    ][7928] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:08:54.667077 duration_in_ms=1448.717
2019-03-14 09:08:54,668 [salt.state       :1780][INFO    ][7928] Running state [maas_machines_storage_cmp002_lvm] at time 09:08:54.668519
2019-03-14 09:08:54,668 [salt.state       :1813][INFO    ][7928] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-03-14 09:08:56,122 [salt.loaded.ext.module.maasng:610 ][INFO    ][7928] 76h8ym
2019-03-14 09:08:56,122 [salt.loaded.ext.module.maasng:626 ][INFO    ][7928] sda
2019-03-14 09:08:56,800 [salt.loaded.ext.module.maasng:361 ][INFO    ][7928] 76h8ym
2019-03-14 09:08:56,938 [salt.loaded.ext.module.maasng:367 ][INFO    ][7928] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'12840598-8690-4569-9d48-bdeeac099678', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'76h8ym', u'device_id': 5, u'filesystem': {u'uuid': u'9a01fe41-bb73-472d-ad56-02fff0462e03', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/5/partition/2', u'type': u'partition', u'id': 2, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'76h8ym', 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'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/5/'}, {u'size': 2397988454400, u'model': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'partitions': [], u'uuid': u'75eb794a-f853-410e-8072-1a1177ff69b2', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'76h8ym', u'partition_table_type': None, u'filesystem': {u'uuid': u'cc2a91fe-d802-49ed-b54f-62468ce64947', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/6/'}]
2019-03-14 09:08:56,939 [salt.loaded.ext.module.maasng:632 ][INFO    ][7928] vgroot
2019-03-14 09:08:56,939 [salt.loaded.ext.module.maasng:635 ][INFO    ][7928] lvroot
2019-03-14 09:08:56,939 [salt.loaded.ext.module.maasng:639 ][INFO    ][7928] 107374182400
2019-03-14 09:08:57,647 [salt.loaded.ext.module.maasng:645 ][INFO    ][7928] {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'testing_status_name': u'Passed', u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', 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'id': 19, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', 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'76h8ym', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/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'min_hwe_kernel': u'hwe-16.04', u'status_action': u'modules-final', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'fqdn': u'cmp002.maas', u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'description': u''}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'76h8ym', 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"'cloudinit' running modules for final", u'owner_data': {}, u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'uuid': u'd57db9f3-fd5c-462f-b9fc-222c6a17d49f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'76h8ym', u'device_id': 5, u'filesystem': {u'uuid': u'fc056b50-0b98-4501-ab98-21ad865fac33', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/5/partition/10', u'type': u'partition', u'id': 10, u'size': 2397992648704}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'76h8ym', 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'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/5/'}, {u'size': 107374182400, u'model': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'53715915-134e-4d95-bbee-e107a47e513b', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'76h8ym', u'partition_table_type': None, u'filesystem': {u'uuid': u'61f1709b-d29e-4e6b-8366-4f553f3f9b09', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/15/'}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'power_state': u'on', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/5/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'd57db9f3-fd5c-462f-b9fc-222c6a17d49f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'76h8ym', u'device_id': 5, u'filesystem': {u'uuid': u'fc056b50-0b98-4501-ab98-21ad865fac33', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/5/partition/10', u'type': u'partition', u'id': 10, u'size': 2397992648704}], u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'76h8ym', 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'type': u'physical', u'id': 5, u'name': u'sda'}], 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'76h8ym', u'id': 10}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/5/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'd57db9f3-fd5c-462f-b9fc-222c6a17d49f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'76h8ym', u'device_id': 5, u'filesystem': {u'uuid': u'fc056b50-0b98-4501-ab98-21ad865fac33', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/5/partition/10', u'type': u'partition', u'id': 10, u'size': 2397992648704}], u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'76h8ym', 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'type': u'physical', u'id': 5, u'name': u'sda'}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', 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'id': 19, u'mode': u'dhcp'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', 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'76h8ym', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/interfaces/4/'}, {u'name': u'enp9s0', u'links': [{u'id': 20, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'enabled': True, u'children': [], 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'76h8ym', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/interfaces/17/'}, {u'name': u'enp7s0', u'links': [{u'id': 21, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'enabled': True, u'children': [], 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'76h8ym', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/interfaces/20/'}, {u'name': u'enp8s0', u'links': [{u'id': 23, u'mode': u'link_up'}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'enabled': True, u'children': [], 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'76h8ym', u'type': u'physical', u'id': 23, u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/interfaces/23/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'node_type': 0, u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'available_size': 0, u'uuid': u'53715915-134e-4d95-bbee-e107a47e513b', u'resource_uri': u'/MAAS/api/2.0/nodes/76h8ym/blockdevices/15/', u'used_size': 107374182400, u'partitions': [], u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'76h8ym', u'partition_table_type': None, u'filesystem': {u'uuid': u'61f1709b-d29e-4e6b-8366-4f553f3f9b09', u'label': u'root', u'mount_point': u'/', u'mount_options': None, 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'type': u'virtual', u'id': 15, u'name': u'vgroot-lvroot'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'current_commissioning_result_id': 2, u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/76h8ym/', u'distro_series': u'', u'memory_test_status': -1}
2019-03-14 09:08:57,649 [salt.state       :300 ][INFO    ][7928] {'new': {'storage_layout': 'lvm'}}
2019-03-14 09:08:57,649 [salt.state       :1951][INFO    ][7928] Completed state [maas_machines_storage_cmp002_lvm] at time 09:08:57.649636 duration_in_ms=2981.114
2019-03-14 09:08:57,650 [salt.state       :1780][INFO    ][7928] Running state [maas_machines_storage_cmp001_lvm] at time 09:08:57.650206
2019-03-14 09:08:57,650 [salt.state       :1813][INFO    ][7928] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-03-14 09:08:59,176 [salt.loaded.ext.module.maasng:610 ][INFO    ][7928] sqx4fh
2019-03-14 09:08:59,176 [salt.loaded.ext.module.maasng:626 ][INFO    ][7928] sda
2019-03-14 09:08:59,693 [salt.loaded.ext.module.maasng:361 ][INFO    ][7928] sqx4fh
2019-03-14 09:08:59,802 [salt.loaded.ext.module.maasng:367 ][INFO    ][7928] [{u'size': 2397998940160, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'80fc6eaf-5322-4833-9c3d-21bd5a6c7332', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'sqx4fh', u'filesystem': {u'uuid': u'7a9f6dbf-807f-4ce2-af75-2929ff2185fb', u'label': None, u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/2/partition/7'}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'sqx4fh', 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'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 2, u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/2/'}, {u'size': 2397988454400, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'uuid': u'209f39e0-b919-4f56-9e5e-d06623022f94', u'label': u'root', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'uuid': u'34b33256-f720-4d36-9446-e15cccd8f4f0', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'sqx4fh', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 12, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/12/'}]
2019-03-14 09:08:59,802 [salt.loaded.ext.module.maasng:632 ][INFO    ][7928] vgroot
2019-03-14 09:08:59,803 [salt.loaded.ext.module.maasng:635 ][INFO    ][7928] lvroot
2019-03-14 09:08:59,803 [salt.loaded.ext.module.maasng:639 ][INFO    ][7928] 107374182400
2019-03-14 09:09:00,479 [salt.loaded.ext.module.maasng:645 ][INFO    ][7928] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.38'], u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'modules-final', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'9a8eefcb-12b3-4e9d-a0df-e3a104942511', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'sqx4fh', u'filesystem': {u'uuid': u'b57a6c22-cc3b-49d1-a88e-a4d069252da8', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/2/partition/11', u'type': u'partition', u'id': 11, u'device_id': 2}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'sqx4fh', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/2/'}, u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'sqx4fh', 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"'cloudinit' running modules for final", u'disable_ipv4': False, u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'9a8eefcb-12b3-4e9d-a0df-e3a104942511', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'sqx4fh', u'filesystem': {u'uuid': u'b57a6c22-cc3b-49d1-a88e-a4d069252da8', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/2/partition/11', u'type': u'partition', u'id': 11, u'device_id': 2}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'sqx4fh', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'size': 2397998940160, u'type': u'physical', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/2/'}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'7ba41ceb-2c99-4907-8cc1-50893139f21e', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'sqx4fh', u'partition_table_type': None, u'filesystem': {u'uuid': u'731e886e-3c11-4170-a28d-c49ab5dc780f', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'size': 107374182400, u'type': u'virtual', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/16/'}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'on', u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'sqx4fh', u'id': 11}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_interface': {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', 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': 43, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', 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'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'sqx4fh', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/interfaces/5/'}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'partitions': [{u'size': 2397992648704, u'uuid': u'9a8eefcb-12b3-4e9d-a0df-e3a104942511', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'sqx4fh', u'filesystem': {u'uuid': u'b57a6c22-cc3b-49d1-a88e-a4d069252da8', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/2/partition/11', u'type': u'partition', u'id': 11, u'device_id': 2}], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'sqx4fh', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/2/'}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'uuid': u'7ba41ceb-2c99-4907-8cc1-50893139f21e', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'sqx4fh', u'partition_table_type': None, u'filesystem': {u'uuid': u'731e886e-3c11-4170-a28d-c49ab5dc780f', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/blockdevices/16/'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', 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': 43, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', 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'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'sqx4fh', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/interfaces/5/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'name': u'enp9s0', u'links': [{u'id': 45, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'system_id': u'sqx4fh', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/interfaces/12/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'name': u'enp7s0', u'links': [{u'id': 47, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'system_id': u'sqx4fh', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/interfaces/15/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'name': u'enp8s0', u'links': [{u'id': 50, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'system_id': u'sqx4fh', u'type': u'physical', u'id': 22, u'resource_uri': u'/MAAS/api/2.0/nodes/sqx4fh/interfaces/22/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/sqx4fh/'}
2019-03-14 09:09:00,480 [salt.state       :300 ][INFO    ][7928] {'new': {'storage_layout': 'lvm'}}
2019-03-14 09:09:00,481 [salt.state       :1951][INFO    ][7928] Completed state [maas_machines_storage_cmp001_lvm] at time 09:09:00.481163 duration_in_ms=2830.957
2019-03-14 09:09:00,484 [salt.minion      :1711][INFO    ][7928] Returning information for job: 20190314090849611952
2019-03-14 09:09:01,054 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314090901040532
2019-03-14 09:09:01,076 [salt.minion      :1432][INFO    ][8059] Starting a new job with PID 8059
2019-03-14 09:09:01,696 [salt.state       :915 ][INFO    ][8059] Loading fresh modules for state activity
2019-03-14 09:09:01,749 [salt.fileclient  :1219][INFO    ][8059] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-03-14 09:09:01,791 [salt.state       :1780][INFO    ][8059] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:01.791843
2019-03-14 09:09:01,792 [salt.state       :1813][INFO    ][8059] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:09:01,794 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8059] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:09:03,238 [salt.state       :300 ][INFO    ][8059] {'pid': 8066, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:09:03,239 [salt.state       :1951][INFO    ][8059] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:03.239262 duration_in_ms=1447.42
2019-03-14 09:09:03,240 [salt.state       :1780][INFO    ][8059] Running state [maas.deploy_machines] at time 09:09:03.240424
2019-03-14 09:09:03,240 [salt.state       :1813][INFO    ][8059] Executing state module.run for [maas.deploy_machines]
2019-03-14 09:09:03,240 [salt.utils.decorators:613 ][WARNING ][8059] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:09:03,969 [salt.loaded.ext.module.maas:684 ][INFO    ][8059] deploymachines hwe_kernel=hwe-16.04 system_id=76h8ym distro_series=xenial
2019-03-14 09:09:06,551 [salt.loaded.ext.module.maas:684 ][INFO    ][8059] deploymachines hwe_kernel=hwe-16.04 system_id=sqx4fh distro_series=xenial
2019-03-14 09:09:09,014 [salt.loaded.ext.module.maas:684 ][INFO    ][8059] deploymachines hwe_kernel=hwe-16.04 system_id=tyqd8e distro_series=xenial
2019-03-14 09:09:11,554 [salt.loaded.ext.module.maas:684 ][INFO    ][8059] deploymachines hwe_kernel=hwe-16.04 system_id=exyay3 distro_series=xenial
2019-03-14 09:09:14,156 [salt.loaded.ext.module.maas:684 ][INFO    ][8059] deploymachines hwe_kernel=hwe-16.04 system_id=r3r3sy distro_series=xenial
2019-03-14 09:09:16,080 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090916068043
2019-03-14 09:09:16,100 [salt.minion      :1432][INFO    ][8328] Starting a new job with PID 8328
2019-03-14 09:09:16,119 [salt.minion      :1711][INFO    ][8328] Returning information for job: 20190314090916068043
2019-03-14 09:09:16,451 [salt.state       :300 ][INFO    ][8059] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-03-14 09:09:16,451 [salt.state       :1951][INFO    ][8059] Completed state [maas.deploy_machines] at time 09:09:16.451895 duration_in_ms=13211.468
2019-03-14 09:09:16,455 [salt.minion      :1711][INFO    ][8059] Returning information for job: 20190314090901040532
2019-03-14 09:09:17,095 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314090917080000
2019-03-14 09:09:17,117 [salt.minion      :1432][INFO    ][8342] Starting a new job with PID 8342
2019-03-14 09:09:20,838 [salt.state       :915 ][INFO    ][8342] Loading fresh modules for state activity
2019-03-14 09:09:20,871 [salt.fileclient  :1219][INFO    ][8342] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-03-14 09:09:20,911 [salt.state       :1780][INFO    ][8342] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:20.911608
2019-03-14 09:09:20,911 [salt.state       :1813][INFO    ][8342] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:09:20,913 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8342] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:09:22,305 [salt.state       :300 ][INFO    ][8342] {'pid': 8360, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:09:22,306 [salt.state       :1951][INFO    ][8342] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:22.306782 duration_in_ms=1395.173
2019-03-14 09:09:22,309 [salt.state       :1780][INFO    ][8342] Running state [maas.wait_for_machine_status] at time 09:09:22.309353
2019-03-14 09:09:22,309 [salt.state       :1813][INFO    ][8342] Executing state module.run for [maas.wait_for_machine_status]
2019-03-14 09:09:22,310 [salt.utils.decorators:613 ][WARNING ][8342] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:09:26,056 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.26540899s left)
2019-03-14 09:09:32,134 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314090932117254
2019-03-14 09:09:32,157 [salt.minion      :1432][INFO    ][8374] Starting a new job with PID 8374
2019-03-14 09:09:32,181 [salt.minion      :1711][INFO    ][8374] Returning information for job: 20190314090932117254
2019-03-14 09:09:59,754 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2212.56688285s left)
2019-03-14 09:10:02,193 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091002176989
2019-03-14 09:10:02,215 [salt.minion      :1432][INFO    ][8428] Starting a new job with PID 8428
2019-03-14 09:10:02,239 [salt.minion      :1711][INFO    ][8428] Returning information for job: 20190314091002176989
2019-03-14 09:10:32,286 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091032273991
2019-03-14 09:10:32,308 [salt.minion      :1432][INFO    ][8448] Starting a new job with PID 8448
2019-03-14 09:10:32,332 [salt.minion      :1711][INFO    ][8448] Returning information for job: 20190314091032273991
2019-03-14 09:10:33,344 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2178.9773109s left)
2019-03-14 09:11:02,332 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091102320399
2019-03-14 09:11:02,347 [salt.minion      :1432][INFO    ][8589] Starting a new job with PID 8589
2019-03-14 09:11:02,366 [salt.minion      :1711][INFO    ][8589] Returning information for job: 20190314091102320399
2019-03-14 09:11:06,673 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2145.64790797s left)
2019-03-14 09:11:32,374 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091132361787
2019-03-14 09:11:32,396 [salt.minion      :1432][INFO    ][8753] Starting a new job with PID 8753
2019-03-14 09:11:32,419 [salt.minion      :1711][INFO    ][8753] Returning information for job: 20190314091132361787
2019-03-14 09:11:39,934 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.38699484s left)
2019-03-14 09:12:02,428 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091202420596
2019-03-14 09:12:02,441 [salt.minion      :1432][INFO    ][9347] Starting a new job with PID 9347
2019-03-14 09:12:02,456 [salt.minion      :1711][INFO    ][9347] Returning information for job: 20190314091202420596
2019-03-14 09:12:12,748 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.573107s left)
2019-03-14 09:12:32,464 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091232449536
2019-03-14 09:12:32,479 [salt.minion      :1432][INFO    ][9490] Starting a new job with PID 9490
2019-03-14 09:12:32,503 [salt.minion      :1711][INFO    ][9490] Returning information for job: 20190314091232449536
2019-03-14 09:12:46,384 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2045.93682194s left)
2019-03-14 09:13:02,521 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091302508655
2019-03-14 09:13:02,543 [salt.minion      :1432][INFO    ][9717] Starting a new job with PID 9717
2019-03-14 09:13:02,565 [salt.minion      :1711][INFO    ][9717] Returning information for job: 20190314091302508655
2019-03-14 09:13:20,066 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.25535202s left)
2019-03-14 09:13:32,583 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091332569613
2019-03-14 09:13:32,604 [salt.minion      :1432][INFO    ][9760] Starting a new job with PID 9760
2019-03-14 09:13:32,628 [salt.minion      :1711][INFO    ][9760] Returning information for job: 20190314091332569613
2019-03-14 09:13:53,624 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1978.6974678s left)
2019-03-14 09:14:02,655 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091402641764
2019-03-14 09:14:02,678 [salt.minion      :1432][INFO    ][10090] Starting a new job with PID 10090
2019-03-14 09:14:02,701 [salt.minion      :1711][INFO    ][10090] Returning information for job: 20190314091402641764
2019-03-14 09:14:27,314 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1945.00727391s left)
2019-03-14 09:14:32,725 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091432712923
2019-03-14 09:14:32,747 [salt.minion      :1432][INFO    ][10133] Starting a new job with PID 10133
2019-03-14 09:14:32,770 [salt.minion      :1711][INFO    ][10133] Returning information for job: 20190314091432712923
2019-03-14 09:15:00,403 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1911.91790295s left)
2019-03-14 09:15:02,803 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091502789927
2019-03-14 09:15:02,826 [salt.minion      :1432][INFO    ][10457] Starting a new job with PID 10457
2019-03-14 09:15:02,850 [salt.minion      :1711][INFO    ][10457] Returning information for job: 20190314091502789927
2019-03-14 09:15:32,884 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091532871471
2019-03-14 09:15:32,905 [salt.minion      :1432][INFO    ][10476] Starting a new job with PID 10476
2019-03-14 09:15:32,929 [salt.minion      :1711][INFO    ][10476] Returning information for job: 20190314091532871471
2019-03-14 09:15:34,135 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1878.18611789s left)
2019-03-14 09:16:02,972 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091602959388
2019-03-14 09:16:02,995 [salt.minion      :1432][INFO    ][10634] Starting a new job with PID 10634
2019-03-14 09:16:03,018 [salt.minion      :1711][INFO    ][10634] Returning information for job: 20190314091602959388
2019-03-14 09:16:07,862 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1844.45930481s left)
2019-03-14 09:16:33,190 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091633174329
2019-03-14 09:16:33,212 [salt.minion      :1432][INFO    ][10756] Starting a new job with PID 10756
2019-03-14 09:16:33,232 [salt.minion      :1711][INFO    ][10756] Returning information for job: 20190314091633174329
2019-03-14 09:16:41,572 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1810.74897003s left)
2019-03-14 09:17:03,289 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091703277169
2019-03-14 09:17:03,311 [salt.minion      :1432][INFO    ][11262] Starting a new job with PID 11262
2019-03-14 09:17:03,333 [salt.minion      :1711][INFO    ][11262] Returning information for job: 20190314091703277169
2019-03-14 09:17:15,072 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1777.24966788s left)
2019-03-14 09:17:33,391 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091733380644
2019-03-14 09:17:33,413 [salt.minion      :1432][INFO    ][11296] Starting a new job with PID 11296
2019-03-14 09:17:33,433 [salt.minion      :1711][INFO    ][11296] Returning information for job: 20190314091733380644
2019-03-14 09:17:48,581 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1743.74035883s left)
2019-03-14 09:18:03,506 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091803493352
2019-03-14 09:18:03,530 [salt.minion      :1432][INFO    ][11336] Starting a new job with PID 11336
2019-03-14 09:18:03,552 [salt.minion      :1711][INFO    ][11336] Returning information for job: 20190314091803493352
2019-03-14 09:18:22,060 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1710.26135302s left)
2019-03-14 09:18:33,624 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091833611394
2019-03-14 09:18:33,647 [salt.minion      :1432][INFO    ][11366] Starting a new job with PID 11366
2019-03-14 09:18:33,669 [salt.minion      :1711][INFO    ][11366] Returning information for job: 20190314091833611394
2019-03-14 09:18:55,048 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1677.27367496s left)
2019-03-14 09:19:03,751 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091903737674
2019-03-14 09:19:03,774 [salt.minion      :1432][INFO    ][11408] Starting a new job with PID 11408
2019-03-14 09:19:03,797 [salt.minion      :1711][INFO    ][11408] Returning information for job: 20190314091903737674
2019-03-14 09:19:28,316 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1644.00493884s left)
2019-03-14 09:19:33,886 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314091933873144
2019-03-14 09:19:33,908 [salt.minion      :1432][INFO    ][11437] Starting a new job with PID 11437
2019-03-14 09:19:33,932 [salt.minion      :1711][INFO    ][11437] Returning information for job: 20190314091933873144
2019-03-14 09:20:01,556 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1610.76537085s left)
2019-03-14 09:20:04,025 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092004012977
2019-03-14 09:20:04,047 [salt.minion      :1432][INFO    ][11482] Starting a new job with PID 11482
2019-03-14 09:20:04,069 [salt.minion      :1711][INFO    ][11482] Returning information for job: 20190314092004012977
2019-03-14 09:20:34,175 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092034160950
2019-03-14 09:20:34,194 [salt.minion      :1432][INFO    ][11519] Starting a new job with PID 11519
2019-03-14 09:20:34,216 [salt.minion      :1711][INFO    ][11519] Returning information for job: 20190314092034160950
2019-03-14 09:20:35,215 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1577.10629082s left)
2019-03-14 09:21:04,339 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092104323604
2019-03-14 09:21:04,358 [salt.minion      :1432][INFO    ][11565] Starting a new job with PID 11565
2019-03-14 09:21:04,380 [salt.minion      :1711][INFO    ][11565] Returning information for job: 20190314092104323604
2019-03-14 09:21:08,204 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1544.11802983s left)
2019-03-14 09:21:34,502 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092134488846
2019-03-14 09:21:34,524 [salt.minion      :1432][INFO    ][11600] Starting a new job with PID 11600
2019-03-14 09:21:34,547 [salt.minion      :1711][INFO    ][11600] Returning information for job: 20190314092134488846
2019-03-14 09:21:41,647 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1510.6739099s left)
2019-03-14 09:22:04,679 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092204666419
2019-03-14 09:22:04,701 [salt.minion      :1432][INFO    ][11646] Starting a new job with PID 11646
2019-03-14 09:22:04,726 [salt.minion      :1711][INFO    ][11646] Returning information for job: 20190314092204666419
2019-03-14 09:22:15,078 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1477.24304891s left)
2019-03-14 09:22:34,865 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092234852830
2019-03-14 09:22:34,886 [salt.minion      :1432][INFO    ][11678] Starting a new job with PID 11678
2019-03-14 09:22:34,908 [salt.minion      :1711][INFO    ][11678] Returning information for job: 20190314092234852830
2019-03-14 09:22:48,450 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1443.87125993s left)
2019-03-14 09:23:05,065 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092305051942
2019-03-14 09:23:05,087 [salt.minion      :1432][INFO    ][11862] Starting a new job with PID 11862
2019-03-14 09:23:05,112 [salt.minion      :1711][INFO    ][11862] Returning information for job: 20190314092305051942
2019-03-14 09:23:21,673 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1410.64776182s left)
2019-03-14 09:23:35,279 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092335266241
2019-03-14 09:23:35,301 [salt.minion      :1432][INFO    ][11903] Starting a new job with PID 11903
2019-03-14 09:23:35,324 [salt.minion      :1711][INFO    ][11903] Returning information for job: 20190314092335266241
2019-03-14 09:23:55,207 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1377.11389089s left)
2019-03-14 09:24:05,501 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092405489222
2019-03-14 09:24:05,522 [salt.minion      :1432][INFO    ][11949] Starting a new job with PID 11949
2019-03-14 09:24:05,545 [salt.minion      :1711][INFO    ][11949] Returning information for job: 20190314092405489222
2019-03-14 09:24:28,597 [salt.loaded.ext.module.maas:1023][INFO    ][8342] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1343.72400188s left)
2019-03-14 09:24:35,729 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092435716404
2019-03-14 09:24:35,750 [salt.minion      :1432][INFO    ][11984] Starting a new job with PID 11984
2019-03-14 09:24:35,774 [salt.minion      :1711][INFO    ][11984] Returning information for job: 20190314092435716404
2019-03-14 09:25:02,187 [salt.loaded.ext.module.maas:993 ][INFO    ][8342] Machine r3r3sy mark broken
2019-03-14 09:25:02,957 [salt.loaded.ext.module.maas:996 ][INFO    ][8342] Machine r3r3sy mark fixed
2019-03-14 09:25:04,069 [salt.loaded.ext.module.maas:684 ][INFO    ][8342] deploymachines hwe_kernel=hwe-16.04 system_id=r3r3sy distro_series=xenial
2019-03-14 09:25:05,762 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092505750068
2019-03-14 09:25:05,782 [salt.minion      :1432][INFO    ][12094] Starting a new job with PID 12094
2019-03-14 09:25:05,805 [salt.minion      :1711][INFO    ][12094] Returning information for job: 20190314092505750068
2019-03-14 09:25:06,820 [salt.loaded.ext.module.maas:160 ][ERROR   ][8342] Failed for object kvm02 reason Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node.
2019-03-14 09:25:06,822 [salt.state       :302 ][ERROR   ][8342] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {'kvm02': "Unable to change power state to 'cycle' for node kvm02: another action is already in progress for that node."}, 'success': []}
2019-03-14 09:25:06,822 [salt.state       :1951][INFO    ][8342] Completed state [maas.wait_for_machine_status] at time 09:25:06.822606 duration_in_ms=944513.248
2019-03-14 09:25:06,827 [salt.minion      :1711][INFO    ][8342] Returning information for job: 20190314090917080000
2019-03-14 09:25:17,548 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command pillar.get with jid 20190314092517542342
2019-03-14 09:25:17,570 [salt.minion      :1432][INFO    ][12112] Starting a new job with PID 12112
2019-03-14 09:25:17,578 [salt.minion      :1711][INFO    ][12112] Returning information for job: 20190314092517542342
2019-03-14 09:25:18,087 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command service.status with jid 20190314092518075307
2019-03-14 09:25:18,108 [salt.minion      :1432][INFO    ][12117] Starting a new job with PID 12117
2019-03-14 09:25:18,492 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12117] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-03-14 09:25:18,524 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][12117] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-03-14 09:25:18,539 [salt.minion      :1711][INFO    ][12117] Returning information for job: 20190314092518075307
2019-03-14 09:25:19,083 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314092519070368
2019-03-14 09:25:19,103 [salt.minion      :1432][INFO    ][12128] Starting a new job with PID 12128
2019-03-14 09:25:22,799 [salt.state       :915 ][INFO    ][12128] Loading fresh modules for state activity
2019-03-14 09:25:23,240 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command 'salt-minion --version' in directory '/root'
2019-03-14 09:25:23,497 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command 'salt-minion --version' in directory '/root'
2019-03-14 09:25:24,351 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command 'salt-minion --version' in directory '/root'
2019-03-14 09:25:24,578 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command 'salt-minion --version' in directory '/root'
2019-03-14 09:25:25,833 [salt.state       :1780][INFO    ][12128] Running state [salt-minion] at time 09:25:25.833248
2019-03-14 09:25:25,833 [salt.state       :1813][INFO    ][12128] Executing state pkg.installed for [salt-minion]
2019-03-14 09:25:25,834 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-03-14 09:25:25,931 [salt.state       :300 ][INFO    ][12128] All specified packages are already installed
2019-03-14 09:25:25,932 [salt.state       :1951][INFO    ][12128] Completed state [salt-minion] at time 09:25:25.931941 duration_in_ms=98.692
2019-03-14 09:25:25,932 [salt.state       :1780][INFO    ][12128] Running state [salt_minion_dependency_packages] at time 09:25:25.932345
2019-03-14 09:25:25,932 [salt.state       :1813][INFO    ][12128] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-03-14 09:25:25,940 [salt.state       :300 ][INFO    ][12128] All specified packages are already installed
2019-03-14 09:25:25,941 [salt.state       :1951][INFO    ][12128] Completed state [salt_minion_dependency_packages] at time 09:25:25.941036 duration_in_ms=8.69
2019-03-14 09:25:25,944 [salt.state       :1780][INFO    ][12128] Running state [/etc/salt/minion.d/minion.conf] at time 09:25:25.944737
2019-03-14 09:25:25,945 [salt.state       :1813][INFO    ][12128] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-03-14 09:25:26,168 [salt.state       :300 ][INFO    ][12128] File /etc/salt/minion.d/minion.conf is in the correct state
2019-03-14 09:25:26,169 [salt.state       :1951][INFO    ][12128] Completed state [/etc/salt/minion.d/minion.conf] at time 09:25:26.169181 duration_in_ms=224.444
2019-03-14 09:25:26,169 [salt.state       :1780][INFO    ][12128] Running state [python-netaddr] at time 09:25:26.169574
2019-03-14 09:25:26,169 [salt.state       :1813][INFO    ][12128] Executing state pkg.installed for [python-netaddr]
2019-03-14 09:25:26,181 [salt.state       :300 ][INFO    ][12128] All specified packages are already installed
2019-03-14 09:25:26,181 [salt.state       :1951][INFO    ][12128] Completed state [python-netaddr] at time 09:25:26.181476 duration_in_ms=11.901
2019-03-14 09:25:26,186 [salt.state       :1780][INFO    ][12128] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 09:25:26.186182
2019-03-14 09:25:26,186 [salt.state       :1813][INFO    ][12128] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-03-14 09:25:26,199 [salt.state       :300 ][INFO    ][12128] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-03-14 09:25:26,199 [salt.state       :1951][INFO    ][12128] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 09:25:26.199814 duration_in_ms=13.632
2019-03-14 09:25:26,201 [salt.state       :1780][INFO    ][12128] Running state [salt-minion] at time 09:25:26.201321
2019-03-14 09:25:26,201 [salt.state       :1813][INFO    ][12128] Executing state service.running for [salt-minion]
2019-03-14 09:25:26,202 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-03-14 09:25:26,239 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-03-14 09:25:26,256 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-03-14 09:25:26,273 [salt.state       :300 ][INFO    ][12128] The service salt-minion is already running
2019-03-14 09:25:26,274 [salt.state       :1951][INFO    ][12128] Completed state [salt-minion] at time 09:25:26.274065 duration_in_ms=72.744
2019-03-14 09:25:26,276 [salt.state       :1780][INFO    ][12128] Running state [/etc/salt/grains.d] at time 09:25:26.276101
2019-03-14 09:25:26,276 [salt.state       :1813][INFO    ][12128] Executing state file.directory for [/etc/salt/grains.d]
2019-03-14 09:25:26,277 [salt.state       :300 ][INFO    ][12128] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-03-14 09:25:26,278 [salt.state       :1951][INFO    ][12128] Completed state [/etc/salt/grains.d] at time 09:25:26.278122 duration_in_ms=2.022
2019-03-14 09:25:26,279 [salt.state       :1780][INFO    ][12128] Running state [/etc/salt/grains] at time 09:25:26.279016
2019-03-14 09:25:26,279 [salt.state       :1813][INFO    ][12128] Executing state file.managed for [/etc/salt/grains]
2019-03-14 09:25:26,280 [salt.state       :300 ][INFO    ][12128] File /etc/salt/grains exists with proper permissions. No changes made.
2019-03-14 09:25:26,280 [salt.state       :1951][INFO    ][12128] Completed state [/etc/salt/grains] at time 09:25:26.280411 duration_in_ms=1.395
2019-03-14 09:25:26,281 [salt.state       :1780][INFO    ][12128] Running state [/etc/salt/grains.d/placeholder] at time 09:25:26.281046
2019-03-14 09:25:26,281 [salt.state       :1813][INFO    ][12128] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-03-14 09:25:26,282 [salt.state       :300 ][INFO    ][12128] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-03-14 09:25:26,282 [salt.state       :1951][INFO    ][12128] Completed state [/etc/salt/grains.d/placeholder] at time 09:25:26.282386 duration_in_ms=1.339
2019-03-14 09:25:26,283 [salt.state       :1780][INFO    ][12128] Running state [/etc/salt/grains.d/sphinx] at time 09:25:26.283024
2019-03-14 09:25:26,283 [salt.state       :1813][INFO    ][12128] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-03-14 09:25:26,300 [salt.state       :300 ][INFO    ][12128] File /etc/salt/grains.d/sphinx is in the correct state
2019-03-14 09:25:26,300 [salt.state       :1951][INFO    ][12128] Completed state [/etc/salt/grains.d/sphinx] at time 09:25:26.300405 duration_in_ms=17.381
2019-03-14 09:25:26,303 [salt.state       :1780][INFO    ][12128] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 09:25:26.303162
2019-03-14 09:25:26,303 [salt.state       :1813][INFO    ][12128] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-03-14 09:25:26,304 [salt.state       :300 ][INFO    ][12128] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-03-14 09:25:26,304 [salt.state       :1951][INFO    ][12128] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 09:25:26.304226 duration_in_ms=1.064
2019-03-14 09:25:26,304 [salt.state       :1780][INFO    ][12128] Running state [/etc/salt/grains.d/dns_records] at time 09:25:26.304813
2019-03-14 09:25:26,305 [salt.state       :1813][INFO    ][12128] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-03-14 09:25:26,317 [salt.state       :300 ][INFO    ][12128] File /etc/salt/grains.d/dns_records is in the correct state
2019-03-14 09:25:26,318 [salt.state       :1951][INFO    ][12128] Completed state [/etc/salt/grains.d/dns_records] at time 09:25:26.318231 duration_in_ms=13.417
2019-03-14 09:25:26,319 [salt.state       :1780][INFO    ][12128] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 09:25:26.319378
2019-03-14 09:25:26,319 [salt.state       :1813][INFO    ][12128] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-03-14 09:25:26,320 [salt.state       :300 ][INFO    ][12128] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-03-14 09:25:26,320 [salt.state       :1951][INFO    ][12128] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 09:25:26.320428 duration_in_ms=1.05
2019-03-14 09:25:26,321 [salt.state       :1780][INFO    ][12128] Running state [/etc/salt/grains.d/salt] at time 09:25:26.321036
2019-03-14 09:25:26,321 [salt.state       :1813][INFO    ][12128] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-03-14 09:25:26,336 [salt.state       :300 ][INFO    ][12128] File /etc/salt/grains.d/salt is in the correct state
2019-03-14 09:25:26,336 [salt.state       :1951][INFO    ][12128] Completed state [/etc/salt/grains.d/salt] at time 09:25:26.336310 duration_in_ms=15.275
2019-03-14 09:25:26,337 [salt.state       :1780][INFO    ][12128] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 09:25:26.337630
2019-03-14 09:25:26,338 [salt.state       :1813][INFO    ][12128] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-03-14 09:25:26,338 [salt.state       :300 ][INFO    ][12128] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-03-14 09:25:26,338 [salt.state       :1951][INFO    ][12128] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 09:25:26.338839 duration_in_ms=1.209
2019-03-14 09:25:26,341 [salt.state       :1780][INFO    ][12128] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 09:25:26.341685
2019-03-14 09:25:26,342 [salt.state       :1813][INFO    ][12128] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-03-14 09:25:26,342 [salt.state       :300 ][INFO    ][12128] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-03-14 09:25:26,342 [salt.state       :1951][INFO    ][12128] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 09:25:26.342919 duration_in_ms=1.234
2019-03-14 09:25:26,343 [salt.state       :1780][INFO    ][12128] Running state [mine.update] at time 09:25:26.343915
2019-03-14 09:25:26,344 [salt.state       :1813][INFO    ][12128] Executing state module.wait for [mine.update]
2019-03-14 09:25:26,344 [salt.state       :300 ][INFO    ][12128] No changes made for mine.update
2019-03-14 09:25:26,345 [salt.state       :1951][INFO    ][12128] Completed state [mine.update] at time 09:25:26.345042 duration_in_ms=1.127
2019-03-14 09:25:26,345 [salt.state       :1780][INFO    ][12128] Running state [ca-certificates] at time 09:25:26.345384
2019-03-14 09:25:26,345 [salt.state       :1813][INFO    ][12128] Executing state pkg.installed for [ca-certificates]
2019-03-14 09:25:26,356 [salt.state       :300 ][INFO    ][12128] All specified packages are already installed
2019-03-14 09:25:26,356 [salt.state       :1951][INFO    ][12128] Completed state [ca-certificates] at time 09:25:26.356535 duration_in_ms=11.151
2019-03-14 09:25:26,357 [salt.state       :1780][INFO    ][12128] Running state [update-ca-certificates] at time 09:25:26.357480
2019-03-14 09:25:26,357 [salt.state       :1813][INFO    ][12128] Executing state cmd.wait for [update-ca-certificates]
2019-03-14 09:25:26,358 [salt.state       :300 ][INFO    ][12128] No changes made for update-ca-certificates
2019-03-14 09:25:26,358 [salt.state       :1951][INFO    ][12128] Completed state [update-ca-certificates] at time 09:25:26.358556 duration_in_ms=1.076
2019-03-14 09:25:26,358 [salt.state       :1780][INFO    ][12128] Running state [iptables] at time 09:25:26.358870
2019-03-14 09:25:26,359 [salt.state       :1813][INFO    ][12128] Executing state pkg.installed for [iptables]
2019-03-14 09:25:26,368 [salt.state       :300 ][INFO    ][12128] All specified packages are already installed
2019-03-14 09:25:26,368 [salt.state       :1951][INFO    ][12128] Completed state [iptables] at time 09:25:26.368888 duration_in_ms=10.017
2019-03-14 09:25:26,369 [salt.state       :1780][INFO    ][12128] Running state [iptables-persistent] at time 09:25:26.369192
2019-03-14 09:25:26,369 [salt.state       :1813][INFO    ][12128] Executing state pkg.installed for [iptables-persistent]
2019-03-14 09:25:26,378 [salt.state       :300 ][INFO    ][12128] All specified packages are already installed
2019-03-14 09:25:26,378 [salt.state       :1951][INFO    ][12128] Completed state [iptables-persistent] at time 09:25:26.378740 duration_in_ms=9.547
2019-03-14 09:25:26,380 [salt.state       :1780][INFO    ][12128] Running state [iptables_modules_v4_load] at time 09:25:26.379966
2019-03-14 09:25:26,380 [salt.state       :1813][INFO    ][12128] Executing state kmod.present for [iptables_modules_v4_load]
2019-03-14 09:25:26,381 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command 'lsmod' in directory '/root'
2019-03-14 09:25:26,401 [salt.state       :300 ][INFO    ][12128] Kernel modules iptable_filter, ip_tables are already present
2019-03-14 09:25:26,402 [salt.state       :1951][INFO    ][12128] Completed state [iptables_modules_v4_load] at time 09:25:26.402055 duration_in_ms=22.089
2019-03-14 09:25:26,403 [salt.state       :1780][INFO    ][12128] Running state [/etc/iptables/rules.v4] at time 09:25:26.402993
2019-03-14 09:25:26,403 [salt.state       :1813][INFO    ][12128] Executing state file.managed for [/etc/iptables/rules.v4]
2019-03-14 09:25:26,509 [salt.state       :300 ][INFO    ][12128] File /etc/iptables/rules.v4 is in the correct state
2019-03-14 09:25:26,510 [salt.state       :1951][INFO    ][12128] Completed state [/etc/iptables/rules.v4] at time 09:25:26.510077 duration_in_ms=107.083
2019-03-14 09:25:26,511 [salt.state       :1780][INFO    ][12128] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 09:25:26.511215
2019-03-14 09:25:26,511 [salt.state       :1813][INFO    ][12128] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-03-14 09:25:26,512 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-03-14 09:25:26,530 [salt.state       :300 ][INFO    ][12128] onlyif execution failed
2019-03-14 09:25:26,530 [salt.state       :1951][INFO    ][12128] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 09:25:26.530601 duration_in_ms=19.386
2019-03-14 09:25:26,531 [salt.state       :1780][INFO    ][12128] Running state [netfilter-persistent] at time 09:25:26.531697
2019-03-14 09:25:26,532 [salt.state       :1813][INFO    ][12128] Executing state service.running for [netfilter-persistent]
2019-03-14 09:25:26,532 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-03-14 09:25:26,550 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-03-14 09:25:26,566 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-03-14 09:25:26,581 [salt.state       :300 ][INFO    ][12128] The service netfilter-persistent is already running
2019-03-14 09:25:26,581 [salt.state       :1951][INFO    ][12128] Completed state [netfilter-persistent] at time 09:25:26.581578 duration_in_ms=49.881
2019-03-14 09:25:26,582 [salt.state       :1780][INFO    ][12128] Running state [iptables_extra.remove_stale_tables] at time 09:25:26.582396
2019-03-14 09:25:26,582 [salt.state       :1813][INFO    ][12128] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-03-14 09:25:26,583 [salt.state       :300 ][INFO    ][12128] No changes made for iptables_extra.remove_stale_tables
2019-03-14 09:25:26,583 [salt.state       :1951][INFO    ][12128] Completed state [iptables_extra.remove_stale_tables] at time 09:25:26.583310 duration_in_ms=0.914
2019-03-14 09:25:26,583 [salt.state       :1780][INFO    ][12128] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 09:25:26.583580
2019-03-14 09:25:26,583 [salt.state       :1813][INFO    ][12128] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-03-14 09:25:26,584 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12128] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-03-14 09:25:26,597 [salt.state       :300 ][INFO    ][12128] onlyif execution failed
2019-03-14 09:25:26,597 [salt.state       :1951][INFO    ][12128] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 09:25:26.597315 duration_in_ms=13.735
2019-03-14 09:25:26,598 [salt.state       :1780][INFO    ][12128] Running state [/etc/iptables/rules.v6] at time 09:25:26.598239
2019-03-14 09:25:26,598 [salt.state       :1813][INFO    ][12128] Executing state file.absent for [/etc/iptables/rules.v6]
2019-03-14 09:25:26,599 [salt.state       :300 ][INFO    ][12128] File /etc/iptables/rules.v6 is not present
2019-03-14 09:25:26,599 [salt.state       :1951][INFO    ][12128] Completed state [/etc/iptables/rules.v6] at time 09:25:26.599247 duration_in_ms=1.008
2019-03-14 09:25:26,599 [salt.state       :1780][INFO    ][12128] Running state [iptables_extra.flush_all] at time 09:25:26.599900
2019-03-14 09:25:26,600 [salt.state       :1813][INFO    ][12128] Executing state module.wait for [iptables_extra.flush_all]
2019-03-14 09:25:26,600 [salt.state       :300 ][INFO    ][12128] No changes made for iptables_extra.flush_all
2019-03-14 09:25:26,600 [salt.state       :1951][INFO    ][12128] Completed state [iptables_extra.flush_all] at time 09:25:26.600689 duration_in_ms=0.789
2019-03-14 09:25:26,603 [salt.minion      :1711][INFO    ][12128] Returning information for job: 20190314092519070368
2019-03-14 09:25:27,233 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314092527220174
2019-03-14 09:25:27,255 [salt.minion      :1432][INFO    ][12209] Starting a new job with PID 12209
2019-03-14 09:25:27,913 [salt.state       :915 ][INFO    ][12209] Loading fresh modules for state activity
2019-03-14 09:25:28,490 [salt.state       :1780][INFO    ][12209] Running state [maas-rack-controller] at time 09:25:28.490905
2019-03-14 09:25:28,491 [salt.state       :1813][INFO    ][12209] Executing state pkg.installed for [maas-rack-controller]
2019-03-14 09:25:28,491 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12209] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-03-14 09:25:28,649 [salt.state       :300 ][INFO    ][12209] All specified packages are already installed
2019-03-14 09:25:28,650 [salt.state       :1951][INFO    ][12209] Completed state [maas-rack-controller] at time 09:25:28.649976 duration_in_ms=159.072
2019-03-14 09:25:28,650 [salt.state       :1780][INFO    ][12209] Running state [ipmitool] at time 09:25:28.650279
2019-03-14 09:25:28,650 [salt.state       :1813][INFO    ][12209] Executing state pkg.installed for [ipmitool]
2019-03-14 09:25:28,656 [salt.state       :300 ][INFO    ][12209] All specified packages are already installed
2019-03-14 09:25:28,657 [salt.state       :1951][INFO    ][12209] Completed state [ipmitool] at time 09:25:28.656952 duration_in_ms=6.673
2019-03-14 09:25:28,659 [salt.state       :1780][INFO    ][12209] Running state [/etc/maas/rackd.conf] at time 09:25:28.659600
2019-03-14 09:25:28,659 [salt.state       :1813][INFO    ][12209] Executing state file.line for [/etc/maas/rackd.conf]
2019-03-14 09:25:28,660 [salt.state       :300 ][INFO    ][12209] No changes needed to be made
2019-03-14 09:25:28,661 [salt.state       :1951][INFO    ][12209] Completed state [/etc/maas/rackd.conf] at time 09:25:28.661050 duration_in_ms=1.45
2019-03-14 09:25:28,661 [salt.state       :1780][INFO    ][12209] Running state [/etc/maas/rackd.conf] at time 09:25:28.661271
2019-03-14 09:25:28,661 [salt.state       :1813][INFO    ][12209] Executing state file.managed for [/etc/maas/rackd.conf]
2019-03-14 09:25:28,661 [salt.loaded.int.states.file:2298][WARNING ][12209] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-03-14 09:25:28,662 [salt.state       :300 ][INFO    ][12209] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-03-14 09:25:28,662 [salt.state       :1951][INFO    ][12209] Completed state [/etc/maas/rackd.conf] at time 09:25:28.662446 duration_in_ms=1.175
2019-03-14 09:25:28,663 [salt.state       :1780][INFO    ][12209] Running state [maas-rackd] at time 09:25:28.663360
2019-03-14 09:25:28,663 [salt.state       :1813][INFO    ][12209] Executing state service.running for [maas-rackd]
2019-03-14 09:25:28,664 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12209] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-03-14 09:25:28,699 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12209] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-03-14 09:25:28,716 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12209] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-03-14 09:25:28,732 [salt.state       :300 ][INFO    ][12209] The service maas-rackd is already running
2019-03-14 09:25:28,732 [salt.state       :1951][INFO    ][12209] Completed state [maas-rackd] at time 09:25:28.732813 duration_in_ms=69.452
2019-03-14 09:25:28,734 [salt.minion      :1711][INFO    ][12209] Returning information for job: 20190314092527220174
2019-03-14 09:25:29,283 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314092529270827
2019-03-14 09:25:29,303 [salt.minion      :1432][INFO    ][12235] Starting a new job with PID 12235
2019-03-14 09:25:29,918 [salt.state       :915 ][INFO    ][12235] Loading fresh modules for state activity
2019-03-14 09:25:30,631 [salt.state       :1780][INFO    ][12235] Running state [maas-region-controller] at time 09:25:30.631107
2019-03-14 09:25:30,631 [salt.state       :1813][INFO    ][12235] Executing state pkg.installed for [maas-region-controller]
2019-03-14 09:25:30,631 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-03-14 09:25:30,725 [salt.state       :300 ][INFO    ][12235] All specified packages are already installed
2019-03-14 09:25:30,726 [salt.state       :1951][INFO    ][12235] Completed state [maas-region-controller] at time 09:25:30.726346 duration_in_ms=95.239
2019-03-14 09:25:30,726 [salt.state       :1780][INFO    ][12235] Running state [python-oauth] at time 09:25:30.726771
2019-03-14 09:25:30,727 [salt.state       :1813][INFO    ][12235] Executing state pkg.installed for [python-oauth]
2019-03-14 09:25:30,736 [salt.state       :300 ][INFO    ][12235] All specified packages are already installed
2019-03-14 09:25:30,736 [salt.state       :1951][INFO    ][12235] Completed state [python-oauth] at time 09:25:30.736935 duration_in_ms=10.164
2019-03-14 09:25:30,740 [salt.state       :1780][INFO    ][12235] Running state [/etc/maas/regiond.conf] at time 09:25:30.740452
2019-03-14 09:25:30,740 [salt.state       :1813][INFO    ][12235] Executing state file.replace for [/etc/maas/regiond.conf]
2019-03-14 09:25:30,786 [salt.state       :300 ][INFO    ][12235] No changes needed to be made
2019-03-14 09:25:30,786 [salt.state       :1951][INFO    ][12235] Completed state [/etc/maas/regiond.conf] at time 09:25:30.786699 duration_in_ms=46.248
2019-03-14 09:25:30,787 [salt.state       :1780][INFO    ][12235] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:25:30.787360
2019-03-14 09:25:30,787 [salt.state       :1813][INFO    ][12235] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-03-14 09:25:30,857 [salt.state       :300 ][INFO    ][12235] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-03-14 09:25:30,857 [salt.state       :1951][INFO    ][12235] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:25:30.857429 duration_in_ms=70.07
2019-03-14 09:25:30,858 [salt.state       :1780][INFO    ][12235] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:25:30.858052
2019-03-14 09:25:30,858 [salt.state       :1813][INFO    ][12235] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-03-14 09:25:30,876 [salt.state       :300 ][INFO    ][12235] No changes needed to be made
2019-03-14 09:25:30,877 [salt.state       :1951][INFO    ][12235] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:25:30.877087 duration_in_ms=19.034
2019-03-14 09:25:30,877 [salt.state       :1780][INFO    ][12235] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:25:30.877650
2019-03-14 09:25:30,878 [salt.state       :1813][INFO    ][12235] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-03-14 09:25:30,907 [salt.state       :300 ][INFO    ][12235] No changes needed to be made
2019-03-14 09:25:30,908 [salt.state       :1951][INFO    ][12235] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:25:30.908129 duration_in_ms=30.48
2019-03-14 09:25:30,909 [salt.state       :1780][INFO    ][12235] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:25:30.908949
2019-03-14 09:25:30,909 [salt.state       :1813][INFO    ][12235] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-03-14 09:25:30,951 [salt.state       :300 ][INFO    ][12235] No changes needed to be made
2019-03-14 09:25:30,953 [salt.state       :1951][INFO    ][12235] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:25:30.953334 duration_in_ms=44.383
2019-03-14 09:25:30,955 [salt.state       :1780][INFO    ][12235] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:25:30.955044
2019-03-14 09:25:30,955 [salt.state       :1813][INFO    ][12235] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-03-14 09:25:30,974 [salt.state       :300 ][INFO    ][12235] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-03-14 09:25:30,974 [salt.state       :1951][INFO    ][12235] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:25:30.974647 duration_in_ms=19.604
2019-03-14 09:25:30,978 [salt.state       :1780][INFO    ][12235] Running state [a2enmod headers] at time 09:25:30.978745
2019-03-14 09:25:30,979 [salt.state       :1813][INFO    ][12235] Executing state cmd.run for [a2enmod headers]
2019-03-14 09:25:30,980 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command 'a2enmod headers' in directory '/root'
2019-03-14 09:25:31,053 [salt.state       :300 ][INFO    ][12235] {'pid': 12254, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-03-14 09:25:31,054 [salt.state       :1951][INFO    ][12235] Completed state [a2enmod headers] at time 09:25:31.053987 duration_in_ms=75.242
2019-03-14 09:25:31,054 [salt.state       :1780][INFO    ][12235] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:25:31.054564
2019-03-14 09:25:31,055 [salt.state       :1813][INFO    ][12235] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-03-14 09:25:31,074 [salt.state       :300 ][INFO    ][12235] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-03-14 09:25:31,074 [salt.state       :1951][INFO    ][12235] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:25:31.074640 duration_in_ms=20.077
2019-03-14 09:25:31,075 [salt.state       :1780][INFO    ][12235] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:25:31.075481
2019-03-14 09:25:31,075 [salt.state       :1813][INFO    ][12235] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-03-14 09:25:31,156 [salt.state       :300 ][INFO    ][12235] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-03-14 09:25:31,157 [salt.state       :1951][INFO    ][12235] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:25:31.157262 duration_in_ms=81.78
2019-03-14 09:25:31,158 [salt.state       :1780][INFO    ][12235] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:25:31.157943
2019-03-14 09:25:31,158 [salt.state       :1813][INFO    ][12235] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-03-14 09:25:31,228 [salt.state       :300 ][INFO    ][12235] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-03-14 09:25:31,229 [salt.state       :1951][INFO    ][12235] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:25:31.228941 duration_in_ms=70.999
2019-03-14 09:25:31,229 [salt.state       :1780][INFO    ][12235] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:25:31.229507
2019-03-14 09:25:31,229 [salt.state       :1813][INFO    ][12235] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-03-14 09:25:31,294 [salt.state       :300 ][INFO    ][12235] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-03-14 09:25:31,294 [salt.state       :1951][INFO    ][12235] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:25:31.294792 duration_in_ms=65.286
2019-03-14 09:25:31,295 [salt.state       :1780][INFO    ][12235] Running state [/root/.pgpass] at time 09:25:31.295094
2019-03-14 09:25:31,295 [salt.state       :1813][INFO    ][12235] Executing state file.managed for [/root/.pgpass]
2019-03-14 09:25:31,348 [salt.state       :300 ][INFO    ][12235] File /root/.pgpass is in the correct state
2019-03-14 09:25:31,348 [salt.state       :1951][INFO    ][12235] Completed state [/root/.pgpass] at time 09:25:31.348690 duration_in_ms=53.596
2019-03-14 09:25:31,354 [salt.state       :1780][INFO    ][12235] Running state [maas-region syncdb --noinput] at time 09:25:31.354491
2019-03-14 09:25:31,354 [salt.state       :1813][INFO    ][12235] Executing state cmd.run for [maas-region syncdb --noinput]
2019-03-14 09:25:31,355 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-03-14 09:25:33,404 [salt.state       :300 ][INFO    ][12235] {'pid': 12267, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: metadataserver, piston3, contenttypes, auth, sessions, 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-03-14 09:25:33,405 [salt.state       :1951][INFO    ][12235] Completed state [maas-region syncdb --noinput] at time 09:25:33.404917 duration_in_ms=2050.423
2019-03-14 09:25:33,405 [salt.state       :2022][WARNING ][12235] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-03-14 09:25:33,407 [salt.state       :1780][INFO    ][12235] Running state [maas-regiond] at time 09:25:33.407764
2019-03-14 09:25:33,408 [salt.state       :1813][INFO    ][12235] Executing state service.running for [maas-regiond]
2019-03-14 09:25:33,409 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-03-14 09:25:33,450 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-03-14 09:25:33,467 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-03-14 09:25:33,482 [salt.state       :300 ][INFO    ][12235] The service maas-regiond is already running
2019-03-14 09:25:33,483 [salt.state       :1951][INFO    ][12235] Completed state [maas-regiond] at time 09:25:33.483028 duration_in_ms=75.263
2019-03-14 09:25:33,485 [salt.state       :1780][INFO    ][12235] Running state [bind9] at time 09:25:33.484959
2019-03-14 09:25:33,485 [salt.state       :1813][INFO    ][12235] Executing state service.running for [bind9]
2019-03-14 09:25:33,486 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-03-14 09:25:33,503 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-03-14 09:25:33,519 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-03-14 09:25:33,535 [salt.state       :300 ][INFO    ][12235] The service bind9 is already running
2019-03-14 09:25:33,535 [salt.state       :1951][INFO    ][12235] Completed state [bind9] at time 09:25:33.535362 duration_in_ms=50.403
2019-03-14 09:25:33,537 [salt.state       :1780][INFO    ][12235] Running state [apache2] at time 09:25:33.537269
2019-03-14 09:25:33,537 [salt.state       :1813][INFO    ][12235] Executing state service.running for [apache2]
2019-03-14 09:25:33,538 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-03-14 09:25:33,555 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-03-14 09:25:33,571 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-03-14 09:25:33,590 [salt.state       :300 ][INFO    ][12235] The service apache2 is already running
2019-03-14 09:25:33,590 [salt.state       :1951][INFO    ][12235] Completed state [apache2] at time 09:25:33.590642 duration_in_ms=53.374
2019-03-14 09:25:33,592 [salt.state       :1780][INFO    ][12235] Running state [maasng.wait_for_http_code] at time 09:25:33.592193
2019-03-14 09:25:33,592 [salt.state       :1813][INFO    ][12235] Executing state module.run for [maasng.wait_for_http_code]
2019-03-14 09:25:33,593 [salt.utils.decorators:613 ][WARNING ][12235] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:25:33,698 [salt.state       :300 ][INFO    ][12235] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-03-14 09:25:33,698 [salt.state       :1951][INFO    ][12235] Completed state [maasng.wait_for_http_code] at time 09:25:33.698473 duration_in_ms=106.279
2019-03-14 09:25:33,699 [salt.state       :1780][INFO    ][12235] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:25:33.699619
2019-03-14 09:25:33,700 [salt.state       :1813][INFO    ][12235] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-03-14 09:25:33,700 [salt.state       :300 ][INFO    ][12235] /var/lib/maas/.setup_admin exists
2019-03-14 09:25:33,701 [salt.state       :1951][INFO    ][12235] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:25:33.700943 duration_in_ms=1.324
2019-03-14 09:25:33,701 [salt.state       :1780][INFO    ][12235] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:25:33.701847
2019-03-14 09:25:33,702 [salt.state       :1813][INFO    ][12235] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:25:33,703 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12235] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:25:35,147 [salt.state       :300 ][INFO    ][12235] {'pid': 12298, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:25:35,147 [salt.state       :1951][INFO    ][12235] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:25:35.147479 duration_in_ms=1445.632
2019-03-14 09:25:35,151 [salt.state       :1780][INFO    ][12235] Running state [maas_region_boot_source_resources_mirror] at time 09:25:35.151029
2019-03-14 09:25:35,151 [salt.state       :1813][INFO    ][12235] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-03-14 09:25:35,256 [salt.state       :300 ][INFO    ][12235] {'changes': {}}
2019-03-14 09:25:35,257 [salt.state       :1951][INFO    ][12235] Completed state [maas_region_boot_source_resources_mirror] at time 09:25:35.257094 duration_in_ms=106.064
2019-03-14 09:25:35,258 [salt.state       :1780][INFO    ][12235] Running state [maasng.boot_resources_import] at time 09:25:35.258238
2019-03-14 09:25:35,258 [salt.state       :1813][INFO    ][12235] Executing state module.run for [maasng.boot_resources_import]
2019-03-14 09:25:35,259 [salt.utils.decorators:613 ][WARNING ][12235] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:25:35,365 [salt.loaded.ext.module.maasng:1600][INFO    ][12235] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-03-14 09:25:40,421 [salt.loaded.ext.module.maasng:1600][INFO    ][12235] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-03-14 09:25:44,407 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092544394378
2019-03-14 09:25:44,430 [salt.minion      :1432][INFO    ][12329] Starting a new job with PID 12329
2019-03-14 09:25:44,453 [salt.minion      :1711][INFO    ][12329] Returning information for job: 20190314092544394378
2019-03-14 09:25:45,486 [salt.loaded.ext.module.maasng:1600][INFO    ][12235] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-03-14 09:25:50,610 [salt.state       :300 ][INFO    ][12235] {'ret': True}
2019-03-14 09:25:50,610 [salt.state       :1951][INFO    ][12235] Completed state [maasng.boot_resources_import] at time 09:25:50.610457 duration_in_ms=15352.218
2019-03-14 09:25:50,611 [salt.state       :1780][INFO    ][12235] Running state [maas_region_boot_sources_selection_xenial] at time 09:25:50.611723
2019-03-14 09:25:50,612 [salt.state       :1813][INFO    ][12235] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-03-14 09:25:50,846 [salt.state       :300 ][INFO    ][12235] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-03-14 09:25:50,847 [salt.state       :1951][INFO    ][12235] Completed state [maas_region_boot_sources_selection_xenial] at time 09:25:50.847071 duration_in_ms=235.347
2019-03-14 09:25:50,848 [salt.state       :1780][INFO    ][12235] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 09:25:50.848465
2019-03-14 09:25:50,849 [salt.state       :1813][INFO    ][12235] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-03-14 09:25:50,849 [salt.utils.decorators:613 ][WARNING ][12235] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:25:50,850 [salt.loaded.ext.module.maasng:1771][INFO    ][12235] boot-sources sync initiated for ALL Rack's
2019-03-14 09:25:51,866 [salt.state       :300 ][INFO    ][12235] {'ret': True}
2019-03-14 09:25:51,867 [salt.state       :1951][INFO    ][12235] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 09:25:51.866979 duration_in_ms=1018.513
2019-03-14 09:25:51,869 [salt.state       :1780][INFO    ][12235] Running state [maas.process_maas_config] at time 09:25:51.869169
2019-03-14 09:25:51,869 [salt.state       :1813][INFO    ][12235] Executing state module.run for [maas.process_maas_config]
2019-03-14 09:25:51,870 [salt.utils.decorators:613 ][WARNING ][12235] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:25:51,871 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=enable_http_proxy value=True
2019-03-14 09:25:51,938 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=upstream_dns value=8.8.8.8
2019-03-14 09:25:52,007 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=commissioning_distro_series value=xenial
2019-03-14 09:25:55,078 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=default_osystem value=ubuntu
2019-03-14 09:25:55,151 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=active_discovery_interval value=600
2019-03-14 09:25:55,205 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=dnssec_validation value=no
2019-03-14 09:25:55,259 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=maas_name value=mas01
2019-03-14 09:25:55,348 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=network_discovery value=enabled
2019-03-14 09:25:55,457 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=enable_third_party_drivers value=True
2019-03-14 09:25:55,511 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=default_storage_layout value=lvm
2019-03-14 09:25:55,579 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=ntp_external_only value=True
2019-03-14 09:25:55,633 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=disk_erase_with_secure_erase value=False
2019-03-14 09:25:55,705 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=default_distro_series value=xenial
2019-03-14 09:25:55,777 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-03-14 09:25:55,909 [salt.state       :300 ][INFO    ][12235] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-03-14 09:25:55,909 [salt.state       :1951][INFO    ][12235] Completed state [maas.process_maas_config] at time 09:25:55.909512 duration_in_ms=4040.343
2019-03-14 09:25:55,910 [salt.state       :1780][INFO    ][12235] Running state [pxe_admin] at time 09:25:55.910248
2019-03-14 09:25:55,910 [salt.state       :1813][INFO    ][12235] Executing state maasng.fabric_present for [pxe_admin]
2019-03-14 09:25:55,980 [salt.loaded.ext.module.maasng:945 ][INFO    ][12235] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-03-14 09:25:56,052 [salt.loaded.ext.module.maasng:1008][WARNING ][12235] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-03-14 09:25:56,052 [salt.loaded.ext.module.maasng:1011][WARNING ][12235] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-03-14 09:25:56,121 [salt.state       :300 ][INFO    ][12235] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-03-14 09:25:56,121 [salt.state       :1951][INFO    ][12235] Completed state [pxe_admin] at time 09:25:56.121842 duration_in_ms=211.592
2019-03-14 09:25:56,122 [salt.state       :1780][INFO    ][12235] Running state [vlan 0] at time 09:25:56.122311
2019-03-14 09:25:56,122 [salt.state       :1813][INFO    ][12235] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-03-14 09:25:56,202 [salt.loaded.ext.module.maasng:945 ][INFO    ][12235] [{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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rywqst', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-14 09:25:56,349 [salt.loaded.ext.module.maasng:945 ][INFO    ][12235] [{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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rywqst', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-14 09:25:56,685 [salt.loaded.ext.module.maasng:945 ][INFO    ][12235] [{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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rywqst', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-14 09:25:56,786 [salt.state       :300 ][INFO    ][12235] {'new': 'Vlan untagged was updated'}
2019-03-14 09:25:56,787 [salt.state       :1951][INFO    ][12235] Completed state [vlan 0] at time 09:25:56.787314 duration_in_ms=665.003
2019-03-14 09:25:56,788 [salt.state       :1780][INFO    ][12235] Running state [192.168.11.0/24] at time 09:25:56.788607
2019-03-14 09:25:56,789 [salt.state       :1813][INFO    ][12235] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-03-14 09:25:57,005 [salt.loaded.ext.module.maasng:945 ][INFO    ][12235] [{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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], 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'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'rywqst', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-03-14 09:25:57,006 [salt.loaded.ext.module.maasng:1235][WARNING ][12235] Ignoring parameter vlan:0
2019-03-14 09:25:57,083 [salt.state       :300 ][INFO    ][12235] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-03-14 09:25:57,083 [salt.state       :1951][INFO    ][12235] Completed state [192.168.11.0/24] at time 09:25:57.083401 duration_in_ms=294.793
2019-03-14 09:25:57,084 [salt.state       :1780][INFO    ][12235] Running state [maas_create_iprange_1] at time 09:25:57.084313
2019-03-14 09:25:57,084 [salt.state       :1813][INFO    ][12235] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-03-14 09:25:57,136 [salt.state       :300 ][INFO    ][12235] Iprange maas_create_iprange_1 already exist.
2019-03-14 09:25:57,136 [salt.state       :1951][INFO    ][12235] Completed state [maas_create_iprange_1] at time 09:25:57.136737 duration_in_ms=52.423
2019-03-14 09:25:57,137 [salt.state       :1780][INFO    ][12235] Running state [vlan 0] at time 09:25:57.137163
2019-03-14 09:25:57,137 [salt.state       :1813][INFO    ][12235] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-03-14 09:25:57,183 [salt.loaded.ext.module.maasng:945 ][INFO    ][12235] [{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'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 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'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 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'rywqst', 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'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-03-14 09:25:57,274 [salt.loaded.ext.module.maasng:945 ][INFO    ][12235] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-03-14 09:25:57,513 [salt.loaded.ext.module.maasng:945 ][INFO    ][12235] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'rywqst', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-03-14 09:25:57,595 [salt.state       :300 ][INFO    ][12235] {'new': 'Vlan untagged was updated'}
2019-03-14 09:25:57,596 [salt.state       :1951][INFO    ][12235] Completed state [vlan 0] at time 09:25:57.596290 duration_in_ms=459.127
2019-03-14 09:25:57,597 [salt.state       :1780][INFO    ][12235] Running state [opnfv] at time 09:25:57.597051
2019-03-14 09:25:57,597 [salt.state       :1813][INFO    ][12235] Executing state maasng.sshkey_present for [opnfv]
2019-03-14 09:25:57,648 [salt.loaded.ext.module.maasng:1903][INFO    ][12235] [{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-03-14 09:25:57,649 [salt.state       :300 ][INFO    ][12235] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-03-14 09:25:57,649 [salt.state       :1951][INFO    ][12235] Completed state [opnfv] at time 09:25:57.649731 duration_in_ms=52.679
2019-03-14 09:25:57,651 [salt.state       :1780][INFO    ][12235] Running state [maas.process_tags] at time 09:25:57.650921
2019-03-14 09:25:57,651 [salt.state       :1813][INFO    ][12235] Executing state module.run for [maas.process_tags]
2019-03-14 09:25:57,651 [salt.utils.decorators:613 ][WARNING ][12235] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:25:57,690 [salt.loaded.ext.module.maas:92  ][INFO    ][12235] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-03-14 09:25:57,765 [salt.state       :300 ][INFO    ][12235] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-03-14 09:25:57,765 [salt.state       :1951][INFO    ][12235] Completed state [maas.process_tags] at time 09:25:57.765762 duration_in_ms=114.84
2019-03-14 09:25:57,769 [salt.minion      :1711][INFO    ][12235] Returning information for job: 20190314092529270827
2019-03-14 09:25:58,264 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314092558251909
2019-03-14 09:25:58,278 [salt.minion      :1432][INFO    ][12699] Starting a new job with PID 12699
2019-03-14 09:26:01,887 [salt.state       :915 ][INFO    ][12699] Loading fresh modules for state activity
2019-03-14 09:26:01,958 [salt.state       :1780][INFO    ][12699] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:26:01.958805
2019-03-14 09:26:01,959 [salt.state       :1813][INFO    ][12699] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:26:01,960 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12699] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:26:03,328 [salt.state       :300 ][INFO    ][12699] {'pid': 12737, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:26:03,328 [salt.state       :1951][INFO    ][12699] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:26:03.328454 duration_in_ms=1369.649
2019-03-14 09:26:03,329 [salt.state       :1780][INFO    ][12699] Running state [maas.process_machines] at time 09:26:03.329663
2019-03-14 09:26:03,329 [salt.state       :1813][INFO    ][12699] Executing state module.run for [maas.process_machines]
2019-03-14 09:26:03,330 [salt.utils.decorators:613 ][WARNING ][12699] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:26:03,760 [salt.loaded.ext.module.maas:412 ][WARNING ][12699] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:26:03,760 [salt.loaded.ext.module.maas:92  ][INFO    ][12699] 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=76h8ym architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:26:04,815 [salt.loaded.ext.module.maas:412 ][WARNING ][12699] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:26:04,816 [salt.loaded.ext.module.maas:92  ][INFO    ][12699] 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=sqx4fh architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:26:06,005 [salt.loaded.ext.module.maas:412 ][WARNING ][12699] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:26:06,006 [salt.loaded.ext.module.maas:92  ][INFO    ][12699] 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=tyqd8e architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:26:07,239 [salt.loaded.ext.module.maas:412 ][WARNING ][12699] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:26:07,240 [salt.loaded.ext.module.maas:92  ][INFO    ][12699] 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=exyay3 architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:26:08,497 [salt.loaded.ext.module.maas:412 ][WARNING ][12699] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-03-14 09:26:08,498 [salt.loaded.ext.module.maas:92  ][INFO    ][12699] 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=r3r3sy architecture=amd64/generic power_parameters_power_user=admin
2019-03-14 09:26:09,893 [salt.state       :300 ][INFO    ][12699] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-03-14 09:26:09,893 [salt.state       :1951][INFO    ][12699] Completed state [maas.process_machines] at time 09:26:09.893622 duration_in_ms=6563.954
2019-03-14 09:26:09,897 [salt.minion      :1711][INFO    ][12699] Returning information for job: 20190314092558251909
2019-03-14 09:26:43,272 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314092643259062
2019-03-14 09:26:43,294 [salt.minion      :1432][INFO    ][12980] Starting a new job with PID 12980
2019-03-14 09:26:46,866 [salt.state       :915 ][INFO    ][12980] Loading fresh modules for state activity
2019-03-14 09:26:46,952 [salt.state       :1780][INFO    ][12980] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:26:46.952443
2019-03-14 09:26:46,952 [salt.state       :1813][INFO    ][12980] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:26:46,954 [salt.loaded.int.module.cmdmod:395 ][INFO    ][12980] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:26:48,355 [salt.state       :300 ][INFO    ][12980] {'pid': 12987, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:26:48,356 [salt.state       :1951][INFO    ][12980] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:26:48.355954 duration_in_ms=1403.512
2019-03-14 09:26:48,357 [salt.state       :1780][INFO    ][12980] Running state [maas.wait_for_machine_status] at time 09:26:48.357312
2019-03-14 09:26:48,357 [salt.state       :1813][INFO    ][12980] Executing state module.run for [maas.wait_for_machine_status]
2019-03-14 09:26:48,357 [salt.utils.decorators:613 ][WARNING ][12980] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:26:51,676 [salt.loaded.ext.module.maas:993 ][INFO    ][12980] Machine r3r3sy mark broken
2019-03-14 09:26:52,355 [salt.loaded.ext.module.maas:996 ][INFO    ][12980] Machine r3r3sy mark fixed
2019-03-14 09:26:53,665 [salt.loaded.ext.module.maas:684 ][INFO    ][12980] deploymachines hwe_kernel=hwe-16.04 system_id=r3r3sy distro_series=xenial
2019-03-14 09:26:56,396 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1491.96596408s left)
2019-03-14 09:26:58,381 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092658366976
2019-03-14 09:26:58,403 [salt.minion      :1432][INFO    ][13066] Starting a new job with PID 13066
2019-03-14 09:26:58,426 [salt.minion      :1711][INFO    ][13066] Returning information for job: 20190314092658366976
2019-03-14 09:27:28,434 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092728420091
2019-03-14 09:27:28,455 [salt.minion      :1432][INFO    ][13103] Starting a new job with PID 13103
2019-03-14 09:27:28,478 [salt.minion      :1711][INFO    ][13103] Returning information for job: 20190314092728420091
2019-03-14 09:27:29,093 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1459.26884007s left)
2019-03-14 09:27:58,685 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092758633281
2019-03-14 09:27:58,706 [salt.minion      :1432][INFO    ][13146] Starting a new job with PID 13146
2019-03-14 09:27:58,730 [salt.minion      :1711][INFO    ][13146] Returning information for job: 20190314092758633281
2019-03-14 09:28:01,962 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1426.39970493s left)
2019-03-14 09:28:28,737 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092828723112
2019-03-14 09:28:28,759 [salt.minion      :1432][INFO    ][13183] Starting a new job with PID 13183
2019-03-14 09:28:28,782 [salt.minion      :1711][INFO    ][13183] Returning information for job: 20190314092828723112
2019-03-14 09:28:34,413 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1393.94851208s left)
2019-03-14 09:28:58,784 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092858771656
2019-03-14 09:28:58,807 [salt.minion      :1432][INFO    ][13275] Starting a new job with PID 13275
2019-03-14 09:28:58,831 [salt.minion      :1711][INFO    ][13275] Returning information for job: 20190314092858771656
2019-03-14 09:29:07,783 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1360.57894206s left)
2019-03-14 09:29:28,843 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092928829628
2019-03-14 09:29:28,864 [salt.minion      :1432][INFO    ][13356] Starting a new job with PID 13356
2019-03-14 09:29:28,887 [salt.minion      :1711][INFO    ][13356] Returning information for job: 20190314092928829628
2019-03-14 09:29:41,078 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1327.28394914s left)
2019-03-14 09:29:58,896 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314092958884296
2019-03-14 09:29:58,919 [salt.minion      :1432][INFO    ][13408] Starting a new job with PID 13408
2019-03-14 09:29:58,939 [salt.minion      :1711][INFO    ][13408] Returning information for job: 20190314092958884296
2019-03-14 09:30:14,603 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1293.75815606s left)
2019-03-14 09:30:28,960 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314093028947546
2019-03-14 09:30:28,983 [salt.minion      :1432][INFO    ][13535] Starting a new job with PID 13535
2019-03-14 09:30:29,006 [salt.minion      :1711][INFO    ][13535] Returning information for job: 20190314093028947546
2019-03-14 09:30:47,647 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1260.71473503s left)
2019-03-14 09:30:59,023 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314093059011517
2019-03-14 09:30:59,044 [salt.minion      :1432][INFO    ][13588] Starting a new job with PID 13588
2019-03-14 09:30:59,066 [salt.minion      :1711][INFO    ][13588] Returning information for job: 20190314093059011517
2019-03-14 09:31:21,138 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1227.22394609s left)
2019-03-14 09:31:29,089 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314093129076206
2019-03-14 09:31:29,111 [salt.minion      :1432][INFO    ][13642] Starting a new job with PID 13642
2019-03-14 09:31:29,135 [salt.minion      :1711][INFO    ][13642] Returning information for job: 20190314093129076206
2019-03-14 09:31:54,744 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1193.61722016s left)
2019-03-14 09:31:59,156 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314093159142026
2019-03-14 09:31:59,175 [salt.minion      :1432][INFO    ][13722] Starting a new job with PID 13722
2019-03-14 09:31:59,196 [salt.minion      :1711][INFO    ][13722] Returning information for job: 20190314093159142026
2019-03-14 09:32:28,162 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1160.19981194s left)
2019-03-14 09:32:29,229 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314093229216442
2019-03-14 09:32:29,252 [salt.minion      :1432][INFO    ][13796] Starting a new job with PID 13796
2019-03-14 09:32:29,278 [salt.minion      :1711][INFO    ][13796] Returning information for job: 20190314093229216442
2019-03-14 09:32:59,312 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314093259301004
2019-03-14 09:32:59,332 [salt.minion      :1432][INFO    ][13868] Starting a new job with PID 13868
2019-03-14 09:32:59,351 [salt.minion      :1711][INFO    ][13868] Returning information for job: 20190314093259301004
2019-03-14 09:33:01,928 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1126.43400502s left)
2019-03-14 09:33:29,394 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314093329380717
2019-03-14 09:33:29,417 [salt.minion      :1432][INFO    ][13906] Starting a new job with PID 13906
2019-03-14 09:33:29,442 [salt.minion      :1711][INFO    ][13906] Returning information for job: 20190314093329380717
2019-03-14 09:33:35,652 [salt.loaded.ext.module.maas:1023][INFO    ][12980] Waiting status:Ready|Deployed for machines:['kvm02']
sleep for:30s Timeout:1500s (1092.709198s left)
2019-03-14 09:33:59,465 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command saltutil.find_job with jid 20190314093359458553
2019-03-14 09:33:59,481 [salt.minion      :1432][INFO    ][14031] Starting a new job with PID 14031
2019-03-14 09:33:59,507 [salt.minion      :1711][INFO    ][14031] Returning information for job: 20190314093359458553
2019-03-14 09:34:09,330 [salt.state       :300 ][INFO    ][12980] {'ret': True}
2019-03-14 09:34:09,331 [salt.state       :1951][INFO    ][12980] Completed state [maas.wait_for_machine_status] at time 09:34:09.331117 duration_in_ms=440973.801
2019-03-14 09:34:09,334 [salt.minion      :1711][INFO    ][12980] Returning information for job: 20190314092643259062
2019-03-14 09:34:10,034 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314093410019465
2019-03-14 09:34:10,061 [salt.minion      :1432][INFO    ][14082] Starting a new job with PID 14082
2019-03-14 09:34:13,718 [salt.state       :915 ][INFO    ][14082] Loading fresh modules for state activity
2019-03-14 09:34:13,854 [salt.state       :1780][INFO    ][14082] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:34:13.854801
2019-03-14 09:34:13,855 [salt.state       :1813][INFO    ][14082] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:34:13,857 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14082] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:34:15,308 [salt.state       :300 ][INFO    ][14082] {'pid': 14089, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:34:15,309 [salt.state       :1951][INFO    ][14082] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:34:15.309412 duration_in_ms=1454.61
2019-03-14 09:34:15,311 [salt.state       :1780][INFO    ][14082] Running state [maas_machines_storage_cmp002_lvm] at time 09:34:15.310975
2019-03-14 09:34:15,311 [salt.state       :1813][INFO    ][14082] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-03-14 09:34:16,050 [salt.state       :300 ][INFO    ][14082] Machine cmp002 is not in Ready state.
2019-03-14 09:34:16,050 [salt.state       :1951][INFO    ][14082] Completed state [maas_machines_storage_cmp002_lvm] at time 09:34:16.050695 duration_in_ms=739.717
2019-03-14 09:34:16,051 [salt.state       :1780][INFO    ][14082] Running state [maas_machines_storage_cmp001_lvm] at time 09:34:16.051512
2019-03-14 09:34:16,052 [salt.state       :1813][INFO    ][14082] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-03-14 09:34:16,736 [salt.state       :300 ][INFO    ][14082] Machine cmp001 is not in Ready state.
2019-03-14 09:34:16,737 [salt.state       :1951][INFO    ][14082] Completed state [maas_machines_storage_cmp001_lvm] at time 09:34:16.737322 duration_in_ms=685.81
2019-03-14 09:34:16,741 [salt.minion      :1711][INFO    ][14082] Returning information for job: 20190314093410019465
2019-03-14 09:34:17,357 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314093417343717
2019-03-14 09:34:17,378 [salt.minion      :1432][INFO    ][14099] Starting a new job with PID 14099
2019-03-14 09:34:18,029 [salt.state       :915 ][INFO    ][14099] Loading fresh modules for state activity
2019-03-14 09:34:18,076 [salt.state       :1780][INFO    ][14099] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:34:18.076932
2019-03-14 09:34:18,077 [salt.state       :1813][INFO    ][14099] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:34:18,078 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14099] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:34:19,568 [salt.state       :300 ][INFO    ][14099] {'pid': 14106, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:34:19,569 [salt.state       :1951][INFO    ][14099] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:34:19.569261 duration_in_ms=1492.329
2019-03-14 09:34:19,571 [salt.state       :1780][INFO    ][14099] Running state [maas.deploy_machines] at time 09:34:19.571853
2019-03-14 09:34:19,572 [salt.state       :1813][INFO    ][14099] Executing state module.run for [maas.deploy_machines]
2019-03-14 09:34:19,573 [salt.utils.decorators:613 ][WARNING ][14099] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:34:20,303 [salt.state       :300 ][INFO    ][14099] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-03-14 09:34:20,304 [salt.state       :1951][INFO    ][14099] Completed state [maas.deploy_machines] at time 09:34:20.304292 duration_in_ms=732.439
2019-03-14 09:34:20,308 [salt.minion      :1711][INFO    ][14099] Returning information for job: 20190314093417343717
2019-03-14 09:34:20,901 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command state.apply with jid 20190314093420885659
2019-03-14 09:34:20,925 [salt.minion      :1432][INFO    ][14119] Starting a new job with PID 14119
2019-03-14 09:34:21,547 [salt.state       :915 ][INFO    ][14119] Loading fresh modules for state activity
2019-03-14 09:34:21,638 [salt.state       :1780][INFO    ][14119] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:34:21.638696
2019-03-14 09:34:21,639 [salt.state       :1813][INFO    ][14119] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-03-14 09:34:21,641 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14119] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-03-14 09:34:23,100 [salt.state       :300 ][INFO    ][14119] {'pid': 14126, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-03-14 09:34:23,101 [salt.state       :1951][INFO    ][14119] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:34:23.101322 duration_in_ms=1462.627
2019-03-14 09:34:23,102 [salt.state       :1780][INFO    ][14119] Running state [maas.wait_for_machine_status] at time 09:34:23.102463
2019-03-14 09:34:23,102 [salt.state       :1813][INFO    ][14119] Executing state module.run for [maas.wait_for_machine_status]
2019-03-14 09:34:23,102 [salt.utils.decorators:613 ][WARNING ][14119] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-03-14 09:34:26,474 [salt.state       :300 ][INFO    ][14119] {'ret': True}
2019-03-14 09:34:26,474 [salt.state       :1951][INFO    ][14119] Completed state [maas.wait_for_machine_status] at time 09:34:26.474668 duration_in_ms=3372.202
2019-03-14 09:34:26,478 [salt.minion      :1711][INFO    ][14119] Returning information for job: 20190314093420885659
2019-03-14 10:03:56,843 [salt.utils.schedule:1377][INFO    ][5800] Running scheduled job: __mine_interval
2019-03-14 11:03:56,842 [salt.utils.schedule:1377][INFO    ][5800] Running scheduled job: __mine_interval
2019-03-14 11:05:54,320 [salt.minion      :1308][INFO    ][5800] User sudo_ubuntu Executing command cp.push_dir with jid 20190314110554314241
2019-03-14 11:05:54,341 [salt.minion      :1432][INFO    ][20840] Starting a new job with PID 20840
