2019-08-07 20:06:36,448 [salt.utils.decorators:613 ][WARNING ][2395] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:06:37,413 [salt.utils.decorators:613 ][WARNING ][2395] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:06:41,059 [salt.loaded.int.states.file:2298][WARNING ][2599] 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-08-07 20:07:03,340 [salt.state       :2022][WARNING ][2821] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-08-07 20:07:06,617 [salt.utils.decorators:613 ][WARNING ][2821] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:22:19,536 [salt.utils.decorators:613 ][WARNING ][2821] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:37:40,024 [salt.utils.decorators:613 ][WARNING ][2821] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:52:41,204 [salt.utils.decorators:613 ][WARNING ][2821] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:52:42,642 [salt.loaded.ext.module.maas:160 ][ERROR   ][2821] Failed for object commissioning_distro_series reason {"commissioning_distro_series": ["'xenial' is not a valid commissioning_distro_series.  It should be one of: '---'."]}
2019-08-07 20:52:42,687 [salt.loaded.ext.module.maas:160 ][ERROR   ][2821] Failed for object default_osystem reason {"default_osystem": ["'ubuntu' is not a valid osystem.  It should be one of: '---'."]}
2019-08-07 20:52:43,194 [salt.loaded.ext.module.maas:160 ][ERROR   ][2821] Failed for object default_distro_series reason {"default_distro_series": ["'xenial' is not a valid release.  It should be one of: '---'."]}
2019-08-07 20:52:43,465 [salt.state       :302 ][ERROR   ][2821] Module function maas.process_maas_config threw an exception. Exception: {'updated': [], 'errors': {'commissioning_distro_series': '{"commissioning_distro_series": ["\'xenial\' is not a valid commissioning_distro_series.  It should be one of: \'---\'."]}', 'default_osystem': '{"default_osystem": ["\'ubuntu\' is not a valid osystem.  It should be one of: \'---\'."]}', 'default_distro_series': '{"default_distro_series": ["\'xenial\' is not a valid release.  It should be one of: \'---\'."]}'}, 'success': ['enable_http_proxy', 'upstream_dns', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_min_hwe_kernel']}
2019-08-07 20:52:43,595 [salt.loaded.ext.module.maasng:1008][WARNING ][2821] Detected cidr:192.168.11.0/24 in fabric:fabric-1
2019-08-07 20:52:43,595 [salt.loaded.ext.module.maasng:1011][WARNING ][2821] Guessing, that fabric with current name:fabric-1
 should be renamed to:pxe_admin
2019-08-07 20:52:44,341 [salt.loaded.ext.module.maasng:1235][WARNING ][2821] Ignoring parameter vlan:0
2019-08-07 20:52:45,228 [salt.utils.decorators:613 ][WARNING ][2821] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:52:48,918 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62435] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-08-07 20:52:48,963 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62435] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-08-07 20:52:49,080 [salt.utils.parsers:1051][WARNING ][388] Minion received a SIGTERM. Exiting.
2019-08-07 20:52:50,825 [salt.cli.daemons :293 ][INFO    ][62520] Setting up the Salt Minion "mas01.mcp-fdio-noha.local"
2019-08-07 20:52:51,015 [salt.cli.daemons :82  ][INFO    ][62520] Starting up the Salt Minion
2019-08-07 20:52:51,016 [salt.utils.event :1017][INFO    ][62520] Starting pull socket on /var/run/salt/minion/minion_event_38d774b16c_pull.ipc
2019-08-07 20:52:52,403 [salt.minion      :976 ][INFO    ][62520] Creating minion process manager
2019-08-07 20:52:54,555 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][62520] Executing command ['date', '+%z'] in directory '/root'
2019-08-07 20:52:54,588 [salt.utils.schedule:568 ][INFO    ][62520] Updating job settings for scheduled job: __mine_interval
2019-08-07 20:52:54,591 [salt.minion      :1108][INFO    ][62520] Added mine.update to scheduler
2019-08-07 20:52:54,596 [salt.minion      :1975][INFO    ][62520] Minion is starting as user 'root'
2019-08-07 20:52:54,618 [salt.minion      :2336][INFO    ][62520] Minion is ready to receive requests!
2019-08-07 20:52:56,528 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command state.apply with jid 20190807205256516013
2019-08-07 20:52:56,552 [salt.minion      :1432][INFO    ][62601] Starting a new job with PID 62601
2019-08-07 20:53:05,538 [salt.state       :915 ][INFO    ][62601] Loading fresh modules for state activity
2019-08-07 20:53:07,100 [salt.state       :1780][INFO    ][62601] Running state [maas-region-controller] at time 20:53:07.099946
2019-08-07 20:53:07,100 [salt.state       :1813][INFO    ][62601] Executing state pkg.installed for [maas-region-controller]
2019-08-07 20:53:07,101 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-08-07 20:53:07,246 [salt.state       :300 ][INFO    ][62601] All specified packages are already installed
2019-08-07 20:53:07,246 [salt.state       :1951][INFO    ][62601] Completed state [maas-region-controller] at time 20:53:07.246797 duration_in_ms=146.852
2019-08-07 20:53:07,247 [salt.state       :1780][INFO    ][62601] Running state [python-oauth] at time 20:53:07.247157
2019-08-07 20:53:07,247 [salt.state       :1813][INFO    ][62601] Executing state pkg.installed for [python-oauth]
2019-08-07 20:53:07,258 [salt.state       :300 ][INFO    ][62601] All specified packages are already installed
2019-08-07 20:53:07,259 [salt.state       :1951][INFO    ][62601] Completed state [python-oauth] at time 20:53:07.259090 duration_in_ms=11.933
2019-08-07 20:53:07,264 [salt.state       :1780][INFO    ][62601] Running state [/etc/maas/regiond.conf] at time 20:53:07.264267
2019-08-07 20:53:07,264 [salt.state       :1813][INFO    ][62601] Executing state file.replace for [/etc/maas/regiond.conf]
2019-08-07 20:53:07,269 [salt.state       :300 ][INFO    ][62601] No changes needed to be made
2019-08-07 20:53:07,270 [salt.state       :1951][INFO    ][62601] Completed state [/etc/maas/regiond.conf] at time 20:53:07.270136 duration_in_ms=5.869
2019-08-07 20:53:07,270 [salt.state       :1780][INFO    ][62601] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:53:07.270675
2019-08-07 20:53:07,271 [salt.state       :1813][INFO    ][62601] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-08-07 20:53:07,348 [salt.state       :300 ][INFO    ][62601] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-08-07 20:53:07,349 [salt.state       :1951][INFO    ][62601] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:53:07.349168 duration_in_ms=78.491
2019-08-07 20:53:07,350 [salt.state       :1780][INFO    ][62601] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:53:07.350693
2019-08-07 20:53:07,351 [salt.state       :1813][INFO    ][62601] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-08-07 20:53:07,361 [salt.state       :300 ][INFO    ][62601] No changes needed to be made
2019-08-07 20:53:07,362 [salt.state       :1951][INFO    ][62601] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:53:07.362299 duration_in_ms=11.606
2019-08-07 20:53:07,363 [salt.state       :1780][INFO    ][62601] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:53:07.363257
2019-08-07 20:53:07,363 [salt.state       :1813][INFO    ][62601] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-08-07 20:53:07,371 [salt.state       :300 ][INFO    ][62601] No changes needed to be made
2019-08-07 20:53:07,372 [salt.state       :1951][INFO    ][62601] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:53:07.372192 duration_in_ms=8.936
2019-08-07 20:53:07,372 [salt.state       :1780][INFO    ][62601] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:53:07.372735
2019-08-07 20:53:07,373 [salt.state       :1813][INFO    ][62601] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-08-07 20:53:07,408 [salt.state       :300 ][INFO    ][62601] No changes needed to be made
2019-08-07 20:53:07,408 [salt.state       :1951][INFO    ][62601] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:53:07.408892 duration_in_ms=36.157
2019-08-07 20:53:07,409 [salt.state       :1780][INFO    ][62601] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:53:07.409456
2019-08-07 20:53:07,409 [salt.state       :1813][INFO    ][62601] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-08-07 20:53:07,423 [salt.state       :300 ][INFO    ][62601] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-08-07 20:53:07,424 [salt.state       :1951][INFO    ][62601] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:53:07.423938 duration_in_ms=14.482
2019-08-07 20:53:07,425 [salt.state       :1780][INFO    ][62601] Running state [a2enmod headers] at time 20:53:07.425830
2019-08-07 20:53:07,426 [salt.state       :1813][INFO    ][62601] Executing state cmd.run for [a2enmod headers]
2019-08-07 20:53:07,426 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command 'a2enmod headers' in directory '/root'
2019-08-07 20:53:07,512 [salt.state       :300 ][INFO    ][62601] {'pid': 62633, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-08-07 20:53:07,513 [salt.state       :1951][INFO    ][62601] Completed state [a2enmod headers] at time 20:53:07.513341 duration_in_ms=87.51
2019-08-07 20:53:07,516 [salt.state       :1780][INFO    ][62601] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:53:07.516876
2019-08-07 20:53:07,517 [salt.state       :1813][INFO    ][62601] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-08-07 20:53:07,548 [salt.state       :300 ][INFO    ][62601] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-08-07 20:53:07,549 [salt.state       :1951][INFO    ][62601] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:53:07.549280 duration_in_ms=32.405
2019-08-07 20:53:07,551 [salt.state       :1780][INFO    ][62601] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:53:07.551565
2019-08-07 20:53:07,552 [salt.state       :1813][INFO    ][62601] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-08-07 20:53:07,616 [salt.state       :300 ][INFO    ][62601] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-08-07 20:53:07,617 [salt.state       :1951][INFO    ][62601] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:53:07.617071 duration_in_ms=65.506
2019-08-07 20:53:07,618 [salt.state       :1780][INFO    ][62601] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:53:07.618334
2019-08-07 20:53:07,618 [salt.state       :1813][INFO    ][62601] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-08-07 20:53:07,691 [salt.state       :300 ][INFO    ][62601] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-08-07 20:53:07,691 [salt.state       :1951][INFO    ][62601] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:53:07.691582 duration_in_ms=73.248
2019-08-07 20:53:07,692 [salt.state       :1780][INFO    ][62601] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:53:07.692453
2019-08-07 20:53:07,692 [salt.state       :1813][INFO    ][62601] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-08-07 20:53:07,779 [salt.state       :300 ][INFO    ][62601] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-08-07 20:53:07,780 [salt.state       :1951][INFO    ][62601] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:53:07.780058 duration_in_ms=87.605
2019-08-07 20:53:07,780 [salt.state       :1780][INFO    ][62601] Running state [/root/.pgpass] at time 20:53:07.780808
2019-08-07 20:53:07,781 [salt.state       :1813][INFO    ][62601] Executing state file.managed for [/root/.pgpass]
2019-08-07 20:53:07,836 [salt.state       :300 ][INFO    ][62601] File /root/.pgpass is in the correct state
2019-08-07 20:53:07,836 [salt.state       :1951][INFO    ][62601] Completed state [/root/.pgpass] at time 20:53:07.836631 duration_in_ms=55.824
2019-08-07 20:53:07,842 [salt.state       :1780][INFO    ][62601] Running state [maas-region syncdb --noinput] at time 20:53:07.842331
2019-08-07 20:53:07,842 [salt.state       :1813][INFO    ][62601] Executing state cmd.run for [maas-region syncdb --noinput]
2019-08-07 20:53:07,843 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-08-07 20:53:10,793 [salt.state       :300 ][INFO    ][62601] {'pid': 62646, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: maasserver, sessions, metadataserver, piston3, sites, contenttypes, auth\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-08-07 20:53:10,794 [salt.state       :1951][INFO    ][62601] Completed state [maas-region syncdb --noinput] at time 20:53:10.794491 duration_in_ms=2952.159
2019-08-07 20:53:10,794 [salt.state       :2022][WARNING ][62601] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-08-07 20:53:10,796 [salt.state       :1780][INFO    ][62601] Running state [maas-regiond] at time 20:53:10.796636
2019-08-07 20:53:10,797 [salt.state       :1813][INFO    ][62601] Executing state service.running for [maas-regiond]
2019-08-07 20:53:10,798 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-08-07 20:53:10,842 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-08-07 20:53:10,858 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-08-07 20:53:10,879 [salt.state       :300 ][INFO    ][62601] The service maas-regiond is already running
2019-08-07 20:53:10,879 [salt.state       :1951][INFO    ][62601] Completed state [maas-regiond] at time 20:53:10.879679 duration_in_ms=83.042
2019-08-07 20:53:10,882 [salt.state       :1780][INFO    ][62601] Running state [bind9] at time 20:53:10.882858
2019-08-07 20:53:10,883 [salt.state       :1813][INFO    ][62601] Executing state service.running for [bind9]
2019-08-07 20:53:10,884 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-08-07 20:53:10,906 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-08-07 20:53:10,927 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-08-07 20:53:10,944 [salt.state       :300 ][INFO    ][62601] The service bind9 is already running
2019-08-07 20:53:10,944 [salt.state       :1951][INFO    ][62601] Completed state [bind9] at time 20:53:10.944463 duration_in_ms=61.605
2019-08-07 20:53:10,949 [salt.state       :1780][INFO    ][62601] Running state [apache2] at time 20:53:10.949413
2019-08-07 20:53:10,949 [salt.state       :1813][INFO    ][62601] Executing state service.running for [apache2]
2019-08-07 20:53:10,951 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-08-07 20:53:10,974 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-08-07 20:53:10,996 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-08-07 20:53:11,025 [salt.state       :300 ][INFO    ][62601] The service apache2 is already running
2019-08-07 20:53:11,026 [salt.state       :1951][INFO    ][62601] Completed state [apache2] at time 20:53:11.026256 duration_in_ms=76.843
2019-08-07 20:53:11,029 [salt.state       :1780][INFO    ][62601] Running state [maasng.wait_for_http_code] at time 20:53:11.028922
2019-08-07 20:53:11,029 [salt.state       :1813][INFO    ][62601] Executing state module.run for [maasng.wait_for_http_code]
2019-08-07 20:53:11,033 [salt.utils.decorators:613 ][WARNING ][62601] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:53:11,039 [salt.state       :300 ][INFO    ][62601] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-08-07 20:53:11,040 [salt.state       :1951][INFO    ][62601] Completed state [maasng.wait_for_http_code] at time 20:53:11.040147 duration_in_ms=11.225
2019-08-07 20:53:11,041 [salt.state       :1780][INFO    ][62601] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:53:11.041049
2019-08-07 20:53:11,041 [salt.state       :1813][INFO    ][62601] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-08-07 20:53:11,045 [salt.state       :300 ][INFO    ][62601] /var/lib/maas/.setup_admin exists
2019-08-07 20:53:11,045 [salt.state       :1951][INFO    ][62601] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:53:11.045721 duration_in_ms=4.672
2019-08-07 20:53:11,046 [salt.state       :1780][INFO    ][62601] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:53:11.046473
2019-08-07 20:53:11,046 [salt.state       :1813][INFO    ][62601] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-07 20:53:11,047 [salt.loaded.int.module.cmdmod:395 ][INFO    ][62601] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-07 20:53:11,623 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205311616182
2019-08-07 20:53:11,640 [salt.minion      :1432][INFO    ][62670] Starting a new job with PID 62670
2019-08-07 20:53:11,673 [salt.minion      :1711][INFO    ][62670] Returning information for job: 20190807205311616182
2019-08-07 20:53:12,919 [salt.state       :300 ][INFO    ][62601] {'pid': 62665, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-07 20:53:12,920 [salt.state       :1951][INFO    ][62601] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:53:12.920350 duration_in_ms=1873.875
2019-08-07 20:53:12,930 [salt.state       :1780][INFO    ][62601] Running state [maas_region_boot_source_resources_mirror] at time 20:53:12.930831
2019-08-07 20:53:12,931 [salt.state       :1813][INFO    ][62601] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-08-07 20:53:13,018 [salt.state       :300 ][INFO    ][62601] {'changes': {}}
2019-08-07 20:53:13,019 [salt.state       :1951][INFO    ][62601] Completed state [maas_region_boot_source_resources_mirror] at time 20:53:13.019271 duration_in_ms=88.439
2019-08-07 20:53:13,020 [salt.state       :1780][INFO    ][62601] Running state [maasng.boot_resources_import] at time 20:53:13.020523
2019-08-07 20:53:13,021 [salt.state       :1813][INFO    ][62601] Executing state module.run for [maasng.boot_resources_import]
2019-08-07 20:53:13,023 [salt.utils.decorators:613 ][WARNING ][62601] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:53:13,099 [salt.loaded.ext.module.maasng:1600][INFO    ][62601] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-08-07 20:53:18,160 [salt.loaded.ext.module.maasng:1600][INFO    ][62601] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-08-07 20:53:23,300 [salt.state       :300 ][INFO    ][62601] {'ret': True}
2019-08-07 20:53:23,300 [salt.state       :1951][INFO    ][62601] Completed state [maasng.boot_resources_import] at time 20:53:23.300687 duration_in_ms=10280.164
2019-08-07 20:53:23,302 [salt.state       :1780][INFO    ][62601] Running state [maas_region_boot_sources_selection_xenial] at time 20:53:23.302452
2019-08-07 20:53:23,302 [salt.state       :1813][INFO    ][62601] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-08-07 20:53:23,573 [salt.state       :300 ][INFO    ][62601] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-08-07 20:53:23,573 [salt.state       :1951][INFO    ][62601] Completed state [maas_region_boot_sources_selection_xenial] at time 20:53:23.573425 duration_in_ms=270.972
2019-08-07 20:53:23,575 [salt.state       :1780][INFO    ][62601] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 20:53:23.575076
2019-08-07 20:53:23,575 [salt.state       :1813][INFO    ][62601] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-08-07 20:53:23,576 [salt.utils.decorators:613 ][WARNING ][62601] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:53:23,577 [salt.loaded.ext.module.maasng:1771][INFO    ][62601] boot-sources sync initiated for ALL Rack's
2019-08-07 20:53:41,725 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205341713641
2019-08-07 20:53:41,749 [salt.minion      :1432][INFO    ][62751] Starting a new job with PID 62751
2019-08-07 20:53:41,788 [salt.minion      :1711][INFO    ][62751] Returning information for job: 20190807205341713641
2019-08-07 20:54:11,896 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205411883266
2019-08-07 20:54:11,922 [salt.minion      :1432][INFO    ][62804] Starting a new job with PID 62804
2019-08-07 20:54:11,947 [salt.minion      :1711][INFO    ][62804] Returning information for job: 20190807205411883266
2019-08-07 20:54:42,032 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205442021287
2019-08-07 20:54:42,058 [salt.minion      :1432][INFO    ][62860] Starting a new job with PID 62860
2019-08-07 20:54:42,088 [salt.minion      :1711][INFO    ][62860] Returning information for job: 20190807205442021287
2019-08-07 20:55:12,148 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205512139181
2019-08-07 20:55:12,166 [salt.minion      :1432][INFO    ][62893] Starting a new job with PID 62893
2019-08-07 20:55:12,317 [salt.minion      :1711][INFO    ][62893] Returning information for job: 20190807205512139181
2019-08-07 20:55:42,223 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205542211147
2019-08-07 20:55:42,248 [salt.minion      :1432][INFO    ][62935] Starting a new job with PID 62935
2019-08-07 20:55:42,286 [salt.minion      :1711][INFO    ][62935] Returning information for job: 20190807205542211147
2019-08-07 20:55:47,349 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:900.0/900s
2019-08-07 20:55:52,591 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:894.0/900s
2019-08-07 20:55:57,814 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:889.0/900s
2019-08-07 20:56:03,026 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:884.0/900s
2019-08-07 20:56:08,260 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:879.0/900s
2019-08-07 20:56:12,344 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205612335295
2019-08-07 20:56:12,376 [salt.minion      :1432][INFO    ][63017] Starting a new job with PID 63017
2019-08-07 20:56:12,404 [salt.minion      :1711][INFO    ][63017] Returning information for job: 20190807205612335295
2019-08-07 20:56:13,504 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:874.0/900s
2019-08-07 20:56:18,717 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:868.0/900s
2019-08-07 20:56:23,950 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:863.0/900s
2019-08-07 20:56:29,159 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:858.0/900s
2019-08-07 20:56:34,387 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:853.0/900s
2019-08-07 20:56:39,627 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:847.0/900s
2019-08-07 20:56:42,441 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205642429349
2019-08-07 20:56:42,467 [salt.minion      :1432][INFO    ][63063] Starting a new job with PID 63063
2019-08-07 20:56:42,499 [salt.minion      :1711][INFO    ][63063] Returning information for job: 20190807205642429349
2019-08-07 20:56:44,857 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:842.0/900s
2019-08-07 20:56:50,077 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:837.0/900s
2019-08-07 20:56:55,273 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:832.0/900s
2019-08-07 20:57:00,498 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:827.0/900s
2019-08-07 20:57:05,717 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:821.0/900s
2019-08-07 20:57:10,935 [salt.loaded.ext.module.maasng:1878][INFO    ][62601] Waiting boot-resources sync done to rack:mas01
sleep for:5s Left:816.0/900s
2019-08-07 20:57:12,534 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205712522911
2019-08-07 20:57:12,557 [salt.minion      :1432][INFO    ][63270] Starting a new job with PID 63270
2019-08-07 20:57:12,594 [salt.minion      :1711][INFO    ][63270] Returning information for job: 20190807205712522911
2019-08-07 20:57:16,707 [salt.state       :300 ][INFO    ][62601] {'ret': True}
2019-08-07 20:57:16,708 [salt.state       :1951][INFO    ][62601] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 20:57:16.708253 duration_in_ms=233133.177
2019-08-07 20:57:16,710 [salt.state       :1780][INFO    ][62601] Running state [maas.process_maas_config] at time 20:57:16.710463
2019-08-07 20:57:16,710 [salt.state       :1813][INFO    ][62601] Executing state module.run for [maas.process_maas_config]
2019-08-07 20:57:16,711 [salt.utils.decorators:613 ][WARNING ][62601] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:57:16,712 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=enable_http_proxy value=True
2019-08-07 20:57:16,768 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=upstream_dns value=8.8.8.8
2019-08-07 20:57:18,332 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=commissioning_distro_series value=xenial
2019-08-07 20:57:18,402 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=default_osystem value=ubuntu
2019-08-07 20:57:18,466 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=active_discovery_interval value=600
2019-08-07 20:57:18,535 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=dnssec_validation value=no
2019-08-07 20:57:18,584 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=maas_name value=mas01
2019-08-07 20:57:18,631 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=network_discovery value=enabled
2019-08-07 20:57:18,735 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=enable_third_party_drivers value=True
2019-08-07 20:57:18,779 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=default_storage_layout value=lvm
2019-08-07 20:57:18,823 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=ntp_external_only value=True
2019-08-07 20:57:18,875 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=disk_erase_with_secure_erase value=False
2019-08-07 20:57:18,927 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=default_distro_series value=xenial
2019-08-07 20:57:18,983 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-08-07 20:57:19,159 [salt.state       :300 ][INFO    ][62601] {'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-08-07 20:57:19,159 [salt.state       :1951][INFO    ][62601] Completed state [maas.process_maas_config] at time 20:57:19.159572 duration_in_ms=2449.108
2019-08-07 20:57:19,160 [salt.state       :1780][INFO    ][62601] Running state [pxe_admin] at time 20:57:19.160457
2019-08-07 20:57:19,160 [salt.state       :1813][INFO    ][62601] Executing state maasng.fabric_present for [pxe_admin]
2019-08-07 20:57:19,220 [salt.loaded.ext.module.maasng:945 ][INFO    ][62601] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 2, u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 1, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-08-07 20:57:19,282 [salt.loaded.ext.module.maasng:1008][WARNING ][62601] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-08-07 20:57:19,283 [salt.loaded.ext.module.maasng:1011][WARNING ][62601] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-08-07 20:57:19,353 [salt.state       :300 ][INFO    ][62601] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-08-07 20:57:19,353 [salt.state       :1951][INFO    ][62601] Completed state [pxe_admin] at time 20:57:19.353413 duration_in_ms=192.956
2019-08-07 20:57:19,354 [salt.state       :1780][INFO    ][62601] Running state [vlan 0] at time 20:57:19.354443
2019-08-07 20:57:19,354 [salt.state       :1813][INFO    ][62601] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-08-07 20:57:19,515 [salt.loaded.ext.module.maasng:945 ][INFO    ][62601] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-08-07 20:57:19,632 [salt.loaded.ext.module.maasng:945 ][INFO    ][62601] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-08-07 20:57:19,866 [salt.loaded.ext.module.maasng:945 ][INFO    ][62601] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': u'6rsbk6', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-08-07 20:57:19,953 [salt.state       :300 ][INFO    ][62601] {'new': 'Vlan untagged was updated'}
2019-08-07 20:57:19,953 [salt.state       :1951][INFO    ][62601] Completed state [vlan 0] at time 20:57:19.953460 duration_in_ms=599.016
2019-08-07 20:57:19,956 [salt.state       :1780][INFO    ][62601] Running state [192.168.11.0/24] at time 20:57:19.956282
2019-08-07 20:57:19,956 [salt.state       :1813][INFO    ][62601] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-08-07 20:57:20,148 [salt.loaded.ext.module.maasng:945 ][INFO    ][62601] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 2, u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 1, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-08-07 20:57:20,152 [salt.loaded.ext.module.maasng:1235][WARNING ][62601] Ignoring parameter vlan:0
2019-08-07 20:57:20,218 [salt.state       :300 ][INFO    ][62601] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-08-07 20:57:20,218 [salt.state       :1951][INFO    ][62601] Completed state [192.168.11.0/24] at time 20:57:20.218597 duration_in_ms=262.314
2019-08-07 20:57:20,219 [salt.state       :1780][INFO    ][62601] Running state [maas_create_iprange_1] at time 20:57:20.219702
2019-08-07 20:57:20,220 [salt.state       :1813][INFO    ][62601] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-08-07 20:57:20,287 [salt.state       :300 ][INFO    ][62601] Iprange maas_create_iprange_1 already exist.
2019-08-07 20:57:20,288 [salt.state       :1951][INFO    ][62601] Completed state [maas_create_iprange_1] at time 20:57:20.288163 duration_in_ms=68.461
2019-08-07 20:57:20,288 [salt.state       :1780][INFO    ][62601] Running state [vlan 0] at time 20:57:20.288508
2019-08-07 20:57:20,288 [salt.state       :1813][INFO    ][62601] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-08-07 20:57:20,341 [salt.loaded.ext.module.maasng:945 ][INFO    ][62601] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-08-07 20:57:20,445 [salt.loaded.ext.module.maasng:945 ][INFO    ][62601] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 2, u'class_type': None, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}, {u'id': 1, u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-08-07 20:57:20,718 [salt.loaded.ext.module.maasng:945 ][INFO    ][62601] [{u'id': 0, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None}, {u'id': 2, u'vlans': [{u'fabric': u'fabric-2', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'fabric-2', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': None}, {u'id': 1, u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': u'6rsbk6', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-08-07 20:57:20,830 [salt.state       :300 ][INFO    ][62601] {'new': 'Vlan untagged was updated'}
2019-08-07 20:57:20,831 [salt.state       :1951][INFO    ][62601] Completed state [vlan 0] at time 20:57:20.831351 duration_in_ms=542.842
2019-08-07 20:57:20,832 [salt.state       :1780][INFO    ][62601] Running state [opnfv] at time 20:57:20.832444
2019-08-07 20:57:20,832 [salt.state       :1813][INFO    ][62601] Executing state maasng.sshkey_present for [opnfv]
2019-08-07 20:57:20,903 [salt.loaded.ext.module.maasng:1903][INFO    ][62601] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-08-07 20:57:20,903 [salt.state       :300 ][INFO    ][62601] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b already exist for user opnfv.
2019-08-07 20:57:20,904 [salt.state       :1951][INFO    ][62601] Completed state [opnfv] at time 20:57:20.903976 duration_in_ms=71.533
2019-08-07 20:57:20,904 [salt.state       :1780][INFO    ][62601] Running state [maas.process_tags] at time 20:57:20.904732
2019-08-07 20:57:20,905 [salt.state       :1813][INFO    ][62601] Executing state module.run for [maas.process_tags]
2019-08-07 20:57:20,905 [salt.utils.decorators:613 ][WARNING ][62601] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:57:20,945 [salt.loaded.ext.module.maas:92  ][INFO    ][62601] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-08-07 20:57:21,016 [salt.state       :300 ][INFO    ][62601] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-08-07 20:57:21,016 [salt.state       :1951][INFO    ][62601] Completed state [maas.process_tags] at time 20:57:21.016473 duration_in_ms=111.74
2019-08-07 20:57:21,020 [salt.minion      :1711][INFO    ][62601] Returning information for job: 20190807205256516013
2019-08-07 20:57:21,848 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command state.apply with jid 20190807205721837279
2019-08-07 20:57:21,872 [salt.minion      :1432][INFO    ][63393] Starting a new job with PID 63393
2019-08-07 20:57:31,001 [salt.state       :915 ][INFO    ][63393] Loading fresh modules for state activity
2019-08-07 20:57:31,074 [salt.fileclient  :1219][INFO    ][63393] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-08-07 20:57:31,134 [salt.state       :1780][INFO    ][63393] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:57:31.134200
2019-08-07 20:57:31,134 [salt.state       :1813][INFO    ][63393] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-07 20:57:31,137 [salt.loaded.int.module.cmdmod:395 ][INFO    ][63393] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-07 20:57:33,213 [salt.state       :300 ][INFO    ][63393] {'pid': 63416, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-07 20:57:33,214 [salt.state       :1951][INFO    ][63393] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:57:33.214591 duration_in_ms=2080.389
2019-08-07 20:57:33,218 [salt.state       :1780][INFO    ][63393] Running state [maas.process_machines] at time 20:57:33.218216
2019-08-07 20:57:33,219 [salt.state       :1813][INFO    ][63393] Executing state module.run for [maas.process_machines]
2019-08-07 20:57:33,219 [salt.utils.decorators:613 ][WARNING ][63393] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:57:33,285 [salt.loaded.ext.module.maas:412 ][WARNING ][63393] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-07 20:57:33,286 [salt.loaded.ext.module.maas:92  ][INFO    ][63393] machine hostname=gtw01 power_type=ipmi mac_addresses=14:58:d0:54:6a:60 power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-07 20:57:34,957 [salt.loaded.ext.module.maas:412 ][WARNING ][63393] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-07 20:57:34,957 [salt.loaded.ext.module.maas:92  ][INFO    ][63393] machine hostname=cmp002 power_type=ipmi mac_addresses=9c:b6:54:8a:10:18 power_parameters_power_address=172.16.1.20 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-07 20:57:36,301 [salt.loaded.ext.module.maas:412 ][WARNING ][63393] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-07 20:57:36,301 [salt.loaded.ext.module.maas:92  ][INFO    ][63393] machine hostname=cmp001 power_type=ipmi mac_addresses=9c:b6:54:8a:95:a0 power_parameters_power_address=172.16.1.19 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-07 20:57:36,874 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205736864214
2019-08-07 20:57:36,896 [salt.minion      :1432][INFO    ][63570] Starting a new job with PID 63570
2019-08-07 20:57:36,929 [salt.minion      :1711][INFO    ][63570] Returning information for job: 20190807205736864214
2019-08-07 20:57:37,511 [salt.loaded.ext.module.maas:412 ][WARNING ][63393] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-08-07 20:57:37,511 [salt.loaded.ext.module.maas:92  ][INFO    ][63393] machine hostname=ctl01 power_type=ipmi mac_addresses=14:58:d0:54:e7:88 power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-08-07 20:57:38,842 [salt.state       :300 ][INFO    ][63393] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'cmp001', 'ctl01']}}
2019-08-07 20:57:38,842 [salt.state       :1951][INFO    ][63393] Completed state [maas.process_machines] at time 20:57:38.842723 duration_in_ms=5624.506
2019-08-07 20:57:38,845 [salt.minion      :1711][INFO    ][63393] Returning information for job: 20190807205721837279
2019-08-07 20:58:10,319 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command state.apply with jid 20190807205810306927
2019-08-07 20:58:10,344 [salt.minion      :1432][INFO    ][63687] Starting a new job with PID 63687
2019-08-07 20:58:18,737 [salt.state       :915 ][INFO    ][63687] Loading fresh modules for state activity
2019-08-07 20:58:18,801 [salt.fileclient  :1219][INFO    ][63687] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-08-07 20:58:18,856 [salt.state       :1780][INFO    ][63687] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:58:18.856640
2019-08-07 20:58:18,857 [salt.state       :1813][INFO    ][63687] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-07 20:58:18,858 [salt.loaded.int.module.cmdmod:395 ][INFO    ][63687] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-07 20:58:20,785 [salt.state       :300 ][INFO    ][63687] {'pid': 63711, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-07 20:58:20,787 [salt.state       :1951][INFO    ][63687] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:58:20.787024 duration_in_ms=1930.383
2019-08-07 20:58:20,791 [salt.state       :1780][INFO    ][63687] Running state [maas.wait_for_machine_status] at time 20:58:20.791719
2019-08-07 20:58:20,792 [salt.state       :1813][INFO    ][63687] Executing state module.run for [maas.wait_for_machine_status]
2019-08-07 20:58:20,794 [salt.utils.decorators:613 ][WARNING ][63687] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 20:58:21,415 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1499.39574599s left)
2019-08-07 20:58:25,385 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205825369322
2019-08-07 20:58:25,415 [salt.minion      :1432][INFO    ][63727] Starting a new job with PID 63727
2019-08-07 20:58:25,444 [salt.minion      :1711][INFO    ][63727] Returning information for job: 20190807205825369322
2019-08-07 20:58:52,028 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1468.78225398s left)
2019-08-07 20:58:55,464 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205855447515
2019-08-07 20:58:55,491 [salt.minion      :1432][INFO    ][63756] Starting a new job with PID 63756
2019-08-07 20:58:55,521 [salt.minion      :1711][INFO    ][63756] Returning information for job: 20190807205855447515
2019-08-07 20:59:22,654 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1438.15653992s left)
2019-08-07 20:59:25,573 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205925558199
2019-08-07 20:59:25,604 [salt.minion      :1432][INFO    ][63801] Starting a new job with PID 63801
2019-08-07 20:59:25,633 [salt.minion      :1711][INFO    ][63801] Returning information for job: 20190807205925558199
2019-08-07 20:59:53,258 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1407.5519731s left)
2019-08-07 20:59:55,661 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807205955647139
2019-08-07 20:59:55,687 [salt.minion      :1432][INFO    ][63829] Starting a new job with PID 63829
2019-08-07 20:59:55,717 [salt.minion      :1711][INFO    ][63829] Returning information for job: 20190807205955647139
2019-08-07 21:00:24,060 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1376.75053s left)
2019-08-07 21:00:25,727 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210025717536
2019-08-07 21:00:25,753 [salt.minion      :1432][INFO    ][63906] Starting a new job with PID 63906
2019-08-07 21:00:25,784 [salt.minion      :1711][INFO    ][63906] Returning information for job: 20190807210025717536
2019-08-07 21:00:54,809 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1346.00092793s left)
2019-08-07 21:00:55,811 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210055799704
2019-08-07 21:00:55,832 [salt.minion      :1432][INFO    ][63991] Starting a new job with PID 63991
2019-08-07 21:00:55,860 [salt.minion      :1711][INFO    ][63991] Returning information for job: 20190807210055799704
2019-08-07 21:01:25,727 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1315.08295798s left)
2019-08-07 21:01:25,928 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210125914446
2019-08-07 21:01:25,955 [salt.minion      :1432][INFO    ][64216] Starting a new job with PID 64216
2019-08-07 21:01:25,981 [salt.minion      :1711][INFO    ][64216] Returning information for job: 20190807210125914446
2019-08-07 21:01:56,025 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210156013324
2019-08-07 21:01:56,048 [salt.minion      :1432][INFO    ][64344] Starting a new job with PID 64344
2019-08-07 21:01:56,080 [salt.minion      :1711][INFO    ][64344] Returning information for job: 20190807210156013324
2019-08-07 21:01:56,701 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1284.10926104s left)
2019-08-07 21:02:26,131 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210226117948
2019-08-07 21:02:26,157 [salt.minion      :1432][INFO    ][64479] Starting a new job with PID 64479
2019-08-07 21:02:26,190 [salt.minion      :1711][INFO    ][64479] Returning information for job: 20190807210226117948
2019-08-07 21:02:28,321 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:1500s (1252.48925209s left)
2019-08-07 21:02:56,292 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210256273671
2019-08-07 21:02:56,324 [salt.minion      :1432][INFO    ][64630] Starting a new job with PID 64630
2019-08-07 21:02:56,354 [salt.minion      :1711][INFO    ][64630] Returning information for job: 20190807210256273671
2019-08-07 21:02:59,900 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:1500s (1220.91074491s left)
2019-08-07 21:03:26,463 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210326447021
2019-08-07 21:03:26,492 [salt.minion      :1432][INFO    ][64982] Starting a new job with PID 64982
2019-08-07 21:03:26,529 [salt.minion      :1711][INFO    ][64982] Returning information for job: 20190807210326447021
2019-08-07 21:03:31,545 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:1500s (1189.26555395s left)
2019-08-07 21:03:56,588 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210356571807
2019-08-07 21:03:56,620 [salt.minion      :1432][INFO    ][65017] Starting a new job with PID 65017
2019-08-07 21:03:56,653 [salt.minion      :1711][INFO    ][65017] Returning information for job: 20190807210356571807
2019-08-07 21:04:03,080 [salt.loaded.ext.module.maas:1023][INFO    ][63687] Waiting status:Ready|Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:1500s (1157.72992611s left)
2019-08-07 21:04:26,753 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210426738689
2019-08-07 21:04:26,788 [salt.minion      :1432][INFO    ][65144] Starting a new job with PID 65144
2019-08-07 21:04:26,819 [salt.minion      :1711][INFO    ][65144] Returning information for job: 20190807210426738689
2019-08-07 21:04:35,036 [salt.state       :300 ][INFO    ][63687] {'ret': True}
2019-08-07 21:04:35,036 [salt.state       :1951][INFO    ][63687] Completed state [maas.wait_for_machine_status] at time 21:04:35.036452 duration_in_ms=374244.733
2019-08-07 21:04:35,040 [salt.minion      :1711][INFO    ][63687] Returning information for job: 20190807205810306927
2019-08-07 21:04:35,780 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command state.apply with jid 20190807210435766446
2019-08-07 21:04:35,805 [salt.minion      :1432][INFO    ][65157] Starting a new job with PID 65157
2019-08-07 21:04:44,239 [salt.state       :915 ][INFO    ][65157] Loading fresh modules for state activity
2019-08-07 21:04:44,308 [salt.fileclient  :1219][INFO    ][65157] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-08-07 21:04:44,416 [salt.state       :1780][INFO    ][65157] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:04:44.416867
2019-08-07 21:04:44,417 [salt.state       :1813][INFO    ][65157] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-07 21:04:44,419 [salt.loaded.int.module.cmdmod:395 ][INFO    ][65157] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-07 21:04:46,374 [salt.state       :300 ][INFO    ][65157] {'pid': 65181, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-07 21:04:46,376 [salt.state       :1951][INFO    ][65157] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:04:46.376123 duration_in_ms=1959.254
2019-08-07 21:04:46,380 [salt.state       :1780][INFO    ][65157] Running state [maas_machines_storage_cmp002_lvm] at time 21:04:46.380805
2019-08-07 21:04:46,381 [salt.state       :1813][INFO    ][65157] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-08-07 21:04:47,346 [salt.loaded.ext.module.maasng:610 ][INFO    ][65157] m4sna6
2019-08-07 21:04:47,347 [salt.loaded.ext.module.maasng:626 ][INFO    ][65157] sda
2019-08-07 21:04:47,823 [salt.loaded.ext.module.maasng:361 ][INFO    ][65157] m4sna6
2019-08-07 21:04:47,917 [salt.loaded.ext.module.maasng:367 ][INFO    ][65157] [{u'model': u'LOGICAL VOLUME', u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'e46e30d1-1bbf-4b10-a952-53b1ce852840', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'm4sna6', u'device_id': 1, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'daa200e6-cd19-48ea-8103-1a6281369397', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/1/partition/1', u'type': u'partition', u'id': 1, u'size': 800101236736}], u'path': u'/dev/disk/by-dname/sda', u'name': u'sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'system_id': u'm4sna6', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 1, u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/1/', u'size': 800109715456}, {u'model': None, u'uuid': u'4fb118ec-fd58-4233-9aa6-75acf1d9fc4c', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 800097042432, u'partitions': [], u'path': u'/dev/disk/by-dname/lvroot', u'name': u'vgroot-lvroot', u'id_path': None, u'system_id': u'm4sna6', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'd2558e53-70c4-4bab-8d3f-003d17d10a2f', u'fstype': u'ext4'}, u'id': 3, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/3/', u'size': 800097042432}]
2019-08-07 21:04:47,919 [salt.loaded.ext.module.maasng:632 ][INFO    ][65157] vgroot
2019-08-07 21:04:47,919 [salt.loaded.ext.module.maasng:635 ][INFO    ][65157] lvroot
2019-08-07 21:04:47,919 [salt.loaded.ext.module.maasng:639 ][INFO    ][65157] 107374182400
2019-08-07 21:04:48,515 [salt.loaded.ext.module.maasng:645 ][INFO    ][65157] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 40, 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'fqdn': u'cmp002.maas', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'model': u'LOGICAL VOLUME', u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/1/', u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'68730642-e889-4e21-b242-44466ca6440d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'm4sna6', u'device_id': 1, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'9dfab548-4038-4b75-a180-1e796f1b56c7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/1/partition/5', u'type': u'partition', u'id': 5, u'size': 800101236736}], u'tags': [u'ssd'], u'name': u'sda', u'system_id': u'm4sna6', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'id': 1, u'size': 800109715456}, u'blockdevice_set': [{u'model': u'LOGICAL VOLUME', u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'68730642-e889-4e21-b242-44466ca6440d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'm4sna6', u'device_id': 1, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'9dfab548-4038-4b75-a180-1e796f1b56c7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/1/partition/5', u'type': u'partition', u'id': 5, u'size': 800101236736}], u'path': u'/dev/disk/by-dname/sda', u'name': u'sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'system_id': u'm4sna6', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 1, u'available_size': 0, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/1/', u'size': 800109715456}, {u'model': None, u'uuid': u'2c97f93b-4a87-4b15-a182-cad86ee2e5d1', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'partitions': [], u'path': u'/dev/disk/by-dname/lvroot', u'name': u'vgroot-lvroot', u'id_path': None, u'system_id': u'm4sna6', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'c917a1d5-4be2-480d-ba5c-3a8af2cc9d38', u'fstype': u'ext4'}, u'id': 9, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/9/', u'size': 107374182400}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'm4sna6', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'owner_data': {}, u'min_hwe_kernel': u'hwe-16.04', u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'model': u'LOGICAL VOLUME', u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/1/', u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'68730642-e889-4e21-b242-44466ca6440d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'm4sna6', u'device_id': 1, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'9dfab548-4038-4b75-a180-1e796f1b56c7', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/1/partition/5', u'type': u'partition', u'id': 5, u'size': 800101236736}], u'tags': [u'ssd'], u'name': u'sda', u'system_id': u'm4sna6', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'block_size': 4096, u'type': u'physical', u'id': 1, u'size': 800109715456}], u'ip_addresses': [u'192.168.11.38', u'192.168.11.40'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'm4sna6', u'id': 5}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'commissioning_status_name': u'Passed', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 18}], u'tags': [u'sriov'], u'mac_address': u'9c:b6:54:8a:10:18', u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38'}], u'system_id': u'm4sna6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/interfaces/5/'}, {u'vlan': None, u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'mac_address': u'38:ea:a7:8f:07:51', u'enabled': True, u'id': 10, u'discovered': None, u'system_id': u'm4sna6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/interfaces/10/'}, {u'vlan': None, u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'mac_address': u'38:ea:a7:8f:07:50', u'enabled': True, u'id': 11, u'discovered': None, u'system_id': u'm4sna6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/interfaces/11/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'ens2f0', u'links': [{u'mode': u'link_up', u'id': 19}], u'tags': [u'sriov'], u'mac_address': u'38:ea:a7:8f:12:48', u'enabled': True, u'id': 13, u'discovered': None, u'system_id': u'm4sna6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/interfaces/13/'}, {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'name': u'eno2', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'mode': u'link_up', u'id': 20}], u'tags': [u'sriov'], u'mac_address': u'9c:b6:54:8a:10:1c', u'enabled': True, u'id': 14, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.40'}], u'system_id': u'm4sna6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/interfaces/14/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'ens2f1', u'links': [{u'mode': u'link_up', u'id': 21}], u'tags': [u'sriov'], u'mac_address': u'38:ea:a7:8f:12:49', u'enabled': True, u'id': 12, u'discovered': None, u'system_id': u'm4sna6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/interfaces/12/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'node_type': 0, u'virtualblockdevice_set': [{u'model': None, u'available_size': 0, u'uuid': u'2c97f93b-4a87-4b15-a182-cad86ee2e5d1', u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/blockdevices/9/', u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'partitions': [], u'tags': [], u'name': u'vgroot-lvroot', u'system_id': u'm4sna6', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'c917a1d5-4be2-480d-ba5c-3a8af2cc9d38', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 9, u'size': 107374182400}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 18}], u'tags': [u'sriov'], u'mac_address': u'9c:b6:54:8a:10:18', u'enabled': True, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.38'}], u'system_id': u'm4sna6', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/m4sna6/interfaces/5/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/m4sna6/'}
2019-08-07 21:04:48,519 [salt.state       :300 ][INFO    ][65157] {'new': {'storage_layout': 'lvm'}}
2019-08-07 21:04:48,519 [salt.state       :1951][INFO    ][65157] Completed state [maas_machines_storage_cmp002_lvm] at time 21:04:48.519787 duration_in_ms=2138.982
2019-08-07 21:04:48,520 [salt.state       :1780][INFO    ][65157] Running state [maas_machines_storage_cmp001_lvm] at time 21:04:48.520195
2019-08-07 21:04:48,520 [salt.state       :1813][INFO    ][65157] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-08-07 21:04:49,644 [salt.loaded.ext.module.maasng:610 ][INFO    ][65157] mkhy6w
2019-08-07 21:04:49,645 [salt.loaded.ext.module.maasng:626 ][INFO    ][65157] sda
2019-08-07 21:04:50,237 [salt.loaded.ext.module.maasng:361 ][INFO    ][65157] mkhy6w
2019-08-07 21:04:50,336 [salt.loaded.ext.module.maasng:367 ][INFO    ][65157] [{u'size': 800109715456, u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'name': u'sda', u'tags': [u'ssd'], u'type': u'physical', u'uuid': None, u'used_for': u'MBR partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'mkhy6w', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/2/', u'used_size': 800106479616, u'id': 2, u'partitions': [{u'size': 800101236736, u'uuid': u'5ea917b8-db0b-4296-8d42-014db893eb1d', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'mkhy6w', u'filesystem': {u'mount_options': None, u'mount_point': None, u'uuid': u'208c52f5-113c-4850-90fb-fffc5e1b0bfa', u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'device_id': 2, u'type': u'partition', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/2/partition/2'}]}, {u'size': 800097042432, u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'uuid': u'5c018b99-b198-45ac-9499-bdb0ad968413', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'mkhy6w', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'mount_point': u'/', u'uuid': u'975a1558-e28c-41af-9a33-d84595efc45b', u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/4/', u'used_size': 800097042432, u'id': 4, u'partitions': []}]
2019-08-07 21:04:50,337 [salt.loaded.ext.module.maasng:632 ][INFO    ][65157] vgroot
2019-08-07 21:04:50,337 [salt.loaded.ext.module.maasng:635 ][INFO    ][65157] lvroot
2019-08-07 21:04:50,337 [salt.loaded.ext.module.maasng:639 ][INFO    ][65157] 107374182400
2019-08-07 21:04:50,872 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210450862431
2019-08-07 21:04:50,891 [salt.minion      :1432][INFO    ][65213] Starting a new job with PID 65213
2019-08-07 21:04:50,924 [salt.minion      :1711][INFO    ][65213] Returning information for job: 20190807210450862431
2019-08-07 21:04:50,938 [salt.loaded.ext.module.maasng:645 ][INFO    ][65157] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'disable_ipv4': False, u'cpu_count': 40, 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'fqdn': u'cmp001.maas', u'status_action': u'', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'model': u'LOGICAL VOLUME', u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/2/', u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'379468e6-d4c1-4ad2-bee1-1e4ee45f685f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'mkhy6w', u'device_id': 2, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'ab73bdb2-0aab-4d0a-b58d-c9b0d11e11bd', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/2/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}], u'tags': [u'ssd'], u'name': u'sda', u'system_id': u'mkhy6w', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'id': 2, u'size': 800109715456}, u'blockdevice_set': [{u'model': u'LOGICAL VOLUME', u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'379468e6-d4c1-4ad2-bee1-1e4ee45f685f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'mkhy6w', u'device_id': 2, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'ab73bdb2-0aab-4d0a-b58d-c9b0d11e11bd', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/2/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}], u'path': u'/dev/disk/by-dname/sda', u'name': u'sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'system_id': u'mkhy6w', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 2, u'available_size': 0, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/2/', u'size': 800109715456}, {u'model': None, u'uuid': u'f8512ec5-5521-4642-871c-313970f1cda2', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'partitions': [], u'path': u'/dev/disk/by-dname/lvroot', u'name': u'vgroot-lvroot', u'id_path': None, u'system_id': u'mkhy6w', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'f74f7a12-b78c-4324-90ac-2da9ca278173', u'fstype': u'ext4'}, u'id': 10, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/10/', u'size': 107374182400}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'mkhy6w', u'raids': [], u'memory': 65536, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': u'192.168.11.3', u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'owner_data': {}, u'min_hwe_kernel': u'hwe-16.04', u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'model': u'LOGICAL VOLUME', u'available_size': 0, u'uuid': None, u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/2/', u'used_for': u'MBR partitioned with 1 partition', u'used_size': 800106479616, u'partitions': [{u'uuid': u'379468e6-d4c1-4ad2-bee1-1e4ee45f685f', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'mkhy6w', u'device_id': 2, u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'ab73bdb2-0aab-4d0a-b58d-c9b0d11e11bd', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/2/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}], u'tags': [u'ssd'], u'name': u'sda', u'system_id': u'mkhy6w', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'path': u'/dev/disk/by-dname/sda', u'serial': u'600508b1001cd7e61f5cd3479576479e', u'block_size': 4096, u'type': u'physical', u'id': 2, u'size': 800109715456}], u'ip_addresses': [u'192.168.11.39', u'192.168.11.43'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'mkhy6w', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 6, u'commissioning_status_name': u'Passed', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 24}], u'tags': [u'sriov'], u'mac_address': u'9c:b6:54:8a:95:a0', u'enabled': True, u'id': 6, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39'}], u'system_id': u'mkhy6w', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/interfaces/6/'}, {u'vlan': None, u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'mac_address': u'38:ea:a7:8f:1f:d4', u'enabled': True, u'id': 16, u'discovered': None, u'system_id': u'mkhy6w', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/interfaces/16/'}, {u'vlan': None, u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'mac_address': u'38:ea:a7:8f:1f:d5', u'enabled': True, u'id': 17, u'discovered': None, u'system_id': u'mkhy6w', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/interfaces/17/'}, {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'name': u'eno2', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'mode': u'link_up', u'id': 25}], u'tags': [u'sriov'], u'mac_address': u'9c:b6:54:8a:95:a4', u'enabled': True, u'id': 15, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.43'}], u'system_id': u'mkhy6w', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/interfaces/15/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'ens2f1', u'links': [{u'mode': u'link_up', u'id': 26}], u'tags': [u'sriov'], u'mac_address': u'38:ea:a7:8f:52:cd', u'enabled': True, u'id': 18, u'discovered': None, u'system_id': u'mkhy6w', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/interfaces/18/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'ens2f0', u'links': [{u'mode': u'link_up', u'id': 27}], u'tags': [u'sriov'], u'mac_address': u'38:ea:a7:8f:52:cc', u'enabled': True, u'id': 19, u'discovered': None, u'system_id': u'mkhy6w', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/interfaces/19/'}], u'current_testing_result_id': 7, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'node_type': 0, u'virtualblockdevice_set': [{u'model': None, u'available_size': 0, u'uuid': u'f8512ec5-5521-4642-871c-313970f1cda2', u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/blockdevices/10/', u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'partitions': [], u'tags': [], u'name': u'vgroot-lvroot', u'system_id': u'mkhy6w', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'f74f7a12-b78c-4324-90ac-2da9ca278173', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 10, u'size': 107374182400}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'name': u'eno1', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 24}], u'tags': [u'sriov'], u'mac_address': u'9c:b6:54:8a:95:a0', u'enabled': True, u'id': 6, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'6rsbk6', u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, 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': 2, u'resource_uri': u'/MAAS/api/2.0/subnets/2/'}, u'ip_address': u'192.168.11.39'}], u'system_id': u'mkhy6w', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/mkhy6w/interfaces/6/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/mkhy6w/'}
2019-08-07 21:04:50,941 [salt.state       :300 ][INFO    ][65157] {'new': {'storage_layout': 'lvm'}}
2019-08-07 21:04:50,944 [salt.state       :1951][INFO    ][65157] Completed state [maas_machines_storage_cmp001_lvm] at time 21:04:50.941637 duration_in_ms=2421.439
2019-08-07 21:04:50,947 [salt.minion      :1711][INFO    ][65157] Returning information for job: 20190807210435766446
2019-08-07 21:04:51,677 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command state.apply with jid 20190807210451666949
2019-08-07 21:04:51,702 [salt.minion      :1432][INFO    ][65220] Starting a new job with PID 65220
2019-08-07 21:04:52,758 [salt.state       :915 ][INFO    ][65220] Loading fresh modules for state activity
2019-08-07 21:04:52,818 [salt.fileclient  :1219][INFO    ][65220] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-08-07 21:04:52,874 [salt.state       :1780][INFO    ][65220] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:04:52.874414
2019-08-07 21:04:52,874 [salt.state       :1813][INFO    ][65220] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-07 21:04:52,876 [salt.loaded.int.module.cmdmod:395 ][INFO    ][65220] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-07 21:04:54,884 [salt.state       :300 ][INFO    ][65220] {'pid': 65227, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-07 21:04:54,885 [salt.state       :1951][INFO    ][65220] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:04:54.885440 duration_in_ms=2011.024
2019-08-07 21:04:54,889 [salt.state       :1780][INFO    ][65220] Running state [maas.deploy_machines] at time 21:04:54.888931
2019-08-07 21:04:54,889 [salt.state       :1813][INFO    ][65220] Executing state module.run for [maas.deploy_machines]
2019-08-07 21:04:54,891 [salt.utils.decorators:613 ][WARNING ][65220] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 21:04:55,398 [salt.loaded.ext.module.maas:684 ][INFO    ][65220] deploymachines hwe_kernel=hwe-16.04 system_id=xbm4e6 distro_series=xenial
2019-08-07 21:04:57,876 [salt.loaded.ext.module.maas:684 ][INFO    ][65220] deploymachines hwe_kernel=hwe-16.04 system_id=m4sna6 distro_series=xenial
2019-08-07 21:05:00,333 [salt.loaded.ext.module.maas:684 ][INFO    ][65220] deploymachines hwe_kernel=hwe-16.04 system_id=mkhy6w distro_series=xenial
2019-08-07 21:05:02,795 [salt.loaded.ext.module.maas:684 ][INFO    ][65220] deploymachines hwe_kernel=hwe-16.04 system_id=8rxpxq distro_series=xenial
2019-08-07 21:05:05,345 [salt.state       :300 ][INFO    ][65220] {'ret': {'updated': [], 'errors': {}, 'success': ['gtw01', 'cmp002', 'cmp001', 'ctl01']}}
2019-08-07 21:05:05,346 [salt.state       :1951][INFO    ][65220] Completed state [maas.deploy_machines] at time 21:05:05.346157 duration_in_ms=10457.225
2019-08-07 21:05:05,349 [salt.minion      :1711][INFO    ][65220] Returning information for job: 20190807210451666949
2019-08-07 21:05:06,084 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command state.apply with jid 20190807210506071286
2019-08-07 21:05:06,107 [salt.minion      :1432][INFO    ][65445] Starting a new job with PID 65445
2019-08-07 21:05:14,537 [salt.state       :915 ][INFO    ][65445] Loading fresh modules for state activity
2019-08-07 21:05:14,604 [salt.fileclient  :1219][INFO    ][65445] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-08-07 21:05:14,655 [salt.state       :1780][INFO    ][65445] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:14.655526
2019-08-07 21:05:14,655 [salt.state       :1813][INFO    ][65445] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-08-07 21:05:14,658 [salt.loaded.int.module.cmdmod:395 ][INFO    ][65445] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-08-07 21:05:16,698 [salt.state       :300 ][INFO    ][65445] {'pid': 65474, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-08-07 21:05:16,699 [salt.state       :1951][INFO    ][65445] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:05:16.699283 duration_in_ms=2043.758
2019-08-07 21:05:16,701 [salt.state       :1780][INFO    ][65445] Running state [maas.wait_for_machine_status] at time 21:05:16.700990
2019-08-07 21:05:16,701 [salt.state       :1813][INFO    ][65445] Executing state module.run for [maas.wait_for_machine_status]
2019-08-07 21:05:16,702 [salt.utils.decorators:613 ][WARNING ][65445] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-08-07 21:05:18,607 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2248.10845995s left)
2019-08-07 21:05:21,180 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210521169180
2019-08-07 21:05:21,201 [salt.minion      :1432][INFO    ][65508] Starting a new job with PID 65508
2019-08-07 21:05:21,229 [salt.minion      :1711][INFO    ][65508] Returning information for job: 20190807210521169180
2019-08-07 21:05:50,647 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2216.06841588s left)
2019-08-07 21:05:51,271 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210551256440
2019-08-07 21:05:51,300 [salt.minion      :1432][INFO    ][65535] Starting a new job with PID 65535
2019-08-07 21:05:51,330 [salt.minion      :1711][INFO    ][65535] Returning information for job: 20190807210551256440
2019-08-07 21:06:21,379 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210621365415
2019-08-07 21:06:21,404 [salt.minion      :1432][INFO    ][344] Starting a new job with PID 344
2019-08-07 21:06:21,440 [salt.minion      :1711][INFO    ][344] Returning information for job: 20190807210621365415
2019-08-07 21:06:22,587 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2184.12800598s left)
2019-08-07 21:06:51,476 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210651462810
2019-08-07 21:06:51,502 [salt.minion      :1432][INFO    ][377] Starting a new job with PID 377
2019-08-07 21:06:51,529 [salt.minion      :1711][INFO    ][377] Returning information for job: 20190807210651462810
2019-08-07 21:06:54,528 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2152.18685389s left)
2019-08-07 21:07:21,569 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210721555107
2019-08-07 21:07:21,598 [salt.minion      :1432][INFO    ][456] Starting a new job with PID 456
2019-08-07 21:07:21,627 [salt.minion      :1711][INFO    ][456] Returning information for job: 20190807210721555107
2019-08-07 21:07:26,596 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2120.11954904s left)
2019-08-07 21:07:51,637 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210751623323
2019-08-07 21:07:51,660 [salt.minion      :1432][INFO    ][633] Starting a new job with PID 633
2019-08-07 21:07:51,695 [salt.minion      :1711][INFO    ][633] Returning information for job: 20190807210751623323
2019-08-07 21:07:58,736 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2087.97892499s left)
2019-08-07 21:08:21,751 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210821737958
2019-08-07 21:08:21,781 [salt.minion      :1432][INFO    ][794] Starting a new job with PID 794
2019-08-07 21:08:21,813 [salt.minion      :1711][INFO    ][794] Returning information for job: 20190807210821737958
2019-08-07 21:08:30,823 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2055.89194298s left)
2019-08-07 21:08:51,859 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210851844335
2019-08-07 21:08:51,887 [salt.minion      :1432][INFO    ][857] Starting a new job with PID 857
2019-08-07 21:08:51,922 [salt.minion      :1711][INFO    ][857] Returning information for job: 20190807210851844335
2019-08-07 21:09:02,933 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (2023.78237796s left)
2019-08-07 21:09:22,008 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210921998738
2019-08-07 21:09:22,029 [salt.minion      :1432][INFO    ][1179] Starting a new job with PID 1179
2019-08-07 21:09:22,064 [salt.minion      :1711][INFO    ][1179] Returning information for job: 20190807210921998738
2019-08-07 21:09:34,971 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1991.74432898s left)
2019-08-07 21:09:52,105 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807210952089145
2019-08-07 21:09:52,138 [salt.minion      :1432][INFO    ][1267] Starting a new job with PID 1267
2019-08-07 21:09:52,171 [salt.minion      :1711][INFO    ][1267] Returning information for job: 20190807210952089145
2019-08-07 21:10:07,353 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1959.36224294s left)
2019-08-07 21:10:22,283 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211022265729
2019-08-07 21:10:22,306 [salt.minion      :1432][INFO    ][1489] Starting a new job with PID 1489
2019-08-07 21:10:22,341 [salt.minion      :1711][INFO    ][1489] Returning information for job: 20190807211022265729
2019-08-07 21:10:39,456 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1927.25880194s left)
2019-08-07 21:10:52,415 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211052399777
2019-08-07 21:10:52,441 [salt.minion      :1432][INFO    ][1523] Starting a new job with PID 1523
2019-08-07 21:10:52,471 [salt.minion      :1711][INFO    ][1523] Returning information for job: 20190807211052399777
2019-08-07 21:11:11,896 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1894.81911993s left)
2019-08-07 21:11:22,645 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211122629710
2019-08-07 21:11:22,678 [salt.minion      :1432][INFO    ][1944] Starting a new job with PID 1944
2019-08-07 21:11:22,711 [salt.minion      :1711][INFO    ][1944] Returning information for job: 20190807211122629710
2019-08-07 21:11:43,870 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1862.84497499s left)
2019-08-07 21:11:52,792 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211152779009
2019-08-07 21:11:52,817 [salt.minion      :1432][INFO    ][1988] Starting a new job with PID 1988
2019-08-07 21:11:52,843 [salt.minion      :1711][INFO    ][1988] Returning information for job: 20190807211152779009
2019-08-07 21:12:16,417 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1830.298105s left)
2019-08-07 21:12:22,931 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211222917692
2019-08-07 21:12:22,962 [salt.minion      :1432][INFO    ][2195] Starting a new job with PID 2195
2019-08-07 21:12:22,992 [salt.minion      :1711][INFO    ][2195] Returning information for job: 20190807211222917692
2019-08-07 21:12:48,607 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1798.10820889s left)
2019-08-07 21:12:53,108 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211253093254
2019-08-07 21:12:53,137 [salt.minion      :1432][INFO    ][2225] Starting a new job with PID 2225
2019-08-07 21:12:53,167 [salt.minion      :1711][INFO    ][2225] Returning information for job: 20190807211253093254
2019-08-07 21:13:20,773 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1765.94260383s left)
2019-08-07 21:13:23,292 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211323278644
2019-08-07 21:13:23,337 [salt.minion      :1432][INFO    ][2535] Starting a new job with PID 2535
2019-08-07 21:13:23,382 [salt.minion      :1711][INFO    ][2535] Returning information for job: 20190807211323278644
2019-08-07 21:13:52,700 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp002', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1734.0150919s left)
2019-08-07 21:13:53,496 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211353483072
2019-08-07 21:13:53,523 [salt.minion      :1432][INFO    ][2563] Starting a new job with PID 2563
2019-08-07 21:13:53,555 [salt.minion      :1711][INFO    ][2563] Returning information for job: 20190807211353483072
2019-08-07 21:14:23,683 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211423670734
2019-08-07 21:14:23,708 [salt.minion      :1432][INFO    ][2698] Starting a new job with PID 2698
2019-08-07 21:14:23,741 [salt.minion      :1711][INFO    ][2698] Returning information for job: 20190807211423670734
2019-08-07 21:14:24,736 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'cmp001', 'ctl01']
sleep for:30s Timeout:2250s (1701.97926998s left)
2019-08-07 21:14:53,716 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211453703515
2019-08-07 21:14:53,744 [salt.minion      :1432][INFO    ][2751] Starting a new job with PID 2751
2019-08-07 21:14:53,772 [salt.minion      :1711][INFO    ][2751] Returning information for job: 20190807211453703515
2019-08-07 21:14:56,769 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1669.94582891s left)
2019-08-07 21:15:23,946 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211523932919
2019-08-07 21:15:23,971 [salt.minion      :1432][INFO    ][3023] Starting a new job with PID 3023
2019-08-07 21:15:24,002 [salt.minion      :1711][INFO    ][3023] Returning information for job: 20190807211523932919
2019-08-07 21:15:28,899 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1637.81630588s left)
2019-08-07 21:15:54,138 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211554124020
2019-08-07 21:15:54,165 [salt.minion      :1432][INFO    ][3053] Starting a new job with PID 3053
2019-08-07 21:15:54,192 [salt.minion      :1711][INFO    ][3053] Returning information for job: 20190807211554124020
2019-08-07 21:16:01,008 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1605.70690203s left)
2019-08-07 21:16:24,324 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211624307673
2019-08-07 21:16:24,355 [salt.minion      :1432][INFO    ][3098] Starting a new job with PID 3098
2019-08-07 21:16:24,384 [salt.minion      :1711][INFO    ][3098] Returning information for job: 20190807211624307673
2019-08-07 21:16:33,071 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1573.64428782s left)
2019-08-07 21:16:54,515 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211654496954
2019-08-07 21:16:54,547 [salt.minion      :1432][INFO    ][3132] Starting a new job with PID 3132
2019-08-07 21:16:54,575 [salt.minion      :1711][INFO    ][3132] Returning information for job: 20190807211654496954
2019-08-07 21:17:05,086 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['gtw01', 'ctl01']
sleep for:30s Timeout:2250s (1541.62941194s left)
2019-08-07 21:17:24,732 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211724722793
2019-08-07 21:17:24,754 [salt.minion      :1432][INFO    ][3229] Starting a new job with PID 3229
2019-08-07 21:17:24,788 [salt.minion      :1711][INFO    ][3229] Returning information for job: 20190807211724722793
2019-08-07 21:17:37,234 [salt.loaded.ext.module.maas:1023][INFO    ][65445] Waiting status:Deployed for machines:['ctl01']
sleep for:30s Timeout:2250s (1509.48126292s left)
2019-08-07 21:17:54,903 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command saltutil.find_job with jid 20190807211754893641
2019-08-07 21:17:54,922 [salt.minion      :1432][INFO    ][3309] Starting a new job with PID 3309
2019-08-07 21:17:54,949 [salt.minion      :1711][INFO    ][3309] Returning information for job: 20190807211754893641
2019-08-07 21:18:09,689 [salt.state       :300 ][INFO    ][65445] {'ret': True}
2019-08-07 21:18:09,690 [salt.state       :1951][INFO    ][65445] Completed state [maas.wait_for_machine_status] at time 21:18:09.690475 duration_in_ms=772989.482
2019-08-07 21:18:09,703 [salt.minion      :1711][INFO    ][65445] Returning information for job: 20190807210506071286
2019-08-07 21:52:55,622 [salt.utils.schedule:1377][INFO    ][62520] Running scheduled job: __mine_interval
2019-08-07 22:12:38,144 [salt.minion      :1308][INFO    ][62520] User sudo_ubuntu Executing command cp.push_dir with jid 20190807221238128572
2019-08-07 22:12:38,168 [salt.minion      :1432][INFO    ][7556] Starting a new job with PID 7556
