2019-06-04 20:07:44,889 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 20:08:34,939 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 20:09:24,986 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 20:10:15,033 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 20:11:05,081 [salt.minion      :870 ][ERROR   ][365] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 20:13:14,014 [salt.utils.decorators:613 ][WARNING ][2705] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 20:13:14,610 [salt.utils.decorators:613 ][WARNING ][2705] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 20:13:16,674 [salt.loaded.int.states.file:2298][WARNING ][2858] 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-06-04 20:13:22,353 [salt.state       :2022][WARNING ][2953] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-04 20:13:24,894 [salt.utils.decorators:613 ][WARNING ][2953] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 20:28:30,867 [salt.utils.decorators:613 ][WARNING ][2953] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 20:58:39,715 [salt.utils.decorators:613 ][WARNING ][2953] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:19:24,264 [salt.state       :302 ][ERROR   ][2953] Module function maasng.sync_and_wait_bs_to_all_racks threw an exception. Exception: HTTP Error 401: OK
2019-06-04 21:19:25,524 [salt.loaded.ext.module.maasng:1008][WARNING ][2953] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-06-04 21:19:25,524 [salt.loaded.ext.module.maasng:1011][WARNING ][2953] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-06-04 21:19:26,862 [salt.loaded.ext.module.maasng:1235][WARNING ][2953] Ignoring parameter vlan:0
2019-06-04 21:19:32,221 [salt.utils.decorators:613 ][WARNING ][2953] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:19:34,589 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1613] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-04 21:19:34,621 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1613] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-06-04 21:19:34,644 [salt.utils.parsers:1051][WARNING ][365] Minion received a SIGTERM. Exiting.
2019-06-04 21:19:35,678 [salt.cli.daemons :293 ][INFO    ][1661] Setting up the Salt Minion "mas01.mcp-odl-noha.local"
2019-06-04 21:19:35,764 [salt.cli.daemons :82  ][INFO    ][1661] Starting up the Salt Minion
2019-06-04 21:19:35,764 [salt.utils.event :1017][INFO    ][1661] Starting pull socket on /var/run/salt/minion/minion_event_0f3e0c7467_pull.ipc
2019-06-04 21:19:36,639 [salt.minion      :976 ][INFO    ][1661] Creating minion process manager
2019-06-04 21:19:37,998 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][1661] Executing command ['date', '+%z'] in directory '/root'
2019-06-04 21:19:38,016 [salt.utils.schedule:568 ][INFO    ][1661] Updating job settings for scheduled job: __mine_interval
2019-06-04 21:19:38,046 [salt.minion      :1108][INFO    ][1661] Added mine.update to scheduler
2019-06-04 21:19:38,051 [salt.minion      :1975][INFO    ][1661] Minion is starting as user 'root'
2019-06-04 21:19:38,065 [salt.minion      :2336][INFO    ][1661] Minion is ready to receive requests!
2019-06-04 21:19:43,625 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604211943611926
2019-06-04 21:19:43,645 [salt.minion      :1432][INFO    ][1741] Starting a new job with PID 1741
2019-06-04 21:19:47,294 [salt.state       :915 ][INFO    ][1741] Loading fresh modules for state activity
2019-06-04 21:19:47,992 [salt.state       :1780][INFO    ][1741] Running state [maas-region-controller] at time 21:19:47.992566
2019-06-04 21:19:47,993 [salt.state       :1813][INFO    ][1741] Executing state pkg.installed for [maas-region-controller]
2019-06-04 21:19:47,994 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-04 21:19:48,086 [salt.state       :300 ][INFO    ][1741] All specified packages are already installed
2019-06-04 21:19:48,086 [salt.state       :1951][INFO    ][1741] Completed state [maas-region-controller] at time 21:19:48.086563 duration_in_ms=93.998
2019-06-04 21:19:48,086 [salt.state       :1780][INFO    ][1741] Running state [python-oauth] at time 21:19:48.086923
2019-06-04 21:19:48,087 [salt.state       :1813][INFO    ][1741] Executing state pkg.installed for [python-oauth]
2019-06-04 21:19:48,094 [salt.state       :300 ][INFO    ][1741] All specified packages are already installed
2019-06-04 21:19:48,094 [salt.state       :1951][INFO    ][1741] Completed state [python-oauth] at time 21:19:48.094726 duration_in_ms=7.803
2019-06-04 21:19:48,098 [salt.state       :1780][INFO    ][1741] Running state [/etc/maas/regiond.conf] at time 21:19:48.098222
2019-06-04 21:19:48,098 [salt.state       :1813][INFO    ][1741] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-04 21:19:48,169 [salt.state       :300 ][INFO    ][1741] No changes needed to be made
2019-06-04 21:19:48,169 [salt.state       :1951][INFO    ][1741] Completed state [/etc/maas/regiond.conf] at time 21:19:48.169554 duration_in_ms=71.331
2019-06-04 21:19:48,170 [salt.state       :1780][INFO    ][1741] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:19:48.170389
2019-06-04 21:19:48,170 [salt.state       :1813][INFO    ][1741] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-04 21:19:48,252 [salt.state       :300 ][INFO    ][1741] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-04 21:19:48,252 [salt.state       :1951][INFO    ][1741] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:19:48.252374 duration_in_ms=81.985
2019-06-04 21:19:48,253 [salt.state       :1780][INFO    ][1741] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:48.253026
2019-06-04 21:19:48,253 [salt.state       :1813][INFO    ][1741] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-04 21:19:48,272 [salt.state       :300 ][INFO    ][1741] No changes needed to be made
2019-06-04 21:19:48,272 [salt.state       :1951][INFO    ][1741] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:48.272712 duration_in_ms=19.686
2019-06-04 21:19:48,273 [salt.state       :1780][INFO    ][1741] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:48.273465
2019-06-04 21:19:48,273 [salt.state       :1813][INFO    ][1741] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-04 21:19:48,302 [salt.state       :300 ][INFO    ][1741] No changes needed to be made
2019-06-04 21:19:48,302 [salt.state       :1951][INFO    ][1741] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:19:48.302408 duration_in_ms=28.943
2019-06-04 21:19:48,303 [salt.state       :1780][INFO    ][1741] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:19:48.303151
2019-06-04 21:19:48,303 [salt.state       :1813][INFO    ][1741] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-04 21:19:48,343 [salt.state       :300 ][INFO    ][1741] No changes needed to be made
2019-06-04 21:19:48,345 [salt.state       :1951][INFO    ][1741] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:19:48.345628 duration_in_ms=42.475
2019-06-04 21:19:48,347 [salt.state       :1780][INFO    ][1741] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:19:48.347532
2019-06-04 21:19:48,348 [salt.state       :1813][INFO    ][1741] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-04 21:19:48,368 [salt.state       :300 ][INFO    ][1741] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-04 21:19:48,368 [salt.state       :1951][INFO    ][1741] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:19:48.368742 duration_in_ms=21.21
2019-06-04 21:19:48,374 [salt.state       :1780][INFO    ][1741] Running state [a2enmod headers] at time 21:19:48.374914
2019-06-04 21:19:48,375 [salt.state       :1813][INFO    ][1741] Executing state cmd.run for [a2enmod headers]
2019-06-04 21:19:48,376 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command 'a2enmod headers' in directory '/root'
2019-06-04 21:19:48,446 [salt.state       :300 ][INFO    ][1741] {'pid': 1774, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-04 21:19:48,447 [salt.state       :1951][INFO    ][1741] Completed state [a2enmod headers] at time 21:19:48.447319 duration_in_ms=72.404
2019-06-04 21:19:48,447 [salt.state       :1780][INFO    ][1741] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:19:48.447862
2019-06-04 21:19:48,448 [salt.state       :1813][INFO    ][1741] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-04 21:19:48,466 [salt.state       :300 ][INFO    ][1741] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-04 21:19:48,466 [salt.state       :1951][INFO    ][1741] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:19:48.466789 duration_in_ms=18.926
2019-06-04 21:19:48,467 [salt.state       :1780][INFO    ][1741] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:19:48.467634
2019-06-04 21:19:48,468 [salt.state       :1813][INFO    ][1741] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-04 21:19:48,551 [salt.state       :300 ][INFO    ][1741] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-04 21:19:48,552 [salt.state       :1951][INFO    ][1741] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:19:48.551944 duration_in_ms=84.31
2019-06-04 21:19:48,552 [salt.state       :1780][INFO    ][1741] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:19:48.552576
2019-06-04 21:19:48,552 [salt.state       :1813][INFO    ][1741] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-04 21:19:48,617 [salt.state       :300 ][INFO    ][1741] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-04 21:19:48,617 [salt.state       :1951][INFO    ][1741] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:19:48.617766 duration_in_ms=65.19
2019-06-04 21:19:48,618 [salt.state       :1780][INFO    ][1741] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:19:48.618360
2019-06-04 21:19:48,618 [salt.state       :1813][INFO    ][1741] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-04 21:19:48,683 [salt.state       :300 ][INFO    ][1741] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-04 21:19:48,683 [salt.state       :1951][INFO    ][1741] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:19:48.683532 duration_in_ms=65.172
2019-06-04 21:19:48,683 [salt.state       :1780][INFO    ][1741] Running state [/root/.pgpass] at time 21:19:48.683841
2019-06-04 21:19:48,684 [salt.state       :1813][INFO    ][1741] Executing state file.managed for [/root/.pgpass]
2019-06-04 21:19:48,731 [salt.state       :300 ][INFO    ][1741] File /root/.pgpass is in the correct state
2019-06-04 21:19:48,731 [salt.state       :1951][INFO    ][1741] Completed state [/root/.pgpass] at time 21:19:48.731417 duration_in_ms=47.576
2019-06-04 21:19:48,737 [salt.state       :1780][INFO    ][1741] Running state [maas-region syncdb --noinput] at time 21:19:48.737683
2019-06-04 21:19:48,738 [salt.state       :1813][INFO    ][1741] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-04 21:19:48,738 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-04 21:19:50,966 [salt.state       :300 ][INFO    ][1741] {'pid': 1791, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: maasserver, auth, contenttypes, sessions, metadataserver, piston3, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-04 21:19:50,967 [salt.state       :1951][INFO    ][1741] Completed state [maas-region syncdb --noinput] at time 21:19:50.967612 duration_in_ms=2229.928
2019-06-04 21:19:50,968 [salt.state       :2022][WARNING ][1741] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-04 21:19:50,970 [salt.state       :1780][INFO    ][1741] Running state [maas-regiond] at time 21:19:50.970804
2019-06-04 21:19:50,971 [salt.state       :1813][INFO    ][1741] Executing state service.running for [maas-regiond]
2019-06-04 21:19:50,973 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-04 21:19:51,013 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-04 21:19:51,031 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-04 21:19:51,049 [salt.state       :300 ][INFO    ][1741] The service maas-regiond is already running
2019-06-04 21:19:51,049 [salt.state       :1951][INFO    ][1741] Completed state [maas-regiond] at time 21:19:51.049514 duration_in_ms=78.71
2019-06-04 21:19:51,052 [salt.state       :1780][INFO    ][1741] Running state [bind9] at time 21:19:51.052223
2019-06-04 21:19:51,052 [salt.state       :1813][INFO    ][1741] Executing state service.running for [bind9]
2019-06-04 21:19:51,053 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-04 21:19:51,072 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-04 21:19:51,088 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-04 21:19:51,104 [salt.state       :300 ][INFO    ][1741] The service bind9 is already running
2019-06-04 21:19:51,104 [salt.state       :1951][INFO    ][1741] Completed state [bind9] at time 21:19:51.104844 duration_in_ms=52.621
2019-06-04 21:19:51,107 [salt.state       :1780][INFO    ][1741] Running state [apache2] at time 21:19:51.107324
2019-06-04 21:19:51,107 [salt.state       :1813][INFO    ][1741] Executing state service.running for [apache2]
2019-06-04 21:19:51,108 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-04 21:19:51,126 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-04 21:19:51,142 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-04 21:19:51,162 [salt.state       :300 ][INFO    ][1741] The service apache2 is already running
2019-06-04 21:19:51,163 [salt.state       :1951][INFO    ][1741] Completed state [apache2] at time 21:19:51.162992 duration_in_ms=55.668
2019-06-04 21:19:51,165 [salt.state       :1780][INFO    ][1741] Running state [maasng.wait_for_http_code] at time 21:19:51.165474
2019-06-04 21:19:51,166 [salt.state       :1813][INFO    ][1741] Executing state module.run for [maasng.wait_for_http_code]
2019-06-04 21:19:51,166 [salt.utils.decorators:613 ][WARNING ][1741] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:19:51,305 [salt.state       :300 ][INFO    ][1741] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-04 21:19:51,306 [salt.state       :1951][INFO    ][1741] Completed state [maasng.wait_for_http_code] at time 21:19:51.306052 duration_in_ms=140.577
2019-06-04 21:19:51,307 [salt.state       :1780][INFO    ][1741] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:19:51.307465
2019-06-04 21:19:51,308 [salt.state       :1813][INFO    ][1741] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-04 21:19:51,308 [salt.state       :300 ][INFO    ][1741] /var/lib/maas/.setup_admin exists
2019-06-04 21:19:51,309 [salt.state       :1951][INFO    ][1741] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:19:51.309129 duration_in_ms=1.663
2019-06-04 21:19:51,310 [salt.state       :1780][INFO    ][1741] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:51.310274
2019-06-04 21:19:51,310 [salt.state       :1813][INFO    ][1741] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:19:51,311 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1741] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:19:52,747 [salt.state       :300 ][INFO    ][1741] {'pid': 1822, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:19:52,747 [salt.state       :1951][INFO    ][1741] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:19:52.747835 duration_in_ms=1437.562
2019-06-04 21:19:52,751 [salt.state       :1780][INFO    ][1741] Running state [maas_region_boot_source_resources_mirror] at time 21:19:52.751151
2019-06-04 21:19:52,751 [salt.state       :1813][INFO    ][1741] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-04 21:19:52,848 [salt.state       :300 ][INFO    ][1741] {'changes': {}}
2019-06-04 21:19:52,848 [salt.state       :1951][INFO    ][1741] Completed state [maas_region_boot_source_resources_mirror] at time 21:19:52.848878 duration_in_ms=97.724
2019-06-04 21:19:52,850 [salt.state       :1780][INFO    ][1741] Running state [maasng.boot_resources_import] at time 21:19:52.850297
2019-06-04 21:19:52,850 [salt.state       :1813][INFO    ][1741] Executing state module.run for [maasng.boot_resources_import]
2019-06-04 21:19:52,851 [salt.utils.decorators:613 ][WARNING ][1741] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:19:52,945 [salt.loaded.ext.module.maasng:1600][INFO    ][1741] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-04 21:19:58,000 [salt.loaded.ext.module.maasng:1600][INFO    ][1741] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-04 21:19:58,706 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604211958693111
2019-06-04 21:19:58,730 [salt.minion      :1432][INFO    ][1846] Starting a new job with PID 1846
2019-06-04 21:19:58,752 [salt.minion      :1711][INFO    ][1846] Returning information for job: 20190604211958693111
2019-06-04 21:20:03,061 [salt.loaded.ext.module.maasng:1600][INFO    ][1741] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-06-04 21:20:08,163 [salt.state       :300 ][INFO    ][1741] {'ret': True}
2019-06-04 21:20:08,164 [salt.state       :1951][INFO    ][1741] Completed state [maasng.boot_resources_import] at time 21:20:08.164097 duration_in_ms=15313.8
2019-06-04 21:20:08,165 [salt.state       :1780][INFO    ][1741] Running state [maas_region_boot_sources_selection_xenial] at time 21:20:08.165217
2019-06-04 21:20:08,165 [salt.state       :1813][INFO    ][1741] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-04 21:20:08,367 [salt.state       :300 ][INFO    ][1741] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-04 21:20:08,367 [salt.state       :1951][INFO    ][1741] Completed state [maas_region_boot_sources_selection_xenial] at time 21:20:08.367661 duration_in_ms=202.444
2019-06-04 21:20:08,369 [salt.state       :1780][INFO    ][1741] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:20:08.369095
2019-06-04 21:20:08,369 [salt.state       :1813][INFO    ][1741] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-04 21:20:08,370 [salt.utils.decorators:613 ][WARNING ][1741] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:20:08,370 [salt.loaded.ext.module.maasng:1771][INFO    ][1741] boot-sources sync initiated for ALL Rack's
2019-06-04 21:20:09,450 [salt.state       :300 ][INFO    ][1741] {'ret': True}
2019-06-04 21:20:09,451 [salt.state       :1951][INFO    ][1741] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:20:09.451377 duration_in_ms=1082.282
2019-06-04 21:20:09,453 [salt.state       :1780][INFO    ][1741] Running state [maas.process_maas_config] at time 21:20:09.453440
2019-06-04 21:20:09,453 [salt.state       :1813][INFO    ][1741] Executing state module.run for [maas.process_maas_config]
2019-06-04 21:20:09,454 [salt.utils.decorators:613 ][WARNING ][1741] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:20:09,455 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=enable_http_proxy value=True
2019-06-04 21:20:09,518 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=upstream_dns value=8.8.8.8
2019-06-04 21:20:09,583 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=commissioning_distro_series value=xenial
2019-06-04 21:20:09,654 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=default_osystem value=ubuntu
2019-06-04 21:20:09,732 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=active_discovery_interval value=600
2019-06-04 21:20:12,597 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=dnssec_validation value=no
2019-06-04 21:20:12,661 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=maas_name value=mas01
2019-06-04 21:20:12,728 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=network_discovery value=enabled
2019-06-04 21:20:12,846 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=enable_third_party_drivers value=True
2019-06-04 21:20:12,907 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=default_storage_layout value=lvm
2019-06-04 21:20:12,966 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=ntp_external_only value=True
2019-06-04 21:20:13,020 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-04 21:20:13,074 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=default_distro_series value=xenial
2019-06-04 21:20:13,147 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-04 21:20:13,267 [salt.state       :300 ][INFO    ][1741] {'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-06-04 21:20:13,268 [salt.state       :1951][INFO    ][1741] Completed state [maas.process_maas_config] at time 21:20:13.268062 duration_in_ms=3814.622
2019-06-04 21:20:13,268 [salt.state       :1780][INFO    ][1741] Running state [pxe_admin] at time 21:20:13.268891
2019-06-04 21:20:13,269 [salt.state       :1813][INFO    ][1741] Executing state maasng.fabric_present for [pxe_admin]
2019-06-04 21:20:13,325 [salt.loaded.ext.module.maasng:945 ][INFO    ][1741] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 21:20:13,405 [salt.loaded.ext.module.maasng:1008][WARNING ][1741] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-04 21:20:13,405 [salt.loaded.ext.module.maasng:1011][WARNING ][1741] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-04 21:20:13,463 [salt.state       :300 ][INFO    ][1741] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-04 21:20:13,463 [salt.state       :1951][INFO    ][1741] Completed state [pxe_admin] at time 21:20:13.463388 duration_in_ms=194.495
2019-06-04 21:20:13,463 [salt.state       :1780][INFO    ][1741] Running state [vlan 0] at time 21:20:13.463882
2019-06-04 21:20:13,464 [salt.state       :1813][INFO    ][1741] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-04 21:20:13,522 [salt.loaded.ext.module.maasng:945 ][INFO    ][1741] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 21:20:13,618 [salt.loaded.ext.module.maasng:945 ][INFO    ][1741] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 21:20:13,895 [salt.loaded.ext.module.maasng:945 ][INFO    ][1741] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-04 21:20:13,985 [salt.state       :300 ][INFO    ][1741] {'new': 'Vlan untagged was updated'}
2019-06-04 21:20:13,985 [salt.state       :1951][INFO    ][1741] Completed state [vlan 0] at time 21:20:13.985820 duration_in_ms=521.937
2019-06-04 21:20:13,987 [salt.state       :1780][INFO    ][1741] Running state [192.168.11.0/24] at time 21:20:13.987333
2019-06-04 21:20:13,987 [salt.state       :1813][INFO    ][1741] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-04 21:20:14,177 [salt.loaded.ext.module.maasng:945 ][INFO    ][1741] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-04 21:20:14,177 [salt.loaded.ext.module.maasng:1235][WARNING ][1741] Ignoring parameter vlan:0
2019-06-04 21:20:14,248 [salt.state       :300 ][INFO    ][1741] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-04 21:20:14,248 [salt.state       :1951][INFO    ][1741] Completed state [192.168.11.0/24] at time 21:20:14.248465 duration_in_ms=261.132
2019-06-04 21:20:14,249 [salt.state       :1780][INFO    ][1741] Running state [maas_create_iprange_1] at time 21:20:14.249411
2019-06-04 21:20:14,249 [salt.state       :1813][INFO    ][1741] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-04 21:20:14,296 [salt.state       :300 ][INFO    ][1741] Iprange maas_create_iprange_1 already exist.
2019-06-04 21:20:14,296 [salt.state       :1951][INFO    ][1741] Completed state [maas_create_iprange_1] at time 21:20:14.296400 duration_in_ms=46.989
2019-06-04 21:20:14,296 [salt.state       :1780][INFO    ][1741] Running state [vlan 0] at time 21:20:14.296739
2019-06-04 21:20:14,297 [salt.state       :1813][INFO    ][1741] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-04 21:20:14,371 [salt.loaded.ext.module.maasng:945 ][INFO    ][1741] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 21:20:14,529 [salt.loaded.ext.module.maasng:945 ][INFO    ][1741] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-04 21:20:14,775 [salt.loaded.ext.module.maasng:945 ][INFO    ][1741] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-04 21:20:14,860 [salt.state       :300 ][INFO    ][1741] {'new': 'Vlan untagged was updated'}
2019-06-04 21:20:14,860 [salt.state       :1951][INFO    ][1741] Completed state [vlan 0] at time 21:20:14.860785 duration_in_ms=564.045
2019-06-04 21:20:14,861 [salt.state       :1780][INFO    ][1741] Running state [opnfv] at time 21:20:14.861750
2019-06-04 21:20:14,862 [salt.state       :1813][INFO    ][1741] Executing state maasng.sshkey_present for [opnfv]
2019-06-04 21:20:14,913 [salt.loaded.ext.module.maasng:1903][INFO    ][1741] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-06-04 21:20:14,913 [salt.state       :300 ][INFO    ][1741] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-04 21:20:14,913 [salt.state       :1951][INFO    ][1741] Completed state [opnfv] at time 21:20:14.913792 duration_in_ms=52.042
2019-06-04 21:20:14,914 [salt.state       :1780][INFO    ][1741] Running state [maas.process_tags] at time 21:20:14.914623
2019-06-04 21:20:14,914 [salt.state       :1813][INFO    ][1741] Executing state module.run for [maas.process_tags]
2019-06-04 21:20:14,915 [salt.utils.decorators:613 ][WARNING ][1741] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:20:14,967 [salt.loaded.ext.module.maas:92  ][INFO    ][1741] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-06-04 21:20:15,022 [salt.state       :300 ][INFO    ][1741] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-06-04 21:20:15,023 [salt.state       :1951][INFO    ][1741] Completed state [maas.process_tags] at time 21:20:15.023042 duration_in_ms=108.42
2019-06-04 21:20:15,026 [salt.minion      :1711][INFO    ][1741] Returning information for job: 20190604211943611926
2019-06-04 21:20:15,627 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604212015620631
2019-06-04 21:20:15,646 [salt.minion      :1432][INFO    ][2245] Starting a new job with PID 2245
2019-06-04 21:20:19,389 [salt.state       :915 ][INFO    ][2245] Loading fresh modules for state activity
2019-06-04 21:20:19,424 [salt.fileclient  :1219][INFO    ][2245] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-06-04 21:20:19,449 [salt.state       :1780][INFO    ][2245] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:19.449712
2019-06-04 21:20:19,449 [salt.state       :1813][INFO    ][2245] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:20:19,451 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2245] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:20:20,893 [salt.state       :300 ][INFO    ][2245] {'pid': 2285, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:20:20,894 [salt.state       :1951][INFO    ][2245] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:20:20.894111 duration_in_ms=1444.4
2019-06-04 21:20:20,895 [salt.state       :1780][INFO    ][2245] Running state [maas.process_machines] at time 21:20:20.895288
2019-06-04 21:20:20,895 [salt.state       :1813][INFO    ][2245] Executing state module.run for [maas.process_machines]
2019-06-04 21:20:20,895 [salt.utils.decorators:613 ][WARNING ][2245] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:20:20,969 [salt.loaded.ext.module.maas:412 ][WARNING ][2245] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:20:20,969 [salt.loaded.ext.module.maas:92  ][INFO    ][2245] machine hostname=gtw01 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-06-04 21:20:22,520 [salt.loaded.ext.module.maas:412 ][WARNING ][2245] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:20:22,520 [salt.loaded.ext.module.maas:92  ][INFO    ][2245] 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-06-04 21:20:23,951 [salt.loaded.ext.module.maas:412 ][WARNING ][2245] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:20:23,952 [salt.loaded.ext.module.maas:92  ][INFO    ][2245] machine hostname=odl01 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-06-04 21:20:25,131 [salt.loaded.ext.module.maas:412 ][WARNING ][2245] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:20:25,132 [salt.loaded.ext.module.maas:92  ][INFO    ][2245] 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-06-04 21:20:26,329 [salt.loaded.ext.module.maas:412 ][WARNING ][2245] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:20:26,330 [salt.loaded.ext.module.maas:92  ][INFO    ][2245] machine hostname=ctl01 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-06-04 21:20:27,449 [salt.state       :300 ][INFO    ][2245] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']}}
2019-06-04 21:20:27,450 [salt.state       :1951][INFO    ][2245] Completed state [maas.process_machines] at time 21:20:27.450115 duration_in_ms=6554.824
2019-06-04 21:20:27,453 [salt.minion      :1711][INFO    ][2245] Returning information for job: 20190604212015620631
2019-06-04 21:20:58,609 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604212058595989
2019-06-04 21:20:58,631 [salt.minion      :1432][INFO    ][2608] Starting a new job with PID 2608
2019-06-04 21:21:02,328 [salt.state       :915 ][INFO    ][2608] Loading fresh modules for state activity
2019-06-04 21:21:02,385 [salt.fileclient  :1219][INFO    ][2608] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-06-04 21:21:02,431 [salt.state       :1780][INFO    ][2608] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:21:02.431059
2019-06-04 21:21:02,431 [salt.state       :1813][INFO    ][2608] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:21:02,433 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2608] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:21:03,880 [salt.state       :300 ][INFO    ][2608] {'pid': 2615, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:21:03,880 [salt.state       :1951][INFO    ][2608] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:21:03.880564 duration_in_ms=1449.505
2019-06-04 21:21:03,881 [salt.state       :1780][INFO    ][2608] Running state [maas.wait_for_machine_status] at time 21:21:03.881774
2019-06-04 21:21:03,882 [salt.state       :1813][INFO    ][2608] Executing state module.run for [maas.wait_for_machine_status]
2019-06-04 21:21:03,882 [salt.utils.decorators:613 ][WARNING ][2608] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:21:04,806 [salt.loaded.ext.module.maas:1023][INFO    ][2608] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1499.08107996s left)
2019-06-04 21:21:13,723 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212113710545
2019-06-04 21:21:13,746 [salt.minion      :1432][INFO    ][2628] Starting a new job with PID 2628
2019-06-04 21:21:13,770 [salt.minion      :1711][INFO    ][2628] Returning information for job: 20190604212113710545
2019-06-04 21:21:35,803 [salt.loaded.ext.module.maas:1023][INFO    ][2608] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1468.08396602s left)
2019-06-04 21:21:43,776 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212143764092
2019-06-04 21:21:43,799 [salt.minion      :1432][INFO    ][2682] Starting a new job with PID 2682
2019-06-04 21:21:43,823 [salt.minion      :1711][INFO    ][2682] Returning information for job: 20190604212143764092
2019-06-04 21:22:07,016 [salt.loaded.ext.module.maas:1023][INFO    ][2608] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1436.87038493s left)
2019-06-04 21:22:13,841 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212213829465
2019-06-04 21:22:13,858 [salt.minion      :1432][INFO    ][2815] Starting a new job with PID 2815
2019-06-04 21:22:13,881 [salt.minion      :1711][INFO    ][2815] Returning information for job: 20190604212213829465
2019-06-04 21:22:38,061 [salt.loaded.ext.module.maas:1023][INFO    ][2608] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1405.82533193s left)
2019-06-04 21:22:43,881 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212243869792
2019-06-04 21:22:43,904 [salt.minion      :1432][INFO    ][3102] Starting a new job with PID 3102
2019-06-04 21:22:43,927 [salt.minion      :1711][INFO    ][3102] Returning information for job: 20190604212243869792
2019-06-04 21:23:09,753 [salt.loaded.ext.module.maas:1023][INFO    ][2608] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1374.133847s left)
2019-06-04 21:23:13,947 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212313935166
2019-06-04 21:23:13,970 [salt.minion      :1432][INFO    ][3280] Starting a new job with PID 3280
2019-06-04 21:23:13,993 [salt.minion      :1711][INFO    ][3280] Returning information for job: 20190604212313935166
2019-06-04 21:23:41,188 [salt.loaded.ext.module.maas:1023][INFO    ][2608] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1342.69910693s left)
2019-06-04 21:23:44,000 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212343986996
2019-06-04 21:23:44,022 [salt.minion      :1432][INFO    ][3887] Starting a new job with PID 3887
2019-06-04 21:23:44,044 [salt.minion      :1711][INFO    ][3887] Returning information for job: 20190604212343986996
2019-06-04 21:24:14,064 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212414051318
2019-06-04 21:24:14,084 [salt.minion      :1432][INFO    ][4084] Starting a new job with PID 4084
2019-06-04 21:24:14,109 [salt.minion      :1711][INFO    ][4084] Returning information for job: 20190604212414051318
2019-06-04 21:24:14,784 [salt.state       :300 ][INFO    ][2608] {'ret': True}
2019-06-04 21:24:14,785 [salt.state       :1951][INFO    ][2608] Completed state [maas.wait_for_machine_status] at time 21:24:14.785054 duration_in_ms=190903.277
2019-06-04 21:24:14,789 [salt.minion      :1711][INFO    ][2608] Returning information for job: 20190604212058595989
2019-06-04 21:24:15,442 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604212415428857
2019-06-04 21:24:15,463 [salt.minion      :1432][INFO    ][4091] Starting a new job with PID 4091
2019-06-04 21:24:19,087 [salt.state       :915 ][INFO    ][4091] Loading fresh modules for state activity
2019-06-04 21:24:19,116 [salt.fileclient  :1219][INFO    ][4091] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-06-04 21:24:19,171 [salt.state       :1780][INFO    ][4091] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:24:19.171214
2019-06-04 21:24:19,171 [salt.state       :1813][INFO    ][4091] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:24:19,172 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4091] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:24:20,593 [salt.state       :300 ][INFO    ][4091] {'pid': 4114, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:24:20,594 [salt.state       :1951][INFO    ][4091] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:24:20.594104 duration_in_ms=1422.89
2019-06-04 21:24:20,595 [salt.state       :1780][INFO    ][4091] Running state [maas_machines_storage_cmp002_lvm] at time 21:24:20.595545
2019-06-04 21:24:20,595 [salt.state       :1813][INFO    ][4091] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-04 21:24:21,829 [salt.loaded.ext.module.maasng:610 ][INFO    ][4091] hrpkk6
2019-06-04 21:24:21,830 [salt.loaded.ext.module.maasng:626 ][INFO    ][4091] sda
2019-06-04 21:24:22,604 [salt.loaded.ext.module.maasng:361 ][INFO    ][4091] hrpkk6
2019-06-04 21:24:22,724 [salt.loaded.ext.module.maasng:367 ][INFO    ][4091] [{u'size': 2397998940160, u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/5/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'c0d939ff-33f4-4c01-941e-f2e137e6251c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hrpkk6', u'device_id': 5, u'filesystem': {u'mount_options': None, u'uuid': u'5be70a48-c543-49dc-b8db-9225173b2f37', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/5/partition/7', u'type': u'partition', u'id': 7, u'size': 2397992648704}], u'tags': [u'rotary'], u'id': 5, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'hrpkk6', 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'model': u'UCSB-MRAID12G', u'name': u'sda'}, {u'size': 2397988454400, u'available_size': 0, u'uuid': u'ac319412-b40b-4463-82c3-3c55592296c8', u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/12/', u'used_size': 2397988454400, u'partitions': [], u'tags': [], u'id': 12, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'hrpkk6', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'82210eb6-3ed3-44da-bbc8-a7965dceb562', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'name': u'vgroot-lvroot'}]
2019-06-04 21:24:22,724 [salt.loaded.ext.module.maasng:632 ][INFO    ][4091] vgroot
2019-06-04 21:24:22,725 [salt.loaded.ext.module.maasng:635 ][INFO    ][4091] lvroot
2019-06-04 21:24:22,725 [salt.loaded.ext.module.maasng:639 ][INFO    ][4091] 107374182400
2019-06-04 21:24:23,470 [salt.loaded.ext.module.maasng:645 ][INFO    ][4091] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.42'], u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/hrpkk6/', u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'hrpkk6', u'power_state': u'on', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"From 'Testing' to 'Ready'", u'disable_ipv4': False, u'blockdevice_set': [{u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/5/', u'type': u'physical', u'partitions': [{u'uuid': u'bc2008a5-3269-4831-a525-ee9effd57fd8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hrpkk6', u'device_id': 5, u'filesystem': {u'mount_options': None, u'uuid': u'9cddb13b-5858-4db1-a1e3-0de1d7b0c0dc', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/5/partition/8', u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'hrpkk6', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 5, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160}, {u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/13/', u'type': u'virtual', u'partitions': [], u'tags': [], u'uuid': u'4a451e36-53d2-4069-b23c-4a7d58657f8b', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'hrpkk6', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'85c7edfc-09e2-404b-add7-0d193b253ca1', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 13, u'serial': None, u'size': 107374182400}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/5/', u'type': u'physical', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'hrpkk6', 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'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'bc2008a5-3269-4831-a525-ee9effd57fd8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hrpkk6', u'device_id': 5, u'filesystem': {u'mount_options': None, u'uuid': u'9cddb13b-5858-4db1-a1e3-0de1d7b0c0dc', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/5/partition/8', u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'used_size': 2397998940160, u'id': 5, u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'hrpkk6', u'id': 8}], u'special_filesystems': [], u'current_commissioning_result_id': 4, 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'pkhtcs', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'mode': u'dhcp', u'id': 43}], 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'pkhtcs', 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'pkhtcs', 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'system_id': u'hrpkk6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/interfaces/5/'}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'virtualblockdevice_set': [{u'size': 107374182400, u'block_size': 4096, u'available_size': 0, u'uuid': u'4a451e36-53d2-4069-b23c-4a7d58657f8b', u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/13/', u'type': u'virtual', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'hrpkk6', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'85c7edfc-09e2-404b-add7-0d193b253ca1', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'partitions': [], u'used_size': 107374182400, u'id': 13, u'serial': None, u'name': u'vgroot-lvroot'}], u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', 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'pkhtcs', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'mode': u'dhcp', u'id': 43}], 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'pkhtcs', 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'pkhtcs', 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'system_id': u'hrpkk6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/interfaces/5/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 44}], 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'system_id': u'hrpkk6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 21, u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/interfaces/21/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 45}], 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'system_id': u'hrpkk6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 22, u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/interfaces/22/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 46}], 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'system_id': u'hrpkk6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'id': 23, u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/interfaces/23/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'size': 2397998940160, u'block_size': 4096, u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/5/', u'type': u'physical', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'hrpkk6', 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'model': u'UCSB-MRAID12G', u'partitions': [{u'uuid': u'bc2008a5-3269-4831-a525-ee9effd57fd8', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'hrpkk6', u'device_id': 5, u'filesystem': {u'mount_options': None, u'uuid': u'9cddb13b-5858-4db1-a1e3-0de1d7b0c0dc', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/hrpkk6/blockdevices/5/partition/8', u'type': u'partition', u'id': 8, u'size': 2397992648704}], u'used_size': 2397998940160, u'id': 5, u'serial': u'618e728372755980239b15112698bc66', u'name': u'sda'}}
2019-06-04 21:24:23,473 [salt.state       :300 ][INFO    ][4091] {'new': {'storage_layout': 'lvm'}}
2019-06-04 21:24:23,473 [salt.state       :1951][INFO    ][4091] Completed state [maas_machines_storage_cmp002_lvm] at time 21:24:23.473629 duration_in_ms=2878.081
2019-06-04 21:24:23,474 [salt.state       :1780][INFO    ][4091] Running state [maas_machines_storage_cmp001_lvm] at time 21:24:23.474226
2019-06-04 21:24:23,474 [salt.state       :1813][INFO    ][4091] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-04 21:24:24,880 [salt.loaded.ext.module.maasng:610 ][INFO    ][4091] bwrbyw
2019-06-04 21:24:24,880 [salt.loaded.ext.module.maasng:626 ][INFO    ][4091] sda
2019-06-04 21:24:25,561 [salt.loaded.ext.module.maasng:361 ][INFO    ][4091] bwrbyw
2019-06-04 21:24:25,676 [salt.loaded.ext.module.maasng:367 ][INFO    ][4091] [{u'size': 2397998940160, u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/2/', u'used_size': 2397998940160, u'partitions': [{u'uuid': u'00990ddb-2401-41f9-8343-89672a1070db', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bwrbyw', u'device_id': 2, u'filesystem': {u'mount_options': None, u'uuid': u'1e1f4f15-76c0-4a54-b354-499f907cbfc6', u'label': None, u'mount_point': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/2/partition/5', u'type': u'partition', u'id': 5, u'size': 2397992648704}], u'tags': [u'rotary'], u'id': 2, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'bwrbyw', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'type': u'physical', u'model': u'UCSB-MRAID12G', u'name': u'sda'}, {u'size': 2397988454400, u'available_size': 0, u'uuid': u'c955e535-b09c-4da9-9843-28197136bc5c', u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/10/', u'used_size': 2397988454400, u'partitions': [], u'tags': [], u'id': 10, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'bwrbyw', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'6584bb8a-b58b-4ca6-844b-80413f5dc98a', u'label': u'root', u'mount_point': u'/', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'name': u'vgroot-lvroot'}]
2019-06-04 21:24:25,676 [salt.loaded.ext.module.maasng:632 ][INFO    ][4091] vgroot
2019-06-04 21:24:25,677 [salt.loaded.ext.module.maasng:635 ][INFO    ][4091] lvroot
2019-06-04 21:24:25,677 [salt.loaded.ext.module.maasng:639 ][INFO    ][4091] 107374182400
2019-06-04 21:24:26,271 [salt.loaded.ext.module.maasng:645 ][INFO    ][4091] {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'memory_test_status': -1, u'ip_addresses': [u'192.168.11.40'], u'cpu_count': 16, u'power_type': u'ipmi', u'memory_test_status_name': u'Unknown', u'boot_interface': {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', 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.40', u'mode': u'dhcp', u'id': 33}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'parents': [], 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', 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.40'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'id': 7, u'system_id': u'bwrbyw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/interfaces/7/'}, u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'', u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'resource_uri': u'/MAAS/api/2.0/machines/bwrbyw/', u'disable_ipv4': False, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'hwe_kernel': u'', u'testing_status': 2, u'system_id': u'bwrbyw', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'model': None, u'block_size': 4096, u'uuid': u'55fc5293-0eb5-4828-8ad9-b4d508192b0b', u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/14/', u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'id': 14, u'tags': [], u'name': u'vgroot-lvroot', u'system_id': u'bwrbyw', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'c6e2d78e-9422-4d64-9c11-f02c7797b9a3', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'size': 107374182400, u'used_size': 107374182400, u'serial': None, u'partitions': []}], u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/2/', u'type': u'physical', u'id': 2, u'tags': [u'rotary'], u'name': u'sda', u'system_id': u'bwrbyw', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'path': u'/dev/disk/by-dname/sda', u'size': 2397998940160, u'used_size': 2397998940160, u'used_for': u'GPT partitioned with 1 partition', u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'e3e50dfd-4902-4674-8f15-d998688158ad', u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/2/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bwrbyw', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'0d85d440-d89b-4a27-843f-ff77496b8d90', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 9, u'size': 2397992648704}]}, {u'model': None, u'block_size': 4096, u'uuid': u'55fc5293-0eb5-4828-8ad9-b4d508192b0b', u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/14/', u'type': u'virtual', u'id': 14, u'tags': [], u'name': u'vgroot-lvroot', u'system_id': u'bwrbyw', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'c6e2d78e-9422-4d64-9c11-f02c7797b9a3', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'path': u'/dev/disk/by-dname/lvroot', u'size': 107374182400, u'used_size': 107374182400, u'used_for': u'ext4 formatted filesystem mounted at /', u'serial': None, u'partitions': []}], u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'bwrbyw', u'id': 9}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'commissioning_status_name': u'Passed', u'current_testing_result_id': 9, u'cpu_test_status': -1, u'bcaches': [], u'current_commissioning_result_id': 8, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/2/', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 2, u'tags': [u'rotary'], u'name': u'sda', u'system_id': u'bwrbyw', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'path': u'/dev/disk/by-dname/sda', u'size': 2397998940160, u'used_size': 2397998940160, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'e3e50dfd-4902-4674-8f15-d998688158ad', u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/2/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bwrbyw', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'0d85d440-d89b-4a27-843f-ff77496b8d90', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 9, u'size': 2397992648704}]}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'commissioning_status': 2, u'architecture': u'amd64/generic', u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', 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.40', u'mode': u'dhcp', u'id': 33}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'parents': [], 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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', 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.40'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'id': 7, u'system_id': u'bwrbyw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/interfaces/7/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, 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'mode': u'link_up', u'id': 34}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'parents': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'id': 14, u'system_id': u'bwrbyw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/interfaces/14/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, 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'mode': u'link_up', u'id': 35}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'parents': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'id': 15, u'system_id': u'bwrbyw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/interfaces/15/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, 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'mode': u'link_up', u'id': 36}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'parents': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'id': 17, u'system_id': u'bwrbyw', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/interfaces/17/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/2/', u'used_for': u'GPT partitioned with 1 partition', u'type': u'physical', u'id': 2, u'tags': [u'rotary'], u'name': u'sda', u'system_id': u'bwrbyw', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'path': u'/dev/disk/by-dname/sda', u'size': 2397998940160, u'used_size': 2397998940160, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'uuid': u'e3e50dfd-4902-4674-8f15-d998688158ad', u'resource_uri': u'/MAAS/api/2.0/nodes/bwrbyw/blockdevices/2/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'bwrbyw', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'0d85d440-d89b-4a27-843f-ff77496b8d90', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 9, u'size': 2397992648704}]}}
2019-06-04 21:24:26,273 [salt.state       :300 ][INFO    ][4091] {'new': {'storage_layout': 'lvm'}}
2019-06-04 21:24:26,274 [salt.state       :1951][INFO    ][4091] Completed state [maas_machines_storage_cmp001_lvm] at time 21:24:26.274266 duration_in_ms=2800.038
2019-06-04 21:24:26,278 [salt.minion      :1711][INFO    ][4091] Returning information for job: 20190604212415428857
2019-06-04 21:24:26,858 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604212426846194
2019-06-04 21:24:26,878 [salt.minion      :1432][INFO    ][4199] Starting a new job with PID 4199
2019-06-04 21:24:27,587 [salt.state       :915 ][INFO    ][4199] Loading fresh modules for state activity
2019-06-04 21:24:27,641 [salt.fileclient  :1219][INFO    ][4199] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-06-04 21:24:27,686 [salt.state       :1780][INFO    ][4199] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:24:27.686469
2019-06-04 21:24:27,686 [salt.state       :1813][INFO    ][4199] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:24:27,689 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4199] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:24:29,115 [salt.state       :300 ][INFO    ][4199] {'pid': 4206, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:24:29,115 [salt.state       :1951][INFO    ][4199] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:24:29.115793 duration_in_ms=1429.325
2019-06-04 21:24:29,117 [salt.state       :1780][INFO    ][4199] Running state [maas.deploy_machines] at time 21:24:29.117008
2019-06-04 21:24:29,117 [salt.state       :1813][INFO    ][4199] Executing state module.run for [maas.deploy_machines]
2019-06-04 21:24:29,117 [salt.utils.decorators:613 ][WARNING ][4199] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:24:29,746 [salt.loaded.ext.module.maas:684 ][INFO    ][4199] deploymachines hwe_kernel=hwe-16.04 system_id=k6bxmb distro_series=xenial
2019-06-04 21:24:32,585 [salt.loaded.ext.module.maas:684 ][INFO    ][4199] deploymachines hwe_kernel=hwe-16.04 system_id=hrpkk6 distro_series=xenial
2019-06-04 21:24:34,426 [salt.loaded.ext.module.maas:684 ][INFO    ][4199] deploymachines hwe_kernel=hwe-16.04 system_id=ex3tyw distro_series=xenial
2019-06-04 21:24:37,056 [salt.loaded.ext.module.maas:684 ][INFO    ][4199] deploymachines hwe_kernel=hwe-16.04 system_id=bwrbyw distro_series=xenial
2019-06-04 21:24:39,700 [salt.loaded.ext.module.maas:684 ][INFO    ][4199] deploymachines hwe_kernel=hwe-16.04 system_id=bxg4be distro_series=xenial
2019-06-04 21:24:41,802 [salt.state       :300 ][INFO    ][4199] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']}}
2019-06-04 21:24:41,803 [salt.state       :1951][INFO    ][4199] Completed state [maas.deploy_machines] at time 21:24:41.803346 duration_in_ms=12686.335
2019-06-04 21:24:41,807 [salt.minion      :1711][INFO    ][4199] Returning information for job: 20190604212426846194
2019-06-04 21:24:42,401 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604212442388261
2019-06-04 21:24:42,423 [salt.minion      :1432][INFO    ][4486] Starting a new job with PID 4486
2019-06-04 21:24:45,969 [salt.state       :915 ][INFO    ][4486] Loading fresh modules for state activity
2019-06-04 21:24:46,016 [salt.fileclient  :1219][INFO    ][4486] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-06-04 21:24:46,050 [salt.state       :1780][INFO    ][4486] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:24:46.050021
2019-06-04 21:24:46,050 [salt.state       :1813][INFO    ][4486] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:24:46,051 [salt.loaded.int.module.cmdmod:395 ][INFO    ][4486] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:24:47,261 [salt.state       :300 ][INFO    ][4486] {'pid': 4497, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:24:47,261 [salt.state       :1951][INFO    ][4486] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:24:47.261873 duration_in_ms=1211.85
2019-06-04 21:24:47,264 [salt.state       :1780][INFO    ][4486] Running state [maas.wait_for_machine_status] at time 21:24:47.264831
2019-06-04 21:24:47,265 [salt.state       :1813][INFO    ][4486] Executing state module.run for [maas.wait_for_machine_status]
2019-06-04 21:24:47,266 [salt.utils.decorators:613 ][WARNING ][4486] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:24:50,765 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2246.50995493s left)
2019-06-04 21:24:57,479 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212457463119
2019-06-04 21:24:57,502 [salt.minion      :1432][INFO    ][4518] Starting a new job with PID 4518
2019-06-04 21:24:57,527 [salt.minion      :1711][INFO    ][4518] Returning information for job: 20190604212457463119
2019-06-04 21:25:24,381 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2212.89354992s left)
2019-06-04 21:25:27,526 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212527512121
2019-06-04 21:25:27,548 [salt.minion      :1432][INFO    ][4573] Starting a new job with PID 4573
2019-06-04 21:25:27,572 [salt.minion      :1711][INFO    ][4573] Returning information for job: 20190604212527512121
2019-06-04 21:25:57,631 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212557619744
2019-06-04 21:25:57,652 [salt.minion      :1432][INFO    ][4594] Starting a new job with PID 4594
2019-06-04 21:25:57,668 [salt.minion      :1711][INFO    ][4594] Returning information for job: 20190604212557619744
2019-06-04 21:25:58,059 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2179.21598387s left)
2019-06-04 21:26:27,663 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212627651429
2019-06-04 21:26:27,685 [salt.minion      :1432][INFO    ][4753] Starting a new job with PID 4753
2019-06-04 21:26:27,710 [salt.minion      :1711][INFO    ][4753] Returning information for job: 20190604212627651429
2019-06-04 21:26:31,036 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2146.23875308s left)
2019-06-04 21:26:57,714 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212657702530
2019-06-04 21:26:57,737 [salt.minion      :1432][INFO    ][4915] Starting a new job with PID 4915
2019-06-04 21:26:57,761 [salt.minion      :1711][INFO    ][4915] Returning information for job: 20190604212657702530
2019-06-04 21:27:04,397 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2112.87824392s left)
2019-06-04 21:27:27,767 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212727761266
2019-06-04 21:27:27,778 [salt.minion      :1432][INFO    ][5558] Starting a new job with PID 5558
2019-06-04 21:27:27,790 [salt.minion      :1711][INFO    ][5558] Returning information for job: 20190604212727761266
2019-06-04 21:27:37,727 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2079.54832697s left)
2019-06-04 21:27:57,809 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212757795800
2019-06-04 21:27:57,828 [salt.minion      :1432][INFO    ][5752] Starting a new job with PID 5752
2019-06-04 21:27:57,849 [salt.minion      :1711][INFO    ][5752] Returning information for job: 20190604212757795800
2019-06-04 21:28:11,469 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2045.80595589s left)
2019-06-04 21:28:27,867 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212827854427
2019-06-04 21:28:27,890 [salt.minion      :1432][INFO    ][5868] Starting a new job with PID 5868
2019-06-04 21:28:27,912 [salt.minion      :1711][INFO    ][5868] Returning information for job: 20190604212827854427
2019-06-04 21:28:44,974 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2012.30118608s left)
2019-06-04 21:28:57,932 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212857919905
2019-06-04 21:28:57,955 [salt.minion      :1432][INFO    ][5899] Starting a new job with PID 5899
2019-06-04 21:28:57,978 [salt.minion      :1711][INFO    ][5899] Returning information for job: 20190604212857919905
2019-06-04 21:29:18,484 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1978.79070592s left)
2019-06-04 21:29:28,001 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212927991256
2019-06-04 21:29:28,021 [salt.minion      :1432][INFO    ][6501] Starting a new job with PID 6501
2019-06-04 21:29:28,041 [salt.minion      :1711][INFO    ][6501] Returning information for job: 20190604212927991256
2019-06-04 21:29:52,394 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1944.88058591s left)
2019-06-04 21:29:58,068 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604212958055235
2019-06-04 21:29:58,090 [salt.minion      :1432][INFO    ][6528] Starting a new job with PID 6528
2019-06-04 21:29:58,115 [salt.minion      :1711][INFO    ][6528] Returning information for job: 20190604212958055235
2019-06-04 21:30:25,428 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1911.846627s left)
2019-06-04 21:30:28,148 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213028136114
2019-06-04 21:30:28,169 [salt.minion      :1432][INFO    ][6943] Starting a new job with PID 6943
2019-06-04 21:30:28,193 [salt.minion      :1711][INFO    ][6943] Returning information for job: 20190604213028136114
2019-06-04 21:30:58,235 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213058222760
2019-06-04 21:30:58,254 [salt.minion      :1432][INFO    ][6964] Starting a new job with PID 6964
2019-06-04 21:30:58,280 [salt.minion      :1711][INFO    ][6964] Returning information for job: 20190604213058222760
2019-06-04 21:30:59,004 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1878.27130103s left)
2019-06-04 21:31:28,316 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213128303668
2019-06-04 21:31:28,339 [salt.minion      :1432][INFO    ][7019] Starting a new job with PID 7019
2019-06-04 21:31:28,363 [salt.minion      :1711][INFO    ][7019] Returning information for job: 20190604213128303668
2019-06-04 21:31:32,761 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1844.51440406s left)
2019-06-04 21:31:58,417 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213158405228
2019-06-04 21:31:58,440 [salt.minion      :1432][INFO    ][7147] Starting a new job with PID 7147
2019-06-04 21:31:58,463 [salt.minion      :1711][INFO    ][7147] Returning information for job: 20190604213158405228
2019-06-04 21:32:06,140 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'odl01', 'ctl01']
sleep for:30s Timeout:2250s (1811.13491988s left)
2019-06-04 21:32:28,481 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213228468413
2019-06-04 21:32:28,503 [salt.minion      :1432][INFO    ][7525] Starting a new job with PID 7525
2019-06-04 21:32:28,527 [salt.minion      :1711][INFO    ][7525] Returning information for job: 20190604213228468413
2019-06-04 21:32:39,653 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1777.62164903s left)
2019-06-04 21:32:58,587 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213258574408
2019-06-04 21:32:58,610 [salt.minion      :1432][INFO    ][7568] Starting a new job with PID 7568
2019-06-04 21:32:58,633 [salt.minion      :1711][INFO    ][7568] Returning information for job: 20190604213258574408
2019-06-04 21:33:12,909 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1744.36560988s left)
2019-06-04 21:33:28,702 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213328689709
2019-06-04 21:33:28,724 [salt.minion      :1432][INFO    ][7798] Starting a new job with PID 7798
2019-06-04 21:33:28,749 [salt.minion      :1711][INFO    ][7798] Returning information for job: 20190604213328689709
2019-06-04 21:33:46,504 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1710.77062988s left)
2019-06-04 21:33:58,826 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213358813336
2019-06-04 21:33:58,848 [salt.minion      :1432][INFO    ][7829] Starting a new job with PID 7829
2019-06-04 21:33:58,873 [salt.minion      :1711][INFO    ][7829] Returning information for job: 20190604213358813336
2019-06-04 21:34:20,063 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1677.21183109s left)
2019-06-04 21:34:28,954 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213428940681
2019-06-04 21:34:28,979 [salt.minion      :1432][INFO    ][7886] Starting a new job with PID 7886
2019-06-04 21:34:29,000 [salt.minion      :1711][INFO    ][7886] Returning information for job: 20190604213428940681
2019-06-04 21:34:53,545 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1643.73026299s left)
2019-06-04 21:34:59,094 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213459081814
2019-06-04 21:34:59,117 [salt.minion      :1432][INFO    ][7906] Starting a new job with PID 7906
2019-06-04 21:34:59,141 [salt.minion      :1711][INFO    ][7906] Returning information for job: 20190604213459081814
2019-06-04 21:35:26,738 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1610.53648496s left)
2019-06-04 21:35:29,230 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213529219774
2019-06-04 21:35:29,251 [salt.minion      :1432][INFO    ][7962] Starting a new job with PID 7962
2019-06-04 21:35:29,274 [salt.minion      :1711][INFO    ][7962] Returning information for job: 20190604213529219774
2019-06-04 21:35:59,378 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213559365744
2019-06-04 21:35:59,401 [salt.minion      :1432][INFO    ][7982] Starting a new job with PID 7982
2019-06-04 21:35:59,425 [salt.minion      :1711][INFO    ][7982] Returning information for job: 20190604213559365744
2019-06-04 21:36:00,115 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1577.1596179s left)
2019-06-04 21:36:29,534 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213629523376
2019-06-04 21:36:29,555 [salt.minion      :1432][INFO    ][8038] Starting a new job with PID 8038
2019-06-04 21:36:29,578 [salt.minion      :1711][INFO    ][8038] Returning information for job: 20190604213629523376
2019-06-04 21:36:32,868 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1544.40748405s left)
2019-06-04 21:36:59,698 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213659686024
2019-06-04 21:36:59,721 [salt.minion      :1432][INFO    ][8070] Starting a new job with PID 8070
2019-06-04 21:36:59,745 [salt.minion      :1711][INFO    ][8070] Returning information for job: 20190604213659686024
2019-06-04 21:37:06,369 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1510.90603995s left)
2019-06-04 21:37:29,876 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213729863691
2019-06-04 21:37:29,898 [salt.minion      :1432][INFO    ][8128] Starting a new job with PID 8128
2019-06-04 21:37:29,923 [salt.minion      :1711][INFO    ][8128] Returning information for job: 20190604213729863691
2019-06-04 21:37:39,348 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1477.92680907s left)
2019-06-04 21:38:00,061 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213800048328
2019-06-04 21:38:00,083 [salt.minion      :1432][INFO    ][8148] Starting a new job with PID 8148
2019-06-04 21:38:00,106 [salt.minion      :1711][INFO    ][8148] Returning information for job: 20190604213800048328
2019-06-04 21:38:12,735 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1444.5395s left)
2019-06-04 21:38:30,256 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213830243306
2019-06-04 21:38:30,279 [salt.minion      :1432][INFO    ][8333] Starting a new job with PID 8333
2019-06-04 21:38:30,301 [salt.minion      :1711][INFO    ][8333] Returning information for job: 20190604213830243306
2019-06-04 21:38:46,222 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1411.05317903s left)
2019-06-04 21:39:00,463 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213900450249
2019-06-04 21:39:00,486 [salt.minion      :1432][INFO    ][8353] Starting a new job with PID 8353
2019-06-04 21:39:00,511 [salt.minion      :1711][INFO    ][8353] Returning information for job: 20190604213900450249
2019-06-04 21:39:19,296 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1377.97877097s left)
2019-06-04 21:39:30,684 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604213930671209
2019-06-04 21:39:30,707 [salt.minion      :1432][INFO    ][8411] Starting a new job with PID 8411
2019-06-04 21:39:30,729 [salt.minion      :1711][INFO    ][8411] Returning information for job: 20190604213930671209
2019-06-04 21:39:52,759 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1344.5161159s left)
2019-06-04 21:40:00,909 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214000897274
2019-06-04 21:40:00,933 [salt.minion      :1432][INFO    ][8431] Starting a new job with PID 8431
2019-06-04 21:40:00,958 [salt.minion      :1711][INFO    ][8431] Returning information for job: 20190604214000897274
2019-06-04 21:40:26,337 [salt.loaded.ext.module.maas:1023][INFO    ][4486] Waiting status:Deployed for machines:['gtw01']
sleep for:30s Timeout:2250s (1310.93827605s left)
2019-06-04 21:40:30,942 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214030929841
2019-06-04 21:40:30,964 [salt.minion      :1432][INFO    ][8495] Starting a new job with PID 8495
2019-06-04 21:40:30,987 [salt.minion      :1711][INFO    ][8495] Returning information for job: 20190604214030929841
2019-06-04 21:40:57,063 [salt.loaded.ext.module.maas:993 ][INFO    ][4486] Machine k6bxmb mark broken
2019-06-04 21:40:57,836 [salt.loaded.ext.module.maas:996 ][INFO    ][4486] Machine k6bxmb mark fixed
2019-06-04 21:40:59,044 [salt.loaded.ext.module.maas:684 ][INFO    ][4486] deploymachines hwe_kernel=hwe-16.04 system_id=k6bxmb distro_series=xenial
2019-06-04 21:41:00,978 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214100965626
2019-06-04 21:41:01,001 [salt.minion      :1432][INFO    ][8576] Starting a new job with PID 8576
2019-06-04 21:41:01,024 [salt.minion      :1711][INFO    ][8576] Returning information for job: 20190604214100965626
2019-06-04 21:41:01,808 [salt.loaded.ext.module.maas:160 ][ERROR   ][4486] Failed for object gtw01 reason Unable to change power state to 'cycle' for node gtw01: another action is already in progress for that node.
2019-06-04 21:41:01,810 [salt.state       :302 ][ERROR   ][4486] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'odl01', 'cmp001', 'ctl01'], 'errors': {'gtw01': "Unable to change power state to 'cycle' for node gtw01: another action is already in progress for that node."}, 'success': []}
2019-06-04 21:41:01,811 [salt.state       :1951][INFO    ][4486] Completed state [maas.wait_for_machine_status] at time 21:41:01.811024 duration_in_ms=974546.171
2019-06-04 21:41:01,820 [salt.minion      :1711][INFO    ][4486] Returning information for job: 20190604212442388261
2019-06-04 21:41:12,560 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command pillar.get with jid 20190604214112548615
2019-06-04 21:41:12,581 [salt.minion      :1432][INFO    ][8596] Starting a new job with PID 8596
2019-06-04 21:41:12,586 [salt.minion      :1711][INFO    ][8596] Returning information for job: 20190604214112548615
2019-06-04 21:41:13,068 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command service.status with jid 20190604214113055551
2019-06-04 21:41:13,089 [salt.minion      :1432][INFO    ][8601] Starting a new job with PID 8601
2019-06-04 21:41:13,479 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][8601] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-04 21:41:13,511 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][8601] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-04 21:41:13,525 [salt.minion      :1711][INFO    ][8601] Returning information for job: 20190604214113055551
2019-06-04 21:41:14,018 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604214114011311
2019-06-04 21:41:14,039 [salt.minion      :1432][INFO    ][8612] Starting a new job with PID 8612
2019-06-04 21:41:17,640 [salt.state       :915 ][INFO    ][8612] Loading fresh modules for state activity
2019-06-04 21:41:18,090 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command 'salt-minion --version' in directory '/root'
2019-06-04 21:41:18,441 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command 'salt-minion --version' in directory '/root'
2019-06-04 21:41:19,324 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command 'salt-minion --version' in directory '/root'
2019-06-04 21:41:19,681 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command 'salt-minion --version' in directory '/root'
2019-06-04 21:41:21,094 [salt.state       :1780][INFO    ][8612] Running state [salt-minion] at time 21:41:21.094461
2019-06-04 21:41:21,094 [salt.state       :1813][INFO    ][8612] Executing state pkg.installed for [salt-minion]
2019-06-04 21:41:21,095 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-04 21:41:21,196 [salt.state       :300 ][INFO    ][8612] All specified packages are already installed
2019-06-04 21:41:21,197 [salt.state       :1951][INFO    ][8612] Completed state [salt-minion] at time 21:41:21.197149 duration_in_ms=102.688
2019-06-04 21:41:21,197 [salt.state       :1780][INFO    ][8612] Running state [salt_minion_dependency_packages] at time 21:41:21.197567
2019-06-04 21:41:21,197 [salt.state       :1813][INFO    ][8612] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-04 21:41:21,205 [salt.state       :300 ][INFO    ][8612] All specified packages are already installed
2019-06-04 21:41:21,206 [salt.state       :1951][INFO    ][8612] Completed state [salt_minion_dependency_packages] at time 21:41:21.206096 duration_in_ms=8.529
2019-06-04 21:41:21,209 [salt.state       :1780][INFO    ][8612] Running state [/etc/salt/minion.d/minion.conf] at time 21:41:21.209878
2019-06-04 21:41:21,210 [salt.state       :1813][INFO    ][8612] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-04 21:41:21,400 [salt.state       :300 ][INFO    ][8612] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-04 21:41:21,400 [salt.state       :1951][INFO    ][8612] Completed state [/etc/salt/minion.d/minion.conf] at time 21:41:21.400737 duration_in_ms=190.859
2019-06-04 21:41:21,402 [salt.state       :1780][INFO    ][8612] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:41:21.402827
2019-06-04 21:41:21,403 [salt.state       :1813][INFO    ][8612] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-04 21:41:21,412 [salt.state       :300 ][INFO    ][8612] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-04 21:41:21,412 [salt.state       :1951][INFO    ][8612] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:41:21.412445 duration_in_ms=9.618
2019-06-04 21:41:21,413 [salt.state       :1780][INFO    ][8612] Running state [salt-minion] at time 21:41:21.413081
2019-06-04 21:41:21,413 [salt.state       :1813][INFO    ][8612] Executing state service.running for [salt-minion]
2019-06-04 21:41:21,413 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-04 21:41:21,448 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-04 21:41:21,464 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-04 21:41:21,480 [salt.state       :300 ][INFO    ][8612] The service salt-minion is already running
2019-06-04 21:41:21,480 [salt.state       :1951][INFO    ][8612] Completed state [salt-minion] at time 21:41:21.480910 duration_in_ms=67.829
2019-06-04 21:41:21,482 [salt.state       :1780][INFO    ][8612] Running state [/etc/salt/grains.d] at time 21:41:21.481997
2019-06-04 21:41:21,482 [salt.state       :1813][INFO    ][8612] Executing state file.directory for [/etc/salt/grains.d]
2019-06-04 21:41:21,482 [salt.state       :300 ][INFO    ][8612] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-04 21:41:21,483 [salt.state       :1951][INFO    ][8612] Completed state [/etc/salt/grains.d] at time 21:41:21.483125 duration_in_ms=1.128
2019-06-04 21:41:21,483 [salt.state       :1780][INFO    ][8612] Running state [/etc/salt/grains] at time 21:41:21.483619
2019-06-04 21:41:21,483 [salt.state       :1813][INFO    ][8612] Executing state file.managed for [/etc/salt/grains]
2019-06-04 21:41:21,484 [salt.state       :300 ][INFO    ][8612] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-04 21:41:21,484 [salt.state       :1951][INFO    ][8612] Completed state [/etc/salt/grains] at time 21:41:21.484407 duration_in_ms=0.788
2019-06-04 21:41:21,484 [salt.state       :1780][INFO    ][8612] Running state [/etc/salt/grains.d/placeholder] at time 21:41:21.484751
2019-06-04 21:41:21,484 [salt.state       :1813][INFO    ][8612] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-04 21:41:21,485 [salt.state       :300 ][INFO    ][8612] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-04 21:41:21,485 [salt.state       :1951][INFO    ][8612] Completed state [/etc/salt/grains.d/placeholder] at time 21:41:21.485503 duration_in_ms=0.752
2019-06-04 21:41:21,485 [salt.state       :1780][INFO    ][8612] Running state [/etc/salt/grains.d/sphinx] at time 21:41:21.485836
2019-06-04 21:41:21,486 [salt.state       :1813][INFO    ][8612] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-04 21:41:21,496 [salt.state       :300 ][INFO    ][8612] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-04 21:41:21,496 [salt.state       :1951][INFO    ][8612] Completed state [/etc/salt/grains.d/sphinx] at time 21:41:21.496406 duration_in_ms=10.57
2019-06-04 21:41:21,498 [salt.state       :1780][INFO    ][8612] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:41:21.498075
2019-06-04 21:41:21,498 [salt.state       :1813][INFO    ][8612] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-04 21:41:21,498 [salt.state       :300 ][INFO    ][8612] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-04 21:41:21,498 [salt.state       :1951][INFO    ][8612] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:41:21.498742 duration_in_ms=0.667
2019-06-04 21:41:21,499 [salt.state       :1780][INFO    ][8612] Running state [/etc/salt/grains.d/dns_records] at time 21:41:21.499081
2019-06-04 21:41:21,499 [salt.state       :1813][INFO    ][8612] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-04 21:41:21,507 [salt.state       :300 ][INFO    ][8612] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-04 21:41:21,508 [salt.state       :1951][INFO    ][8612] Completed state [/etc/salt/grains.d/dns_records] at time 21:41:21.508138 duration_in_ms=9.057
2019-06-04 21:41:21,508 [salt.state       :1780][INFO    ][8612] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:41:21.508812
2019-06-04 21:41:21,509 [salt.state       :1813][INFO    ][8612] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-04 21:41:21,509 [salt.state       :300 ][INFO    ][8612] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-04 21:41:21,509 [salt.state       :1951][INFO    ][8612] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:41:21.509457 duration_in_ms=0.645
2019-06-04 21:41:21,509 [salt.state       :1780][INFO    ][8612] Running state [/etc/salt/grains.d/salt] at time 21:41:21.509817
2019-06-04 21:41:21,510 [salt.state       :1813][INFO    ][8612] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-04 21:41:21,519 [salt.state       :300 ][INFO    ][8612] File /etc/salt/grains.d/salt is in the correct state
2019-06-04 21:41:21,520 [salt.state       :1951][INFO    ][8612] Completed state [/etc/salt/grains.d/salt] at time 21:41:21.520092 duration_in_ms=10.275
2019-06-04 21:41:21,520 [salt.state       :1780][INFO    ][8612] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:41:21.520735
2019-06-04 21:41:21,520 [salt.state       :1813][INFO    ][8612] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-04 21:41:21,521 [salt.state       :300 ][INFO    ][8612] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-04 21:41:21,521 [salt.state       :1951][INFO    ][8612] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:41:21.521367 duration_in_ms=0.632
2019-06-04 21:41:21,522 [salt.state       :1780][INFO    ][8612] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:41:21.522727
2019-06-04 21:41:21,522 [salt.state       :1813][INFO    ][8612] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-04 21:41:21,523 [salt.state       :300 ][INFO    ][8612] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-04 21:41:21,523 [salt.state       :1951][INFO    ][8612] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:41:21.523379 duration_in_ms=0.651
2019-06-04 21:41:21,523 [salt.state       :1780][INFO    ][8612] Running state [mine.update] at time 21:41:21.523885
2019-06-04 21:41:21,524 [salt.state       :1813][INFO    ][8612] Executing state module.wait for [mine.update]
2019-06-04 21:41:21,524 [salt.state       :300 ][INFO    ][8612] No changes made for mine.update
2019-06-04 21:41:21,524 [salt.state       :1951][INFO    ][8612] Completed state [mine.update] at time 21:41:21.524496 duration_in_ms=0.611
2019-06-04 21:41:21,524 [salt.state       :1780][INFO    ][8612] Running state [ca-certificates] at time 21:41:21.524691
2019-06-04 21:41:21,524 [salt.state       :1813][INFO    ][8612] Executing state pkg.installed for [ca-certificates]
2019-06-04 21:41:21,530 [salt.state       :300 ][INFO    ][8612] All specified packages are already installed
2019-06-04 21:41:21,530 [salt.state       :1951][INFO    ][8612] Completed state [ca-certificates] at time 21:41:21.530684 duration_in_ms=5.993
2019-06-04 21:41:21,531 [salt.state       :1780][INFO    ][8612] Running state [update-ca-certificates] at time 21:41:21.531432
2019-06-04 21:41:21,531 [salt.state       :1813][INFO    ][8612] Executing state cmd.wait for [update-ca-certificates]
2019-06-04 21:41:21,531 [salt.state       :300 ][INFO    ][8612] No changes made for update-ca-certificates
2019-06-04 21:41:21,532 [salt.state       :1951][INFO    ][8612] Completed state [update-ca-certificates] at time 21:41:21.532080 duration_in_ms=0.648
2019-06-04 21:41:21,532 [salt.state       :1780][INFO    ][8612] Running state [iptables] at time 21:41:21.532268
2019-06-04 21:41:21,532 [salt.state       :1813][INFO    ][8612] Executing state pkg.installed for [iptables]
2019-06-04 21:41:21,537 [salt.state       :300 ][INFO    ][8612] All specified packages are already installed
2019-06-04 21:41:21,537 [salt.state       :1951][INFO    ][8612] Completed state [iptables] at time 21:41:21.537395 duration_in_ms=5.127
2019-06-04 21:41:21,537 [salt.state       :1780][INFO    ][8612] Running state [iptables-persistent] at time 21:41:21.537599
2019-06-04 21:41:21,537 [salt.state       :1813][INFO    ][8612] Executing state pkg.installed for [iptables-persistent]
2019-06-04 21:41:21,542 [salt.state       :300 ][INFO    ][8612] All specified packages are already installed
2019-06-04 21:41:21,542 [salt.state       :1951][INFO    ][8612] Completed state [iptables-persistent] at time 21:41:21.542826 duration_in_ms=5.227
2019-06-04 21:41:21,543 [salt.state       :1780][INFO    ][8612] Running state [iptables_modules_v4_load] at time 21:41:21.543577
2019-06-04 21:41:21,543 [salt.state       :1813][INFO    ][8612] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-04 21:41:21,544 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command 'lsmod' in directory '/root'
2019-06-04 21:41:21,568 [salt.state       :300 ][INFO    ][8612] Kernel modules iptable_filter, ip_tables are already present
2019-06-04 21:41:21,568 [salt.state       :1951][INFO    ][8612] Completed state [iptables_modules_v4_load] at time 21:41:21.568536 duration_in_ms=24.959
2019-06-04 21:41:21,569 [salt.state       :1780][INFO    ][8612] Running state [/etc/iptables/rules.v4] at time 21:41:21.569150
2019-06-04 21:41:21,569 [salt.state       :1813][INFO    ][8612] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-04 21:41:21,652 [salt.state       :300 ][INFO    ][8612] File /etc/iptables/rules.v4 is in the correct state
2019-06-04 21:41:21,652 [salt.state       :1951][INFO    ][8612] Completed state [/etc/iptables/rules.v4] at time 21:41:21.652250 duration_in_ms=83.1
2019-06-04 21:41:21,653 [salt.state       :1780][INFO    ][8612] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:41:21.653117
2019-06-04 21:41:21,653 [salt.state       :1813][INFO    ][8612] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-04 21:41:21,653 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-04 21:41:21,673 [salt.state       :300 ][INFO    ][8612] onlyif execution failed
2019-06-04 21:41:21,674 [salt.state       :1951][INFO    ][8612] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:41:21.674091 duration_in_ms=20.974
2019-06-04 21:41:21,674 [salt.state       :1780][INFO    ][8612] Running state [netfilter-persistent] at time 21:41:21.674931
2019-06-04 21:41:21,675 [salt.state       :1813][INFO    ][8612] Executing state service.running for [netfilter-persistent]
2019-06-04 21:41:21,675 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-04 21:41:21,695 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-04 21:41:21,712 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-04 21:41:21,729 [salt.state       :300 ][INFO    ][8612] The service netfilter-persistent is already running
2019-06-04 21:41:21,729 [salt.state       :1951][INFO    ][8612] Completed state [netfilter-persistent] at time 21:41:21.729870 duration_in_ms=54.938
2019-06-04 21:41:21,730 [salt.state       :1780][INFO    ][8612] Running state [iptables_extra.remove_stale_tables] at time 21:41:21.730652
2019-06-04 21:41:21,731 [salt.state       :1813][INFO    ][8612] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-04 21:41:21,731 [salt.state       :300 ][INFO    ][8612] No changes made for iptables_extra.remove_stale_tables
2019-06-04 21:41:21,731 [salt.state       :1951][INFO    ][8612] Completed state [iptables_extra.remove_stale_tables] at time 21:41:21.731546 duration_in_ms=0.894
2019-06-04 21:41:21,731 [salt.state       :1780][INFO    ][8612] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:41:21.731796
2019-06-04 21:41:21,732 [salt.state       :1813][INFO    ][8612] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-04 21:41:21,732 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8612] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-04 21:41:21,747 [salt.state       :300 ][INFO    ][8612] onlyif execution failed
2019-06-04 21:41:21,748 [salt.state       :1951][INFO    ][8612] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:41:21.748139 duration_in_ms=16.342
2019-06-04 21:41:21,749 [salt.state       :1780][INFO    ][8612] Running state [/etc/iptables/rules.v6] at time 21:41:21.749747
2019-06-04 21:41:21,750 [salt.state       :1813][INFO    ][8612] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-04 21:41:21,751 [salt.state       :300 ][INFO    ][8612] File /etc/iptables/rules.v6 is not present
2019-06-04 21:41:21,751 [salt.state       :1951][INFO    ][8612] Completed state [/etc/iptables/rules.v6] at time 21:41:21.751365 duration_in_ms=1.618
2019-06-04 21:41:21,752 [salt.state       :1780][INFO    ][8612] Running state [iptables_extra.flush_all] at time 21:41:21.752476
2019-06-04 21:41:21,752 [salt.state       :1813][INFO    ][8612] Executing state module.wait for [iptables_extra.flush_all]
2019-06-04 21:41:21,753 [salt.state       :300 ][INFO    ][8612] No changes made for iptables_extra.flush_all
2019-06-04 21:41:21,753 [salt.state       :1951][INFO    ][8612] Completed state [iptables_extra.flush_all] at time 21:41:21.753758 duration_in_ms=1.281
2019-06-04 21:41:21,757 [salt.minion      :1711][INFO    ][8612] Returning information for job: 20190604214114011311
2019-06-04 21:41:22,351 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604214122337512
2019-06-04 21:41:22,374 [salt.minion      :1432][INFO    ][8703] Starting a new job with PID 8703
2019-06-04 21:41:23,082 [salt.state       :915 ][INFO    ][8703] Loading fresh modules for state activity
2019-06-04 21:41:23,715 [salt.state       :1780][INFO    ][8703] Running state [maas-rack-controller] at time 21:41:23.715519
2019-06-04 21:41:23,716 [salt.state       :1813][INFO    ][8703] Executing state pkg.installed for [maas-rack-controller]
2019-06-04 21:41:23,716 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8703] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-04 21:41:23,826 [salt.state       :300 ][INFO    ][8703] All specified packages are already installed
2019-06-04 21:41:23,826 [salt.state       :1951][INFO    ][8703] Completed state [maas-rack-controller] at time 21:41:23.826769 duration_in_ms=111.251
2019-06-04 21:41:23,827 [salt.state       :1780][INFO    ][8703] Running state [ipmitool] at time 21:41:23.827185
2019-06-04 21:41:23,827 [salt.state       :1813][INFO    ][8703] Executing state pkg.installed for [ipmitool]
2019-06-04 21:41:23,836 [salt.state       :300 ][INFO    ][8703] All specified packages are already installed
2019-06-04 21:41:23,836 [salt.state       :1951][INFO    ][8703] Completed state [ipmitool] at time 21:41:23.836372 duration_in_ms=9.187
2019-06-04 21:41:23,840 [salt.state       :1780][INFO    ][8703] Running state [/etc/maas/rackd.conf] at time 21:41:23.840202
2019-06-04 21:41:23,840 [salt.state       :1813][INFO    ][8703] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-04 21:41:23,841 [salt.state       :300 ][INFO    ][8703] No changes needed to be made
2019-06-04 21:41:23,842 [salt.state       :1951][INFO    ][8703] Completed state [/etc/maas/rackd.conf] at time 21:41:23.842196 duration_in_ms=1.994
2019-06-04 21:41:23,842 [salt.state       :1780][INFO    ][8703] Running state [/etc/maas/rackd.conf] at time 21:41:23.842502
2019-06-04 21:41:23,842 [salt.state       :1813][INFO    ][8703] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-04 21:41:23,843 [salt.loaded.int.states.file:2298][WARNING ][8703] 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-06-04 21:41:23,843 [salt.state       :300 ][INFO    ][8703] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-04 21:41:23,844 [salt.state       :1951][INFO    ][8703] Completed state [/etc/maas/rackd.conf] at time 21:41:23.844102 duration_in_ms=1.6
2019-06-04 21:41:23,845 [salt.state       :1780][INFO    ][8703] Running state [maas-rackd] at time 21:41:23.845305
2019-06-04 21:41:23,845 [salt.state       :1813][INFO    ][8703] Executing state service.running for [maas-rackd]
2019-06-04 21:41:23,846 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8703] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-04 21:41:23,883 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8703] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-04 21:41:23,901 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8703] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-04 21:41:23,919 [salt.state       :300 ][INFO    ][8703] The service maas-rackd is already running
2019-06-04 21:41:23,919 [salt.state       :1951][INFO    ][8703] Completed state [maas-rackd] at time 21:41:23.919390 duration_in_ms=74.084
2019-06-04 21:41:23,921 [salt.minion      :1711][INFO    ][8703] Returning information for job: 20190604214122337512
2019-06-04 21:41:24,507 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604214124498138
2019-06-04 21:41:24,525 [salt.minion      :1432][INFO    ][8747] Starting a new job with PID 8747
2019-06-04 21:41:25,137 [salt.state       :915 ][INFO    ][8747] Loading fresh modules for state activity
2019-06-04 21:41:25,804 [salt.state       :1780][INFO    ][8747] Running state [maas-region-controller] at time 21:41:25.804329
2019-06-04 21:41:25,804 [salt.state       :1813][INFO    ][8747] Executing state pkg.installed for [maas-region-controller]
2019-06-04 21:41:25,805 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-04 21:41:25,910 [salt.state       :300 ][INFO    ][8747] All specified packages are already installed
2019-06-04 21:41:25,910 [salt.state       :1951][INFO    ][8747] Completed state [maas-region-controller] at time 21:41:25.910780 duration_in_ms=106.451
2019-06-04 21:41:25,911 [salt.state       :1780][INFO    ][8747] Running state [python-oauth] at time 21:41:25.911198
2019-06-04 21:41:25,911 [salt.state       :1813][INFO    ][8747] Executing state pkg.installed for [python-oauth]
2019-06-04 21:41:25,919 [salt.state       :300 ][INFO    ][8747] All specified packages are already installed
2019-06-04 21:41:25,920 [salt.state       :1951][INFO    ][8747] Completed state [python-oauth] at time 21:41:25.920172 duration_in_ms=8.974
2019-06-04 21:41:25,924 [salt.state       :1780][INFO    ][8747] Running state [/etc/maas/regiond.conf] at time 21:41:25.924002
2019-06-04 21:41:25,924 [salt.state       :1813][INFO    ][8747] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-04 21:41:25,976 [salt.state       :300 ][INFO    ][8747] No changes needed to be made
2019-06-04 21:41:25,977 [salt.state       :1951][INFO    ][8747] Completed state [/etc/maas/regiond.conf] at time 21:41:25.977025 duration_in_ms=53.022
2019-06-04 21:41:25,977 [salt.state       :1780][INFO    ][8747] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:41:25.977729
2019-06-04 21:41:25,978 [salt.state       :1813][INFO    ][8747] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-04 21:41:26,059 [salt.state       :300 ][INFO    ][8747] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-04 21:41:26,060 [salt.state       :1951][INFO    ][8747] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:41:26.059961 duration_in_ms=82.231
2019-06-04 21:41:26,060 [salt.state       :1780][INFO    ][8747] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:41:26.060640
2019-06-04 21:41:26,061 [salt.state       :1813][INFO    ][8747] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-04 21:41:26,091 [salt.state       :300 ][INFO    ][8747] No changes needed to be made
2019-06-04 21:41:26,091 [salt.state       :1951][INFO    ][8747] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:41:26.091925 duration_in_ms=31.285
2019-06-04 21:41:26,092 [salt.state       :1780][INFO    ][8747] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:41:26.092600
2019-06-04 21:41:26,093 [salt.state       :1813][INFO    ][8747] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-04 21:41:26,109 [salt.state       :300 ][INFO    ][8747] No changes needed to be made
2019-06-04 21:41:26,109 [salt.state       :1951][INFO    ][8747] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:41:26.109763 duration_in_ms=17.163
2019-06-04 21:41:26,110 [salt.state       :1780][INFO    ][8747] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:41:26.110420
2019-06-04 21:41:26,110 [salt.state       :1813][INFO    ][8747] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-04 21:41:26,142 [salt.state       :300 ][INFO    ][8747] No changes needed to be made
2019-06-04 21:41:26,142 [salt.state       :1951][INFO    ][8747] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:41:26.142350 duration_in_ms=31.93
2019-06-04 21:41:26,143 [salt.state       :1780][INFO    ][8747] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:41:26.142948
2019-06-04 21:41:26,143 [salt.state       :1813][INFO    ][8747] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-04 21:41:26,155 [salt.state       :300 ][INFO    ][8747] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-04 21:41:26,156 [salt.state       :1951][INFO    ][8747] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:41:26.155976 duration_in_ms=13.028
2019-06-04 21:41:26,157 [salt.state       :1780][INFO    ][8747] Running state [a2enmod headers] at time 21:41:26.157423
2019-06-04 21:41:26,157 [salt.state       :1813][INFO    ][8747] Executing state cmd.run for [a2enmod headers]
2019-06-04 21:41:26,158 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command 'a2enmod headers' in directory '/root'
2019-06-04 21:41:26,234 [salt.state       :300 ][INFO    ][8747] {'pid': 8772, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-04 21:41:26,235 [salt.state       :1951][INFO    ][8747] Completed state [a2enmod headers] at time 21:41:26.235087 duration_in_ms=77.664
2019-06-04 21:41:26,235 [salt.state       :1780][INFO    ][8747] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:41:26.235672
2019-06-04 21:41:26,236 [salt.state       :1813][INFO    ][8747] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-04 21:41:26,255 [salt.state       :300 ][INFO    ][8747] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-04 21:41:26,255 [salt.state       :1951][INFO    ][8747] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:41:26.255874 duration_in_ms=20.202
2019-06-04 21:41:26,256 [salt.state       :1780][INFO    ][8747] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:41:26.256733
2019-06-04 21:41:26,257 [salt.state       :1813][INFO    ][8747] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-04 21:41:26,347 [salt.state       :300 ][INFO    ][8747] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-04 21:41:26,347 [salt.state       :1951][INFO    ][8747] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:41:26.347862 duration_in_ms=91.129
2019-06-04 21:41:26,348 [salt.state       :1780][INFO    ][8747] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:41:26.348653
2019-06-04 21:41:26,349 [salt.state       :1813][INFO    ][8747] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-04 21:41:26,437 [salt.state       :300 ][INFO    ][8747] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-04 21:41:26,437 [salt.state       :1951][INFO    ][8747] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:41:26.437818 duration_in_ms=89.165
2019-06-04 21:41:26,438 [salt.state       :1780][INFO    ][8747] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:41:26.438595
2019-06-04 21:41:26,439 [salt.state       :1813][INFO    ][8747] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-04 21:41:26,509 [salt.state       :300 ][INFO    ][8747] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-04 21:41:26,509 [salt.state       :1951][INFO    ][8747] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:41:26.509465 duration_in_ms=70.87
2019-06-04 21:41:26,509 [salt.state       :1780][INFO    ][8747] Running state [/root/.pgpass] at time 21:41:26.509889
2019-06-04 21:41:26,510 [salt.state       :1813][INFO    ][8747] Executing state file.managed for [/root/.pgpass]
2019-06-04 21:41:26,568 [salt.state       :300 ][INFO    ][8747] File /root/.pgpass is in the correct state
2019-06-04 21:41:26,569 [salt.state       :1951][INFO    ][8747] Completed state [/root/.pgpass] at time 21:41:26.569062 duration_in_ms=59.174
2019-06-04 21:41:26,575 [salt.state       :1780][INFO    ][8747] Running state [maas-region syncdb --noinput] at time 21:41:26.575848
2019-06-04 21:41:26,576 [salt.state       :1813][INFO    ][8747] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-04 21:41:26,577 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-04 21:41:28,668 [salt.state       :300 ][INFO    ][8747] {'pid': 8785, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: maasserver, contenttypes, sites, sessions, piston3, auth, metadataserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-04 21:41:28,669 [salt.state       :1951][INFO    ][8747] Completed state [maas-region syncdb --noinput] at time 21:41:28.669158 duration_in_ms=2093.309
2019-06-04 21:41:28,669 [salt.state       :2022][WARNING ][8747] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-04 21:41:28,672 [salt.state       :1780][INFO    ][8747] Running state [maas-regiond] at time 21:41:28.672454
2019-06-04 21:41:28,673 [salt.state       :1813][INFO    ][8747] Executing state service.running for [maas-regiond]
2019-06-04 21:41:28,674 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-04 21:41:28,713 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-04 21:41:28,731 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-04 21:41:28,749 [salt.state       :300 ][INFO    ][8747] The service maas-regiond is already running
2019-06-04 21:41:28,749 [salt.state       :1951][INFO    ][8747] Completed state [maas-regiond] at time 21:41:28.749568 duration_in_ms=77.114
2019-06-04 21:41:28,751 [salt.state       :1780][INFO    ][8747] Running state [bind9] at time 21:41:28.751836
2019-06-04 21:41:28,752 [salt.state       :1813][INFO    ][8747] Executing state service.running for [bind9]
2019-06-04 21:41:28,753 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-04 21:41:28,771 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-04 21:41:28,788 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-04 21:41:28,805 [salt.state       :300 ][INFO    ][8747] The service bind9 is already running
2019-06-04 21:41:28,805 [salt.state       :1951][INFO    ][8747] Completed state [bind9] at time 21:41:28.805619 duration_in_ms=53.782
2019-06-04 21:41:28,807 [salt.state       :1780][INFO    ][8747] Running state [apache2] at time 21:41:28.807861
2019-06-04 21:41:28,808 [salt.state       :1813][INFO    ][8747] Executing state service.running for [apache2]
2019-06-04 21:41:28,809 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-04 21:41:28,827 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-04 21:41:28,843 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-04 21:41:28,864 [salt.state       :300 ][INFO    ][8747] The service apache2 is already running
2019-06-04 21:41:28,864 [salt.state       :1951][INFO    ][8747] Completed state [apache2] at time 21:41:28.864628 duration_in_ms=56.766
2019-06-04 21:41:28,866 [salt.state       :1780][INFO    ][8747] Running state [maasng.wait_for_http_code] at time 21:41:28.866279
2019-06-04 21:41:28,866 [salt.state       :1813][INFO    ][8747] Executing state module.run for [maasng.wait_for_http_code]
2019-06-04 21:41:28,867 [salt.utils.decorators:613 ][WARNING ][8747] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:41:28,993 [salt.state       :300 ][INFO    ][8747] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-04 21:41:28,994 [salt.state       :1951][INFO    ][8747] Completed state [maasng.wait_for_http_code] at time 21:41:28.994134 duration_in_ms=127.854
2019-06-04 21:41:28,995 [salt.state       :1780][INFO    ][8747] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:41:28.995603
2019-06-04 21:41:28,996 [salt.state       :1813][INFO    ][8747] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-04 21:41:28,996 [salt.state       :300 ][INFO    ][8747] /var/lib/maas/.setup_admin exists
2019-06-04 21:41:28,997 [salt.state       :1951][INFO    ][8747] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:41:28.997257 duration_in_ms=1.654
2019-06-04 21:41:28,998 [salt.state       :1780][INFO    ][8747] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:41:28.998433
2019-06-04 21:41:28,998 [salt.state       :1813][INFO    ][8747] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:41:28,999 [salt.loaded.int.module.cmdmod:395 ][INFO    ][8747] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:41:30,420 [salt.state       :300 ][INFO    ][8747] {'pid': 8806, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:41:30,421 [salt.state       :1951][INFO    ][8747] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:41:30.421239 duration_in_ms=1422.806
2019-06-04 21:41:30,432 [salt.state       :1780][INFO    ][8747] Running state [maas_region_boot_source_resources_mirror] at time 21:41:30.432337
2019-06-04 21:41:30,432 [salt.state       :1813][INFO    ][8747] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-04 21:41:30,543 [salt.state       :300 ][INFO    ][8747] {'changes': {}}
2019-06-04 21:41:30,543 [salt.state       :1951][INFO    ][8747] Completed state [maas_region_boot_source_resources_mirror] at time 21:41:30.543819 duration_in_ms=111.479
2019-06-04 21:41:30,545 [salt.state       :1780][INFO    ][8747] Running state [maasng.boot_resources_import] at time 21:41:30.545117
2019-06-04 21:41:30,545 [salt.state       :1813][INFO    ][8747] Executing state module.run for [maasng.boot_resources_import]
2019-06-04 21:41:30,546 [salt.utils.decorators:613 ][WARNING ][8747] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:41:30,651 [salt.loaded.ext.module.maasng:1600][INFO    ][8747] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-04 21:41:35,699 [salt.loaded.ext.module.maasng:1600][INFO    ][8747] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-04 21:41:39,630 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214139617471
2019-06-04 21:41:39,653 [salt.minion      :1432][INFO    ][8826] Starting a new job with PID 8826
2019-06-04 21:41:39,678 [salt.minion      :1711][INFO    ][8826] Returning information for job: 20190604214139617471
2019-06-04 21:41:40,762 [salt.loaded.ext.module.maasng:1600][INFO    ][8747] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-06-04 21:41:45,828 [salt.loaded.ext.module.maasng:1600][INFO    ][8747] Waiting boot-resources import done
sleep for:5s Left:885.0/900s
2019-06-04 21:41:50,901 [salt.loaded.ext.module.maasng:1600][INFO    ][8747] Waiting boot-resources import done
sleep for:5s Left:880.0/900s
2019-06-04 21:41:55,960 [salt.loaded.ext.module.maasng:1600][INFO    ][8747] Waiting boot-resources import done
sleep for:5s Left:875.0/900s
2019-06-04 21:42:01,020 [salt.loaded.ext.module.maasng:1600][INFO    ][8747] Waiting boot-resources import done
sleep for:5s Left:870.0/900s
2019-06-04 21:42:06,140 [salt.state       :300 ][INFO    ][8747] {'ret': True}
2019-06-04 21:42:06,140 [salt.state       :1951][INFO    ][8747] Completed state [maasng.boot_resources_import] at time 21:42:06.140908 duration_in_ms=35595.79
2019-06-04 21:42:06,141 [salt.state       :1780][INFO    ][8747] Running state [maas_region_boot_sources_selection_xenial] at time 21:42:06.141828
2019-06-04 21:42:06,142 [salt.state       :1813][INFO    ][8747] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-04 21:42:06,307 [salt.state       :300 ][INFO    ][8747] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-04 21:42:06,308 [salt.state       :1951][INFO    ][8747] Completed state [maas_region_boot_sources_selection_xenial] at time 21:42:06.307924 duration_in_ms=166.096
2019-06-04 21:42:06,308 [salt.state       :1780][INFO    ][8747] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:42:06.308884
2019-06-04 21:42:06,309 [salt.state       :1813][INFO    ][8747] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-04 21:42:06,309 [salt.utils.decorators:613 ][WARNING ][8747] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:42:06,310 [salt.loaded.ext.module.maasng:1771][INFO    ][8747] boot-sources sync initiated for ALL Rack's
2019-06-04 21:42:07,295 [salt.state       :300 ][INFO    ][8747] {'ret': True}
2019-06-04 21:42:07,296 [salt.state       :1951][INFO    ][8747] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:42:07.296445 duration_in_ms=987.561
2019-06-04 21:42:07,298 [salt.state       :1780][INFO    ][8747] Running state [maas.process_maas_config] at time 21:42:07.298780
2019-06-04 21:42:07,299 [salt.state       :1813][INFO    ][8747] Executing state module.run for [maas.process_maas_config]
2019-06-04 21:42:07,300 [salt.utils.decorators:613 ][WARNING ][8747] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:42:07,301 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=enable_http_proxy value=True
2019-06-04 21:42:07,351 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=upstream_dns value=8.8.8.8
2019-06-04 21:42:07,404 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=commissioning_distro_series value=xenial
2019-06-04 21:42:07,476 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=default_osystem value=ubuntu
2019-06-04 21:42:09,680 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214209667302
2019-06-04 21:42:09,703 [salt.minion      :1432][INFO    ][9129] Starting a new job with PID 9129
2019-06-04 21:42:09,727 [salt.minion      :1711][INFO    ][9129] Returning information for job: 20190604214209667302
2019-06-04 21:42:22,923 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=active_discovery_interval value=600
2019-06-04 21:42:22,985 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=dnssec_validation value=no
2019-06-04 21:42:23,045 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=maas_name value=mas01
2019-06-04 21:42:23,114 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=network_discovery value=enabled
2019-06-04 21:42:23,232 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=enable_third_party_drivers value=True
2019-06-04 21:42:23,291 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=default_storage_layout value=lvm
2019-06-04 21:42:23,360 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=ntp_external_only value=True
2019-06-04 21:42:23,411 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-04 21:42:23,464 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=default_distro_series value=xenial
2019-06-04 21:42:23,530 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-06-04 21:42:23,668 [salt.state       :300 ][INFO    ][8747] {'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-06-04 21:42:23,669 [salt.state       :1951][INFO    ][8747] Completed state [maas.process_maas_config] at time 21:42:23.669229 duration_in_ms=16370.449
2019-06-04 21:42:23,669 [salt.state       :1780][INFO    ][8747] Running state [pxe_admin] at time 21:42:23.669917
2019-06-04 21:42:23,670 [salt.state       :1813][INFO    ][8747] Executing state maasng.fabric_present for [pxe_admin]
2019-06-04 21:42:23,746 [salt.loaded.ext.module.maasng:945 ][INFO    ][8747] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 21:42:23,806 [salt.loaded.ext.module.maasng:1008][WARNING ][8747] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-04 21:42:23,807 [salt.loaded.ext.module.maasng:1011][WARNING ][8747] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-04 21:42:23,866 [salt.state       :300 ][INFO    ][8747] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-04 21:42:23,867 [salt.state       :1951][INFO    ][8747] Completed state [pxe_admin] at time 21:42:23.866916 duration_in_ms=196.998
2019-06-04 21:42:23,867 [salt.state       :1780][INFO    ][8747] Running state [vlan 0] at time 21:42:23.867337
2019-06-04 21:42:23,867 [salt.state       :1813][INFO    ][8747] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-04 21:42:23,925 [salt.loaded.ext.module.maasng:945 ][INFO    ][8747] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, 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'pkhtcs', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-06-04 21:42:24,039 [salt.loaded.ext.module.maasng:945 ][INFO    ][8747] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 21:42:24,333 [salt.loaded.ext.module.maasng:945 ][INFO    ][8747] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-04 21:42:24,470 [salt.state       :300 ][INFO    ][8747] {'new': 'Vlan untagged was updated'}
2019-06-04 21:42:24,470 [salt.state       :1951][INFO    ][8747] Completed state [vlan 0] at time 21:42:24.470544 duration_in_ms=603.206
2019-06-04 21:42:24,471 [salt.state       :1780][INFO    ][8747] Running state [192.168.11.0/24] at time 21:42:24.471797
2019-06-04 21:42:24,472 [salt.state       :1813][INFO    ][8747] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-04 21:42:24,668 [salt.loaded.ext.module.maasng:945 ][INFO    ][8747] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-04 21:42:24,669 [salt.loaded.ext.module.maasng:1235][WARNING ][8747] Ignoring parameter vlan:0
2019-06-04 21:42:24,750 [salt.state       :300 ][INFO    ][8747] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-04 21:42:24,750 [salt.state       :1951][INFO    ][8747] Completed state [192.168.11.0/24] at time 21:42:24.750717 duration_in_ms=278.918
2019-06-04 21:42:24,751 [salt.state       :1780][INFO    ][8747] Running state [maas_create_iprange_1] at time 21:42:24.751908
2019-06-04 21:42:24,752 [salt.state       :1813][INFO    ][8747] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-04 21:42:24,800 [salt.state       :300 ][INFO    ][8747] Iprange maas_create_iprange_1 already exist.
2019-06-04 21:42:24,800 [salt.state       :1951][INFO    ][8747] Completed state [maas_create_iprange_1] at time 21:42:24.800757 duration_in_ms=48.849
2019-06-04 21:42:24,801 [salt.state       :1780][INFO    ][8747] Running state [vlan 0] at time 21:42:24.801201
2019-06-04 21:42:24,801 [salt.state       :1813][INFO    ][8747] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-04 21:42:24,866 [salt.loaded.ext.module.maasng:945 ][INFO    ][8747] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'pkhtcs', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-06-04 21:42:24,968 [salt.loaded.ext.module.maasng:945 ][INFO    ][8747] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin'}]
2019-06-04 21:42:25,196 [salt.loaded.ext.module.maasng:945 ][INFO    ][8747] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'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'class_type': None, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'pkhtcs', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': u'', u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 21:42:25,305 [salt.state       :300 ][INFO    ][8747] {'new': 'Vlan untagged was updated'}
2019-06-04 21:42:25,305 [salt.state       :1951][INFO    ][8747] Completed state [vlan 0] at time 21:42:25.305560 duration_in_ms=504.357
2019-06-04 21:42:25,306 [salt.state       :1780][INFO    ][8747] Running state [opnfv] at time 21:42:25.306747
2019-06-04 21:42:25,307 [salt.state       :1813][INFO    ][8747] Executing state maasng.sshkey_present for [opnfv]
2019-06-04 21:42:25,519 [salt.loaded.ext.module.maasng:1903][INFO    ][8747] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-06-04 21:42:25,520 [salt.state       :300 ][INFO    ][8747] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-04 21:42:25,520 [salt.state       :1951][INFO    ][8747] Completed state [opnfv] at time 21:42:25.520698 duration_in_ms=213.951
2019-06-04 21:42:25,521 [salt.state       :1780][INFO    ][8747] Running state [maas.process_tags] at time 21:42:25.521624
2019-06-04 21:42:25,522 [salt.state       :1813][INFO    ][8747] Executing state module.run for [maas.process_tags]
2019-06-04 21:42:25,522 [salt.utils.decorators:613 ][WARNING ][8747] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:42:25,573 [salt.loaded.ext.module.maas:92  ][INFO    ][8747] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-06-04 21:42:25,633 [salt.state       :300 ][INFO    ][8747] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-06-04 21:42:25,634 [salt.state       :1951][INFO    ][8747] Completed state [maas.process_tags] at time 21:42:25.634100 duration_in_ms=112.476
2019-06-04 21:42:25,637 [salt.minion      :1711][INFO    ][8747] Returning information for job: 20190604214124498138
2019-06-04 21:42:26,215 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604214226203021
2019-06-04 21:42:26,233 [salt.minion      :1432][INFO    ][9253] Starting a new job with PID 9253
2019-06-04 21:42:29,936 [salt.state       :915 ][INFO    ][9253] Loading fresh modules for state activity
2019-06-04 21:42:30,024 [salt.state       :1780][INFO    ][9253] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:42:30.024371
2019-06-04 21:42:30,024 [salt.state       :1813][INFO    ][9253] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:42:30,026 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9253] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:42:31,427 [salt.state       :300 ][INFO    ][9253] {'pid': 9278, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:42:31,428 [salt.state       :1951][INFO    ][9253] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:42:31.428272 duration_in_ms=1403.903
2019-06-04 21:42:31,429 [salt.state       :1780][INFO    ][9253] Running state [maas.process_machines] at time 21:42:31.429452
2019-06-04 21:42:31,429 [salt.state       :1813][INFO    ][9253] Executing state module.run for [maas.process_machines]
2019-06-04 21:42:31,430 [salt.utils.decorators:613 ][WARNING ][9253] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:42:32,010 [salt.loaded.ext.module.maas:412 ][WARNING ][9253] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:42:32,011 [salt.loaded.ext.module.maas:92  ][INFO    ][9253] machine hostname=gtw01 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=k6bxmb architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 21:42:33,257 [salt.loaded.ext.module.maas:412 ][WARNING ][9253] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:42:33,258 [salt.loaded.ext.module.maas:92  ][INFO    ][9253] 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=hrpkk6 architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 21:42:34,652 [salt.loaded.ext.module.maas:412 ][WARNING ][9253] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:42:34,653 [salt.loaded.ext.module.maas:92  ][INFO    ][9253] machine hostname=odl01 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=ex3tyw architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 21:42:35,958 [salt.loaded.ext.module.maas:412 ][WARNING ][9253] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:42:35,958 [salt.loaded.ext.module.maas:92  ][INFO    ][9253] 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=bwrbyw architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 21:42:37,227 [salt.loaded.ext.module.maas:412 ][WARNING ][9253] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 21:42:37,228 [salt.loaded.ext.module.maas:92  ][INFO    ][9253] machine hostname=ctl01 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=bxg4be architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 21:42:38,455 [salt.state       :300 ][INFO    ][9253] {'ret': {'updated': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-06-04 21:42:38,455 [salt.state       :1951][INFO    ][9253] Completed state [maas.process_machines] at time 21:42:38.455800 duration_in_ms=7026.345
2019-06-04 21:42:38,458 [salt.minion      :1711][INFO    ][9253] Returning information for job: 20190604214226203021
2019-06-04 21:43:11,762 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604214311752917
2019-06-04 21:43:11,785 [salt.minion      :1432][INFO    ][9509] Starting a new job with PID 9509
2019-06-04 21:43:15,412 [salt.state       :915 ][INFO    ][9509] Loading fresh modules for state activity
2019-06-04 21:43:15,496 [salt.state       :1780][INFO    ][9509] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:43:15.496674
2019-06-04 21:43:15,497 [salt.state       :1813][INFO    ][9509] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:43:15,499 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9509] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:43:16,926 [salt.state       :300 ][INFO    ][9509] {'pid': 9516, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:43:16,926 [salt.state       :1951][INFO    ][9509] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:43:16.926523 duration_in_ms=1429.85
2019-06-04 21:43:16,927 [salt.state       :1780][INFO    ][9509] Running state [maas.wait_for_machine_status] at time 21:43:16.927950
2019-06-04 21:43:16,928 [salt.state       :1813][INFO    ][9509] Executing state module.run for [maas.wait_for_machine_status]
2019-06-04 21:43:16,928 [salt.utils.decorators:613 ][WARNING ][9509] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:43:17,696 [salt.loaded.ext.module.maas:993 ][INFO    ][9509] Machine k6bxmb mark broken
2019-06-04 21:43:18,169 [salt.loaded.ext.module.maas:996 ][INFO    ][9509] Machine k6bxmb mark fixed
2019-06-04 21:43:19,317 [salt.loaded.ext.module.maas:684 ][INFO    ][9509] deploymachines hwe_kernel=hwe-16.04 system_id=k6bxmb distro_series=xenial
2019-06-04 21:43:24,826 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1492.10611606s left)
2019-06-04 21:43:26,815 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214326801640
2019-06-04 21:43:26,839 [salt.minion      :1432][INFO    ][9632] Starting a new job with PID 9632
2019-06-04 21:43:26,862 [salt.minion      :1711][INFO    ][9632] Returning information for job: 20190604214326801640
2019-06-04 21:43:56,863 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214356855094
2019-06-04 21:43:56,884 [salt.minion      :1432][INFO    ][9664] Starting a new job with PID 9664
2019-06-04 21:43:56,911 [salt.minion      :1711][INFO    ][9664] Returning information for job: 20190604214356855094
2019-06-04 21:43:58,069 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1458.86354899s left)
2019-06-04 21:44:26,987 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214426927416
2019-06-04 21:44:27,008 [salt.minion      :1432][INFO    ][9717] Starting a new job with PID 9717
2019-06-04 21:44:27,033 [salt.minion      :1711][INFO    ][9717] Returning information for job: 20190604214426927416
2019-06-04 21:44:31,525 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1425.40732598s left)
2019-06-04 21:44:57,033 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214457020413
2019-06-04 21:44:57,055 [salt.minion      :1432][INFO    ][9739] Starting a new job with PID 9739
2019-06-04 21:44:57,081 [salt.minion      :1711][INFO    ][9739] Returning information for job: 20190604214457020413
2019-06-04 21:45:04,688 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1392.24479389s left)
2019-06-04 21:45:27,086 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214527073335
2019-06-04 21:45:27,108 [salt.minion      :1432][INFO    ][9901] Starting a new job with PID 9901
2019-06-04 21:45:27,134 [salt.minion      :1711][INFO    ][9901] Returning information for job: 20190604214527073335
2019-06-04 21:45:38,209 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1358.72350192s left)
2019-06-04 21:45:57,143 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214557130571
2019-06-04 21:45:57,166 [salt.minion      :1432][INFO    ][9930] Starting a new job with PID 9930
2019-06-04 21:45:57,194 [salt.minion      :1711][INFO    ][9930] Returning information for job: 20190604214557130571
2019-06-04 21:46:11,216 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1325.71595192s left)
2019-06-04 21:46:27,204 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214627190580
2019-06-04 21:46:27,226 [salt.minion      :1432][INFO    ][10079] Starting a new job with PID 10079
2019-06-04 21:46:27,250 [salt.minion      :1711][INFO    ][10079] Returning information for job: 20190604214627190580
2019-06-04 21:46:45,008 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1291.92449188s left)
2019-06-04 21:46:57,261 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214657249084
2019-06-04 21:46:57,284 [salt.minion      :1432][INFO    ][10103] Starting a new job with PID 10103
2019-06-04 21:46:57,308 [salt.minion      :1711][INFO    ][10103] Returning information for job: 20190604214657249084
2019-06-04 21:47:18,227 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1258.70546198s left)
2019-06-04 21:47:27,323 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214727310626
2019-06-04 21:47:27,347 [salt.minion      :1432][INFO    ][10177] Starting a new job with PID 10177
2019-06-04 21:47:27,374 [salt.minion      :1711][INFO    ][10177] Returning information for job: 20190604214727310626
2019-06-04 21:47:51,785 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1225.14753795s left)
2019-06-04 21:47:57,397 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214757384906
2019-06-04 21:47:57,421 [salt.minion      :1432][INFO    ][10198] Starting a new job with PID 10198
2019-06-04 21:47:57,447 [salt.minion      :1711][INFO    ][10198] Returning information for job: 20190604214757384906
2019-06-04 21:48:25,066 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1191.86606789s left)
2019-06-04 21:48:27,515 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214827503074
2019-06-04 21:48:27,538 [salt.minion      :1432][INFO    ][10356] Starting a new job with PID 10356
2019-06-04 21:48:27,564 [salt.minion      :1711][INFO    ][10356] Returning information for job: 20190604214827503074
2019-06-04 21:48:57,594 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214857582782
2019-06-04 21:48:57,617 [salt.minion      :1432][INFO    ][10380] Starting a new job with PID 10380
2019-06-04 21:48:57,642 [salt.minion      :1711][INFO    ][10380] Returning information for job: 20190604214857582782
2019-06-04 21:48:58,575 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1158.35753298s left)
2019-06-04 21:49:27,673 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214927660932
2019-06-04 21:49:27,697 [salt.minion      :1432][INFO    ][10503] Starting a new job with PID 10503
2019-06-04 21:49:27,722 [salt.minion      :1711][INFO    ][10503] Returning information for job: 20190604214927660932
2019-06-04 21:49:32,276 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1124.65641809s left)
2019-06-04 21:49:57,761 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604214957749746
2019-06-04 21:49:57,785 [salt.minion      :1432][INFO    ][10525] Starting a new job with PID 10525
2019-06-04 21:49:57,812 [salt.minion      :1711][INFO    ][10525] Returning information for job: 20190604214957749746
2019-06-04 21:50:06,124 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1090.80884004s left)
2019-06-04 21:50:27,861 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604215027848699
2019-06-04 21:50:27,883 [salt.minion      :1432][INFO    ][10583] Starting a new job with PID 10583
2019-06-04 21:50:27,910 [salt.minion      :1711][INFO    ][10583] Returning information for job: 20190604215027848699
2019-06-04 21:50:39,420 [salt.loaded.ext.module.maas:1023][INFO    ][9509] Waiting status:Ready|Deployed for machines:['gtw01']
sleep for:30s Timeout:1500s (1057.512079s left)
2019-06-04 21:50:58,017 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604215058004425
2019-06-04 21:50:58,040 [salt.minion      :1432][INFO    ][10640] Starting a new job with PID 10640
2019-06-04 21:50:58,067 [salt.minion      :1711][INFO    ][10640] Returning information for job: 20190604215058004425
2019-06-04 21:51:13,120 [salt.state       :300 ][INFO    ][9509] {'ret': True}
2019-06-04 21:51:13,120 [salt.state       :1951][INFO    ][9509] Completed state [maas.wait_for_machine_status] at time 21:51:13.120431 duration_in_ms=476192.478
2019-06-04 21:51:13,123 [salt.minion      :1711][INFO    ][9509] Returning information for job: 20190604214311752917
2019-06-04 21:51:13,790 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604215113777149
2019-06-04 21:51:13,811 [salt.minion      :1432][INFO    ][10668] Starting a new job with PID 10668
2019-06-04 21:51:17,480 [salt.state       :915 ][INFO    ][10668] Loading fresh modules for state activity
2019-06-04 21:51:17,623 [salt.state       :1780][INFO    ][10668] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:51:17.623663
2019-06-04 21:51:17,624 [salt.state       :1813][INFO    ][10668] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:51:17,625 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10668] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:51:19,054 [salt.state       :300 ][INFO    ][10668] {'pid': 10675, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:51:19,054 [salt.state       :1951][INFO    ][10668] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:51:19.054917 duration_in_ms=1431.255
2019-06-04 21:51:19,056 [salt.state       :1780][INFO    ][10668] Running state [maas_machines_storage_cmp002_lvm] at time 21:51:19.056283
2019-06-04 21:51:19,056 [salt.state       :1813][INFO    ][10668] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-04 21:51:19,685 [salt.state       :300 ][INFO    ][10668] Machine cmp002 is not in Ready state.
2019-06-04 21:51:19,685 [salt.state       :1951][INFO    ][10668] Completed state [maas_machines_storage_cmp002_lvm] at time 21:51:19.685751 duration_in_ms=629.466
2019-06-04 21:51:19,686 [salt.state       :1780][INFO    ][10668] Running state [maas_machines_storage_cmp001_lvm] at time 21:51:19.686309
2019-06-04 21:51:19,686 [salt.state       :1813][INFO    ][10668] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-04 21:51:20,451 [salt.state       :300 ][INFO    ][10668] Machine cmp001 is not in Ready state.
2019-06-04 21:51:20,451 [salt.state       :1951][INFO    ][10668] Completed state [maas_machines_storage_cmp001_lvm] at time 21:51:20.451592 duration_in_ms=765.283
2019-06-04 21:51:20,455 [salt.minion      :1711][INFO    ][10668] Returning information for job: 20190604215113777149
2019-06-04 21:51:21,054 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604215121040913
2019-06-04 21:51:21,077 [salt.minion      :1432][INFO    ][10700] Starting a new job with PID 10700
2019-06-04 21:51:21,797 [salt.state       :915 ][INFO    ][10700] Loading fresh modules for state activity
2019-06-04 21:51:21,884 [salt.state       :1780][INFO    ][10700] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:51:21.884509
2019-06-04 21:51:21,884 [salt.state       :1813][INFO    ][10700] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:51:21,887 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10700] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:51:23,354 [salt.state       :300 ][INFO    ][10700] {'pid': 10707, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:51:23,355 [salt.state       :1951][INFO    ][10700] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:51:23.355636 duration_in_ms=1471.126
2019-06-04 21:51:23,358 [salt.state       :1780][INFO    ][10700] Running state [maas.deploy_machines] at time 21:51:23.358286
2019-06-04 21:51:23,358 [salt.state       :1813][INFO    ][10700] Executing state module.run for [maas.deploy_machines]
2019-06-04 21:51:23,359 [salt.utils.decorators:613 ][WARNING ][10700] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:51:24,100 [salt.state       :300 ][INFO    ][10700] {'ret': {'updated': ['gtw01', 'cmp002', 'odl01', 'cmp001', 'ctl01'], 'errors': {}, 'success': []}}
2019-06-04 21:51:24,100 [salt.state       :1951][INFO    ][10700] Completed state [maas.deploy_machines] at time 21:51:24.100640 duration_in_ms=742.353
2019-06-04 21:51:24,104 [salt.minion      :1711][INFO    ][10700] Returning information for job: 20190604215121040913
2019-06-04 21:51:24,600 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command state.apply with jid 20190604215124591521
2019-06-04 21:51:24,613 [salt.minion      :1432][INFO    ][10777] Starting a new job with PID 10777
2019-06-04 21:51:25,089 [salt.state       :915 ][INFO    ][10777] Loading fresh modules for state activity
2019-06-04 21:51:25,134 [salt.state       :1780][INFO    ][10777] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:51:25.134060
2019-06-04 21:51:25,134 [salt.state       :1813][INFO    ][10777] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 21:51:25,135 [salt.loaded.int.module.cmdmod:395 ][INFO    ][10777] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 21:51:26,551 [salt.state       :300 ][INFO    ][10777] {'pid': 10865, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 21:51:26,552 [salt.state       :1951][INFO    ][10777] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:51:26.552111 duration_in_ms=1418.051
2019-06-04 21:51:26,554 [salt.state       :1780][INFO    ][10777] Running state [maas.wait_for_machine_status] at time 21:51:26.554720
2019-06-04 21:51:26,555 [salt.state       :1813][INFO    ][10777] Executing state module.run for [maas.wait_for_machine_status]
2019-06-04 21:51:26,555 [salt.utils.decorators:613 ][WARNING ][10777] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 21:51:29,665 [salt.state       :300 ][INFO    ][10777] {'ret': True}
2019-06-04 21:51:29,666 [salt.state       :1951][INFO    ][10777] Completed state [maas.wait_for_machine_status] at time 21:51:29.666357 duration_in_ms=3111.635
2019-06-04 21:51:29,669 [salt.minion      :1711][INFO    ][10777] Returning information for job: 20190604215124591521
2019-06-04 22:19:39,067 [salt.utils.schedule:1377][INFO    ][1661] Running scheduled job: __mine_interval
2019-06-04 22:45:16,182 [salt.minion      :1308][INFO    ][1661] User sudo_ubuntu Executing command cp.push_dir with jid 20190604224516170310
2019-06-04 22:45:16,206 [salt.minion      :1432][INFO    ][14919] Starting a new job with PID 14919
