2019-05-26 20:09:28,929 [salt.utils.decorators:613 ][WARNING ][2092] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:09:29,953 [salt.utils.decorators:613 ][WARNING ][2092] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:09:33,047 [salt.loaded.int.states.file:2298][WARNING ][2437] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-26 20:10:02,205 [salt.state       :2022][WARNING ][2956] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-26 20:10:05,276 [salt.utils.decorators:613 ][WARNING ][2956] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:25:11,475 [salt.utils.decorators:613 ][WARNING ][2956] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:27:09,335 [salt.utils.decorators:613 ][WARNING ][2956] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:29:39,287 [salt.utils.decorators:613 ][WARNING ][2956] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:29:39,459 [salt.loaded.ext.module.maas:160 ][ERROR   ][2956] Failed for object commissioning_distro_series reason {"commissioning_distro_series": ["'xenial' is not a valid commissioning_distro_series.  It should be one of: '---'."]}
2019-05-26 20:29:39,509 [salt.loaded.ext.module.maas:160 ][ERROR   ][2956] Failed for object default_osystem reason {"default_osystem": ["'ubuntu' is not a valid osystem.  It should be one of: '---'."]}
2019-05-26 20:29:41,197 [salt.state       :302 ][ERROR   ][2956] 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: \'---\'."]}'}, '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_distro_series', 'default_min_hwe_kernel']}
2019-05-26 20:29:41,320 [salt.loaded.ext.module.maasng:1008][WARNING ][2956] Detected cidr:192.168.11.0/24 in fabric:fabric-1
2019-05-26 20:29:41,321 [salt.loaded.ext.module.maasng:1011][WARNING ][2956] Guessing, that fabric with current name:fabric-1
 should be renamed to:pxe_admin
2019-05-26 20:29:42,091 [salt.loaded.ext.module.maasng:1235][WARNING ][2956] Ignoring parameter vlan:0
2019-05-26 20:29:48,600 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32389] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-26 20:29:48,646 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32389] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-26 20:29:48,711 [salt.utils.parsers:1051][WARNING ][383] Minion received a SIGTERM. Exiting.
2019-05-26 20:29:51,371 [salt.cli.daemons :293 ][INFO    ][32435] Setting up the Salt Minion "mas01.mcp-ovs-ha.local"
2019-05-26 20:29:51,550 [salt.cli.daemons :82  ][INFO    ][32435] Starting up the Salt Minion
2019-05-26 20:29:51,551 [salt.utils.event :1017][INFO    ][32435] Starting pull socket on /var/run/salt/minion/minion_event_501f9ec045_pull.ipc
2019-05-26 20:29:52,920 [salt.minion      :976 ][INFO    ][32435] Creating minion process manager
2019-05-26 20:29:54,954 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][32435] Executing command ['date', '+%z'] in directory '/root'
2019-05-26 20:29:54,985 [salt.utils.schedule:568 ][INFO    ][32435] Updating job settings for scheduled job: __mine_interval
2019-05-26 20:29:54,989 [salt.minion      :1108][INFO    ][32435] Added mine.update to scheduler
2019-05-26 20:29:54,995 [salt.minion      :1975][INFO    ][32435] Minion is starting as user 'root'
2019-05-26 20:29:55,009 [salt.minion      :2336][INFO    ][32435] Minion is ready to receive requests!
2019-05-26 20:29:55,015 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526202953934088
2019-05-26 20:29:55,030 [salt.minion      :1432][INFO    ][32565] Starting a new job with PID 32565
2019-05-26 20:30:01,648 [salt.state       :915 ][INFO    ][32565] Loading fresh modules for state activity
2019-05-26 20:30:03,203 [salt.state       :1780][INFO    ][32565] Running state [maas-region-controller] at time 20:30:03.203559
2019-05-26 20:30:03,204 [salt.state       :1813][INFO    ][32565] Executing state pkg.installed for [maas-region-controller]
2019-05-26 20:30:03,204 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-26 20:30:03,346 [salt.state       :300 ][INFO    ][32565] All specified packages are already installed
2019-05-26 20:30:03,347 [salt.state       :1951][INFO    ][32565] Completed state [maas-region-controller] at time 20:30:03.346957 duration_in_ms=143.399
2019-05-26 20:30:03,347 [salt.state       :1780][INFO    ][32565] Running state [python-oauth] at time 20:30:03.347317
2019-05-26 20:30:03,347 [salt.state       :1813][INFO    ][32565] Executing state pkg.installed for [python-oauth]
2019-05-26 20:30:03,357 [salt.state       :300 ][INFO    ][32565] All specified packages are already installed
2019-05-26 20:30:03,357 [salt.state       :1951][INFO    ][32565] Completed state [python-oauth] at time 20:30:03.357500 duration_in_ms=10.182
2019-05-26 20:30:03,363 [salt.state       :1780][INFO    ][32565] Running state [/etc/maas/regiond.conf] at time 20:30:03.363159
2019-05-26 20:30:03,363 [salt.state       :1813][INFO    ][32565] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-26 20:30:03,369 [salt.state       :300 ][INFO    ][32565] No changes needed to be made
2019-05-26 20:30:03,369 [salt.state       :1951][INFO    ][32565] Completed state [/etc/maas/regiond.conf] at time 20:30:03.369623 duration_in_ms=6.464
2019-05-26 20:30:03,370 [salt.state       :1780][INFO    ][32565] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:30:03.370805
2019-05-26 20:30:03,371 [salt.state       :1813][INFO    ][32565] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-26 20:30:03,439 [salt.state       :300 ][INFO    ][32565] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-26 20:30:03,440 [salt.state       :1951][INFO    ][32565] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 20:30:03.440122 duration_in_ms=69.317
2019-05-26 20:30:03,440 [salt.state       :1780][INFO    ][32565] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:30:03.440650
2019-05-26 20:30:03,440 [salt.state       :1813][INFO    ][32565] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-26 20:30:03,446 [salt.state       :300 ][INFO    ][32565] No changes needed to be made
2019-05-26 20:30:03,447 [salt.state       :1951][INFO    ][32565] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:30:03.446945 duration_in_ms=6.294
2019-05-26 20:30:03,447 [salt.state       :1780][INFO    ][32565] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:30:03.447462
2019-05-26 20:30:03,447 [salt.state       :1813][INFO    ][32565] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-26 20:30:03,452 [salt.state       :300 ][INFO    ][32565] No changes needed to be made
2019-05-26 20:30:03,452 [salt.state       :1951][INFO    ][32565] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 20:30:03.452227 duration_in_ms=4.765
2019-05-26 20:30:03,452 [salt.state       :1780][INFO    ][32565] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:30:03.452742
2019-05-26 20:30:03,453 [salt.state       :1813][INFO    ][32565] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-26 20:30:03,488 [salt.state       :300 ][INFO    ][32565] No changes needed to be made
2019-05-26 20:30:03,488 [salt.state       :1951][INFO    ][32565] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 20:30:03.488358 duration_in_ms=35.616
2019-05-26 20:30:03,489 [salt.state       :1780][INFO    ][32565] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:30:03.488956
2019-05-26 20:30:03,489 [salt.state       :1813][INFO    ][32565] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-26 20:30:03,510 [salt.state       :300 ][INFO    ][32565] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-26 20:30:03,511 [salt.state       :1951][INFO    ][32565] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 20:30:03.511080 duration_in_ms=22.122
2019-05-26 20:30:03,515 [salt.state       :1780][INFO    ][32565] Running state [a2enmod headers] at time 20:30:03.514878
2019-05-26 20:30:03,515 [salt.state       :1813][INFO    ][32565] Executing state cmd.run for [a2enmod headers]
2019-05-26 20:30:03,516 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command 'a2enmod headers' in directory '/root'
2019-05-26 20:30:03,610 [salt.state       :300 ][INFO    ][32565] {'pid': 32591, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-26 20:30:03,611 [salt.state       :1951][INFO    ][32565] Completed state [a2enmod headers] at time 20:30:03.611159 duration_in_ms=96.282
2019-05-26 20:30:03,611 [salt.state       :1780][INFO    ][32565] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:30:03.611713
2019-05-26 20:30:03,612 [salt.state       :1813][INFO    ][32565] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-26 20:30:03,637 [salt.state       :300 ][INFO    ][32565] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-26 20:30:03,637 [salt.state       :1951][INFO    ][32565] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 20:30:03.637423 duration_in_ms=25.71
2019-05-26 20:30:03,640 [salt.state       :1780][INFO    ][32565] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:30:03.640502
2019-05-26 20:30:03,640 [salt.state       :1813][INFO    ][32565] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-26 20:30:03,713 [salt.state       :300 ][INFO    ][32565] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-26 20:30:03,713 [salt.state       :1951][INFO    ][32565] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 20:30:03.713370 duration_in_ms=72.867
2019-05-26 20:30:03,714 [salt.state       :1780][INFO    ][32565] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:30:03.714211
2019-05-26 20:30:03,714 [salt.state       :1813][INFO    ][32565] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-26 20:30:03,782 [salt.state       :300 ][INFO    ][32565] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-26 20:30:03,783 [salt.state       :1951][INFO    ][32565] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 20:30:03.783096 duration_in_ms=68.884
2019-05-26 20:30:03,783 [salt.state       :1780][INFO    ][32565] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:30:03.783840
2019-05-26 20:30:03,784 [salt.state       :1813][INFO    ][32565] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-26 20:30:03,857 [salt.state       :300 ][INFO    ][32565] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-26 20:30:03,858 [salt.state       :1951][INFO    ][32565] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 20:30:03.858388 duration_in_ms=74.548
2019-05-26 20:30:03,859 [salt.state       :1780][INFO    ][32565] Running state [/root/.pgpass] at time 20:30:03.858981
2019-05-26 20:30:03,859 [salt.state       :1813][INFO    ][32565] Executing state file.managed for [/root/.pgpass]
2019-05-26 20:30:03,927 [salt.state       :300 ][INFO    ][32565] File /root/.pgpass is in the correct state
2019-05-26 20:30:03,927 [salt.state       :1951][INFO    ][32565] Completed state [/root/.pgpass] at time 20:30:03.927823 duration_in_ms=68.842
2019-05-26 20:30:03,933 [salt.state       :1780][INFO    ][32565] Running state [maas-region syncdb --noinput] at time 20:30:03.933587
2019-05-26 20:30:03,933 [salt.state       :1813][INFO    ][32565] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-26 20:30:03,934 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-26 20:30:07,307 [salt.state       :300 ][INFO    ][32565] {'pid': 32604, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sites, sessions, contenttypes, piston3, auth, maasserver, metadataserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-26 20:30:07,308 [salt.state       :1951][INFO    ][32565] Completed state [maas-region syncdb --noinput] at time 20:30:07.308640 duration_in_ms=3375.051
2019-05-26 20:30:07,309 [salt.state       :2022][WARNING ][32565] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-26 20:30:07,313 [salt.state       :1780][INFO    ][32565] Running state [maas-regiond] at time 20:30:07.313451
2019-05-26 20:30:07,314 [salt.state       :1813][INFO    ][32565] Executing state service.running for [maas-regiond]
2019-05-26 20:30:07,316 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-26 20:30:07,371 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-26 20:30:07,392 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-26 20:30:07,415 [salt.state       :300 ][INFO    ][32565] The service maas-regiond is already running
2019-05-26 20:30:07,416 [salt.state       :1951][INFO    ][32565] Completed state [maas-regiond] at time 20:30:07.416005 duration_in_ms=102.554
2019-05-26 20:30:07,421 [salt.state       :1780][INFO    ][32565] Running state [bind9] at time 20:30:07.421013
2019-05-26 20:30:07,421 [salt.state       :1813][INFO    ][32565] Executing state service.running for [bind9]
2019-05-26 20:30:07,422 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-26 20:30:07,446 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-26 20:30:07,469 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-26 20:30:07,493 [salt.state       :300 ][INFO    ][32565] The service bind9 is already running
2019-05-26 20:30:07,494 [salt.state       :1951][INFO    ][32565] Completed state [bind9] at time 20:30:07.494229 duration_in_ms=73.215
2019-05-26 20:30:07,497 [salt.state       :1780][INFO    ][32565] Running state [apache2] at time 20:30:07.497364
2019-05-26 20:30:07,498 [salt.state       :1813][INFO    ][32565] Executing state service.running for [apache2]
2019-05-26 20:30:07,499 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-26 20:30:07,524 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-26 20:30:07,545 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-26 20:30:07,581 [salt.state       :300 ][INFO    ][32565] The service apache2 is already running
2019-05-26 20:30:07,582 [salt.state       :1951][INFO    ][32565] Completed state [apache2] at time 20:30:07.581645 duration_in_ms=84.281
2019-05-26 20:30:07,584 [salt.state       :1780][INFO    ][32565] Running state [maasng.wait_for_http_code] at time 20:30:07.584624
2019-05-26 20:30:07,585 [salt.state       :1813][INFO    ][32565] Executing state module.run for [maasng.wait_for_http_code]
2019-05-26 20:30:07,587 [salt.utils.decorators:613 ][WARNING ][32565] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:30:07,602 [salt.state       :300 ][INFO    ][32565] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-26 20:30:07,603 [salt.state       :1951][INFO    ][32565] Completed state [maasng.wait_for_http_code] at time 20:30:07.603174 duration_in_ms=18.549
2019-05-26 20:30:07,605 [salt.state       :1780][INFO    ][32565] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:30:07.605044
2019-05-26 20:30:07,605 [salt.state       :1813][INFO    ][32565] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-26 20:30:07,606 [salt.state       :300 ][INFO    ][32565] /var/lib/maas/.setup_admin exists
2019-05-26 20:30:07,607 [salt.state       :1951][INFO    ][32565] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 20:30:07.607294 duration_in_ms=2.25
2019-05-26 20:30:07,609 [salt.state       :1780][INFO    ][32565] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:30:07.608879
2019-05-26 20:30:07,609 [salt.state       :1813][INFO    ][32565] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 20:30:07,612 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32565] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 20:30:09,060 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203009050821
2019-05-26 20:30:09,081 [salt.minion      :1432][INFO    ][32663] Starting a new job with PID 32663
2019-05-26 20:30:09,112 [salt.minion      :1711][INFO    ][32663] Returning information for job: 20190526203009050821
2019-05-26 20:30:09,568 [salt.state       :300 ][INFO    ][32565] {'pid': 32658, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 20:30:09,569 [salt.state       :1951][INFO    ][32565] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:30:09.569480 duration_in_ms=1960.6
2019-05-26 20:30:09,582 [salt.state       :1780][INFO    ][32565] Running state [maas_region_boot_source_resources_mirror] at time 20:30:09.582404
2019-05-26 20:30:09,583 [salt.state       :1813][INFO    ][32565] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-26 20:30:09,684 [salt.state       :300 ][INFO    ][32565] {'changes': {}}
2019-05-26 20:30:09,685 [salt.state       :1951][INFO    ][32565] Completed state [maas_region_boot_source_resources_mirror] at time 20:30:09.685083 duration_in_ms=102.679
2019-05-26 20:30:09,688 [salt.state       :1780][INFO    ][32565] Running state [maasng.boot_resources_import] at time 20:30:09.688227
2019-05-26 20:30:09,688 [salt.state       :1813][INFO    ][32565] Executing state module.run for [maasng.boot_resources_import]
2019-05-26 20:30:09,689 [salt.utils.decorators:613 ][WARNING ][32565] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:30:09,784 [salt.loaded.ext.module.maasng:1600][INFO    ][32565] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-26 20:30:14,836 [salt.loaded.ext.module.maasng:1600][INFO    ][32565] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-26 20:30:19,936 [salt.state       :300 ][INFO    ][32565] {'ret': True}
2019-05-26 20:30:19,937 [salt.state       :1951][INFO    ][32565] Completed state [maasng.boot_resources_import] at time 20:30:19.937287 duration_in_ms=10249.059
2019-05-26 20:30:19,939 [salt.state       :1780][INFO    ][32565] Running state [maas_region_boot_sources_selection_xenial] at time 20:30:19.939755
2019-05-26 20:30:19,940 [salt.state       :1813][INFO    ][32565] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-26 20:30:20,113 [salt.state       :300 ][INFO    ][32565] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-26 20:30:20,115 [salt.state       :1951][INFO    ][32565] Completed state [maas_region_boot_sources_selection_xenial] at time 20:30:20.113623 duration_in_ms=173.868
2019-05-26 20:30:20,116 [salt.state       :1780][INFO    ][32565] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 20:30:20.116628
2019-05-26 20:30:20,117 [salt.state       :1813][INFO    ][32565] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-26 20:30:20,118 [salt.utils.decorators:613 ][WARNING ][32565] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:30:20,118 [salt.loaded.ext.module.maasng:1771][INFO    ][32565] boot-sources sync initiated for ALL Rack's
2019-05-26 20:30:21,322 [salt.state       :300 ][INFO    ][32565] {'ret': True}
2019-05-26 20:30:21,322 [salt.state       :1951][INFO    ][32565] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 20:30:21.322888 duration_in_ms=1206.26
2019-05-26 20:30:21,325 [salt.state       :1780][INFO    ][32565] Running state [maas.process_maas_config] at time 20:30:21.325386
2019-05-26 20:30:21,327 [salt.state       :1813][INFO    ][32565] Executing state module.run for [maas.process_maas_config]
2019-05-26 20:30:21,328 [salt.utils.decorators:613 ][WARNING ][32565] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:30:21,329 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=enable_http_proxy value=True
2019-05-26 20:30:21,381 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=upstream_dns value=8.8.8.8
2019-05-26 20:30:22,841 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=commissioning_distro_series value=xenial
2019-05-26 20:30:22,905 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=default_osystem value=ubuntu
2019-05-26 20:30:22,968 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=active_discovery_interval value=600
2019-05-26 20:30:23,017 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=dnssec_validation value=no
2019-05-26 20:30:23,068 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=maas_name value=mas01
2019-05-26 20:30:23,109 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=network_discovery value=enabled
2019-05-26 20:30:23,202 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=enable_third_party_drivers value=True
2019-05-26 20:30:23,248 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=default_storage_layout value=lvm
2019-05-26 20:30:23,300 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=ntp_external_only value=True
2019-05-26 20:30:23,348 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-26 20:30:23,393 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=default_distro_series value=xenial
2019-05-26 20:30:23,455 [salt.loaded.ext.module.maas:92  ][INFO    ][32565] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-26 20:30:23,587 [salt.state       :300 ][INFO    ][32565] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-05-26 20:30:23,588 [salt.state       :1951][INFO    ][32565] Completed state [maas.process_maas_config] at time 20:30:23.588484 duration_in_ms=2263.097
2019-05-26 20:30:23,589 [salt.state       :1780][INFO    ][32565] Running state [pxe_admin] at time 20:30:23.589500
2019-05-26 20:30:23,590 [salt.state       :1813][INFO    ][32565] Executing state maasng.fabric_present for [pxe_admin]
2019-05-26 20:30:23,651 [salt.loaded.ext.module.maasng:945 ][INFO    ][32565] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-05-26 20:30:23,737 [salt.loaded.ext.module.maasng:1008][WARNING ][32565] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-26 20:30:23,737 [salt.loaded.ext.module.maasng:1011][WARNING ][32565] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-26 20:30:23,795 [salt.state       :300 ][INFO    ][32565] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-26 20:30:23,795 [salt.state       :1951][INFO    ][32565] Completed state [pxe_admin] at time 20:30:23.795720 duration_in_ms=206.22
2019-05-26 20:30:23,796 [salt.state       :1780][INFO    ][32565] Running state [vlan 0] at time 20:30:23.796189
2019-05-26 20:30:23,796 [salt.state       :1813][INFO    ][32565] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-26 20:30:23,849 [salt.loaded.ext.module.maasng:945 ][INFO    ][32565] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-2', u'relay_vlan': None, u'primary_rack': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'fabric-2'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'pxe_admin'}]
2019-05-26 20:30:23,967 [salt.loaded.ext.module.maasng:945 ][INFO    ][32565] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-05-26 20:30:24,244 [salt.loaded.ext.module.maasng:945 ][INFO    ][32565] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-05-26 20:30:24,333 [salt.state       :300 ][INFO    ][32565] {'new': 'Vlan untagged was updated'}
2019-05-26 20:30:24,334 [salt.state       :1951][INFO    ][32565] Completed state [vlan 0] at time 20:30:24.333648 duration_in_ms=537.459
2019-05-26 20:30:24,335 [salt.state       :1780][INFO    ][32565] Running state [192.168.11.0/24] at time 20:30:24.335096
2019-05-26 20:30:24,335 [salt.state       :1813][INFO    ][32565] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-26 20:30:24,516 [salt.loaded.ext.module.maasng:945 ][INFO    ][32565] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-2', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'fabric-2'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': u'ae4y36', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'pxe_admin'}]
2019-05-26 20:30:24,516 [salt.loaded.ext.module.maasng:1235][WARNING ][32565] Ignoring parameter vlan:0
2019-05-26 20:30:24,577 [salt.state       :300 ][INFO    ][32565] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-26 20:30:24,578 [salt.state       :1951][INFO    ][32565] Completed state [192.168.11.0/24] at time 20:30:24.578553 duration_in_ms=243.456
2019-05-26 20:30:24,579 [salt.state       :1780][INFO    ][32565] Running state [maas_create_iprange_1] at time 20:30:24.579438
2019-05-26 20:30:24,579 [salt.state       :1813][INFO    ][32565] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-26 20:30:24,631 [salt.state       :300 ][INFO    ][32565] Iprange maas_create_iprange_1 already exist.
2019-05-26 20:30:24,631 [salt.state       :1951][INFO    ][32565] Completed state [maas_create_iprange_1] at time 20:30:24.631619 duration_in_ms=52.179
2019-05-26 20:30:24,632 [salt.state       :1780][INFO    ][32565] Running state [vlan 0] at time 20:30:24.632147
2019-05-26 20:30:24,632 [salt.state       :1813][INFO    ][32565] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-26 20:30:24,679 [salt.loaded.ext.module.maasng:945 ][INFO    ][32565] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-05-26 20:30:24,793 [salt.loaded.ext.module.maasng:945 ][INFO    ][32565] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-05-26 20:30:25,012 [salt.loaded.ext.module.maasng:945 ][INFO    ][32565] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-05-26 20:30:25,125 [salt.state       :300 ][INFO    ][32565] {'new': 'Vlan untagged was updated'}
2019-05-26 20:30:25,127 [salt.state       :1951][INFO    ][32565] Completed state [vlan 0] at time 20:30:25.126994 duration_in_ms=494.847
2019-05-26 20:30:25,128 [salt.state       :1780][INFO    ][32565] Running state [opnfv] at time 20:30:25.128130
2019-05-26 20:30:25,128 [salt.state       :1813][INFO    ][32565] Executing state maasng.sshkey_present for [opnfv]
2019-05-26 20:30:25,189 [salt.loaded.ext.module.maasng:1903][INFO    ][32565] [{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-05-26 20:30:25,194 [salt.state       :300 ][INFO    ][32565] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b already exist for user opnfv.
2019-05-26 20:30:25,194 [salt.state       :1951][INFO    ][32565] Completed state [opnfv] at time 20:30:25.194809 duration_in_ms=66.679
2019-05-26 20:30:25,198 [salt.minion      :1711][INFO    ][32565] Returning information for job: 20190526202953934088
2019-05-26 20:30:26,020 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526203026008273
2019-05-26 20:30:26,037 [salt.minion      :1432][INFO    ][33056] Starting a new job with PID 33056
2019-05-26 20:30:32,261 [salt.state       :915 ][INFO    ][33056] Loading fresh modules for state activity
2019-05-26 20:30:32,351 [salt.fileclient  :1219][INFO    ][33056] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-05-26 20:30:32,415 [salt.state       :1780][INFO    ][33056] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:30:32.415377
2019-05-26 20:30:32,415 [salt.state       :1813][INFO    ][33056] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 20:30:32,417 [salt.loaded.int.module.cmdmod:395 ][INFO    ][33056] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 20:30:34,453 [salt.state       :300 ][INFO    ][33056] {'pid': 33079, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 20:30:34,454 [salt.state       :1951][INFO    ][33056] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:30:34.454687 duration_in_ms=2039.311
2019-05-26 20:30:34,456 [salt.state       :1780][INFO    ][33056] Running state [maas.process_machines] at time 20:30:34.456672
2019-05-26 20:30:34,457 [salt.state       :1813][INFO    ][33056] Executing state module.run for [maas.process_machines]
2019-05-26 20:30:34,457 [salt.utils.decorators:613 ][WARNING ][33056] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:30:34,523 [salt.loaded.ext.module.maas:412 ][WARNING ][33056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 20:30:34,524 [salt.loaded.ext.module.maas:92  ][INFO    ][33056] 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-05-26 20:30:36,057 [salt.loaded.ext.module.maas:412 ][WARNING ][33056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 20:30:36,057 [salt.loaded.ext.module.maas:92  ][INFO    ][33056] 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-05-26 20:30:37,458 [salt.loaded.ext.module.maas:412 ][WARNING ][33056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 20:30:37,459 [salt.loaded.ext.module.maas:92  ][INFO    ][33056] machine hostname=kvm01 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-05-26 20:30:38,864 [salt.loaded.ext.module.maas:412 ][WARNING ][33056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 20:30:38,864 [salt.loaded.ext.module.maas:92  ][INFO    ][33056] machine hostname=kvm03 power_type=ipmi mac_addresses=14:58:d0:54:7a:28 power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 architecture=amd64/generic power_parameters_power_user=opnfv
2019-05-26 20:30:40,284 [salt.loaded.ext.module.maas:412 ][WARNING ][33056] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 20:30:40,284 [salt.loaded.ext.module.maas:92  ][INFO    ][33056] machine hostname=kvm02 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-05-26 20:30:41,130 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203041118644
2019-05-26 20:30:41,149 [salt.minion      :1432][INFO    ][33346] Starting a new job with PID 33346
2019-05-26 20:30:41,182 [salt.minion      :1711][INFO    ][33346] Returning information for job: 20190526203041118644
2019-05-26 20:30:41,728 [salt.state       :300 ][INFO    ][33056] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-26 20:30:41,728 [salt.state       :1951][INFO    ][33056] Completed state [maas.process_machines] at time 20:30:41.728642 duration_in_ms=7271.969
2019-05-26 20:30:41,732 [salt.minion      :1711][INFO    ][33056] Returning information for job: 20190526203026008273
2019-05-26 20:31:13,114 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526203113101451
2019-05-26 20:31:13,141 [salt.minion      :1432][INFO    ][33422] Starting a new job with PID 33422
2019-05-26 20:31:19,097 [salt.state       :915 ][INFO    ][33422] Loading fresh modules for state activity
2019-05-26 20:31:19,163 [salt.fileclient  :1219][INFO    ][33422] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-26 20:31:19,227 [salt.state       :1780][INFO    ][33422] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:31:19.227691
2019-05-26 20:31:19,228 [salt.state       :1813][INFO    ][33422] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 20:31:19,231 [salt.loaded.int.module.cmdmod:395 ][INFO    ][33422] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 20:31:21,080 [salt.state       :300 ][INFO    ][33422] {'pid': 33430, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 20:31:21,080 [salt.state       :1951][INFO    ][33422] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:31:21.080705 duration_in_ms=1853.015
2019-05-26 20:31:21,084 [salt.state       :1780][INFO    ][33422] Running state [maas.wait_for_machine_status] at time 20:31:21.084788
2019-05-26 20:31:21,085 [salt.state       :1813][INFO    ][33422] Executing state module.run for [maas.wait_for_machine_status]
2019-05-26 20:31:21,087 [salt.utils.decorators:613 ][WARNING ][33422] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:31:21,884 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.21460605s left)
2019-05-26 20:31:28,173 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203128159180
2019-05-26 20:31:28,204 [salt.minion      :1432][INFO    ][33445] Starting a new job with PID 33445
2019-05-26 20:31:28,234 [salt.minion      :1711][INFO    ][33445] Returning information for job: 20190526203128159180
2019-05-26 20:31:52,791 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.30759406s left)
2019-05-26 20:31:58,272 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203158248418
2019-05-26 20:31:58,301 [salt.minion      :1432][INFO    ][33479] Starting a new job with PID 33479
2019-05-26 20:31:58,328 [salt.minion      :1711][INFO    ][33479] Returning information for job: 20190526203158248418
2019-05-26 20:32:23,651 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.44703817s left)
2019-05-26 20:32:28,347 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203228332330
2019-05-26 20:32:28,374 [salt.minion      :1432][INFO    ][33523] Starting a new job with PID 33523
2019-05-26 20:32:28,403 [salt.minion      :1711][INFO    ][33523] Returning information for job: 20190526203228332330
2019-05-26 20:32:54,515 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1406.58336306s left)
2019-05-26 20:32:58,437 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203258426410
2019-05-26 20:32:58,461 [salt.minion      :1432][INFO    ][33552] Starting a new job with PID 33552
2019-05-26 20:32:58,493 [salt.minion      :1711][INFO    ][33552] Returning information for job: 20190526203258426410
2019-05-26 20:33:25,596 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1375.50206423s left)
2019-05-26 20:33:28,519 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203328499474
2019-05-26 20:33:28,545 [salt.minion      :1432][INFO    ][33629] Starting a new job with PID 33629
2019-05-26 20:33:28,571 [salt.minion      :1711][INFO    ][33629] Returning information for job: 20190526203328499474
2019-05-26 20:33:56,784 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1344.31479311s left)
2019-05-26 20:33:58,602 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203358589035
2019-05-26 20:33:58,628 [salt.minion      :1432][INFO    ][33729] Starting a new job with PID 33729
2019-05-26 20:33:58,659 [salt.minion      :1711][INFO    ][33729] Returning information for job: 20190526203358589035
2019-05-26 20:34:27,942 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1313.15627623s left)
2019-05-26 20:34:28,726 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203428714715
2019-05-26 20:34:28,752 [salt.minion      :1432][INFO    ][33993] Starting a new job with PID 33993
2019-05-26 20:34:28,781 [salt.minion      :1711][INFO    ][33993] Returning information for job: 20190526203428714715
2019-05-26 20:34:58,810 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203458801172
2019-05-26 20:34:58,829 [salt.minion      :1432][INFO    ][34144] Starting a new job with PID 34144
2019-05-26 20:34:58,858 [salt.minion      :1711][INFO    ][34144] Returning information for job: 20190526203458801172
2019-05-26 20:34:59,364 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1281.73470306s left)
2019-05-26 20:35:28,929 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203528919658
2019-05-26 20:35:28,954 [salt.minion      :1432][INFO    ][34298] Starting a new job with PID 34298
2019-05-26 20:35:28,983 [salt.minion      :1711][INFO    ][34298] Returning information for job: 20190526203528919658
2019-05-26 20:35:31,133 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1249.9656682s left)
2019-05-26 20:35:59,049 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203559034172
2019-05-26 20:35:59,080 [salt.minion      :1432][INFO    ][34399] Starting a new job with PID 34399
2019-05-26 20:35:59,112 [salt.minion      :1711][INFO    ][34399] Returning information for job: 20190526203559034172
2019-05-26 20:36:03,348 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1217.75016999s left)
2019-05-26 20:36:29,251 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203629239719
2019-05-26 20:36:29,276 [salt.minion      :1432][INFO    ][34899] Starting a new job with PID 34899
2019-05-26 20:36:29,303 [salt.minion      :1711][INFO    ][34899] Returning information for job: 20190526203629239719
2019-05-26 20:36:35,595 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1185.50330305s left)
2019-05-26 20:36:59,358 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203659342820
2019-05-26 20:36:59,387 [salt.minion      :1432][INFO    ][34928] Starting a new job with PID 34928
2019-05-26 20:36:59,416 [salt.minion      :1711][INFO    ][34928] Returning information for job: 20190526203659342820
2019-05-26 20:37:07,783 [salt.loaded.ext.module.maas:1023][INFO    ][33422] Waiting status:Ready|Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1153.3150022s left)
2019-05-26 20:37:29,504 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203729492921
2019-05-26 20:37:29,533 [salt.minion      :1432][INFO    ][35106] Starting a new job with PID 35106
2019-05-26 20:37:29,565 [salt.minion      :1711][INFO    ][35106] Returning information for job: 20190526203729492921
2019-05-26 20:37:40,732 [salt.state       :300 ][INFO    ][33422] {'ret': True}
2019-05-26 20:37:40,732 [salt.state       :1951][INFO    ][33422] Completed state [maas.wait_for_machine_status] at time 20:37:40.732730 duration_in_ms=379647.941
2019-05-26 20:37:40,736 [salt.minion      :1711][INFO    ][33422] Returning information for job: 20190526203113101451
2019-05-26 20:37:41,433 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526203741423426
2019-05-26 20:37:41,458 [salt.minion      :1432][INFO    ][35138] Starting a new job with PID 35138
2019-05-26 20:37:47,504 [salt.state       :915 ][INFO    ][35138] Loading fresh modules for state activity
2019-05-26 20:37:47,578 [salt.fileclient  :1219][INFO    ][35138] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-26 20:37:47,680 [salt.state       :1780][INFO    ][35138] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:47.680739
2019-05-26 20:37:47,681 [salt.state       :1813][INFO    ][35138] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 20:37:47,683 [salt.loaded.int.module.cmdmod:395 ][INFO    ][35138] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 20:37:49,693 [salt.state       :300 ][INFO    ][35138] {'pid': 35154, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 20:37:49,695 [salt.state       :1951][INFO    ][35138] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:49.695468 duration_in_ms=2014.728
2019-05-26 20:37:49,699 [salt.state       :1780][INFO    ][35138] Running state [maas_machines_storage_cmp002_lvm] at time 20:37:49.699241
2019-05-26 20:37:49,700 [salt.state       :1813][INFO    ][35138] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-26 20:37:50,850 [salt.loaded.ext.module.maasng:610 ][INFO    ][35138] whh8ak
2019-05-26 20:37:50,851 [salt.loaded.ext.module.maasng:626 ][INFO    ][35138] sda
2019-05-26 20:37:51,390 [salt.loaded.ext.module.maasng:361 ][INFO    ][35138] whh8ak
2019-05-26 20:37:51,483 [salt.loaded.ext.module.maasng:367 ][INFO    ][35138] [{u'block_size': 4096, u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'uuid': u'bedec0aa-9c98-4e44-9c34-d475586ad0df', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'whh8ak', u'device_id': 1, u'filesystem': {u'mount_options': None, u'uuid': u'09919863-e88d-4dd3-b6f3-c126bc9095ab', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/1/partition/1'}], u'id': 1, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'whh8ak', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'size': 800109715456, u'used_size': 800106479616, u'serial': u'600508b1001cb19198eb9a66f8a29401', u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/1/'}, {u'block_size': 4096, u'uuid': u'0028c003-a39d-4017-84e7-9421be75f857', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'id': 3, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'whh8ak', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'dc40bddd-5d71-4207-af30-afa000e0989b', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'size': 800097042432, u'used_size': 800097042432, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/3/'}]
2019-05-26 20:37:51,483 [salt.loaded.ext.module.maasng:632 ][INFO    ][35138] vgroot
2019-05-26 20:37:51,484 [salt.loaded.ext.module.maasng:635 ][INFO    ][35138] lvroot
2019-05-26 20:37:51,484 [salt.loaded.ext.module.maasng:639 ][INFO    ][35138] 107374182400
2019-05-26 20:37:52,147 [salt.loaded.ext.module.maasng:645 ][INFO    ][35138] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/whh8ak/', u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 800109.715456, u'testing_status': 2, u'system_id': u'whh8ak', 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'blockdevice_set': [{u'size': 800109715456, u'available_size': 0, u'uuid': None, u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'ae5a00a3-5140-46e1-b6f5-c7bab0140f44', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'whh8ak', u'device_id': 1, u'filesystem': {u'uuid': u'0922ec0f-cfd4-48a8-ac05-b4c353ded186', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/1/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}], u'name': u'sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'system_id': u'whh8ak', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 1, u'path': u'/dev/disk/by-dname/sda', u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'used_for': u'MBR partitioned with 1 partition', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/1/'}, {u'size': 107374182400, u'available_size': 0, u'uuid': u'ab01ff81-c642-407e-a0e6-4276518629e5', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'name': u'vgroot-lvroot', u'id_path': None, u'system_id': u'whh8ak', u'partition_table_type': None, u'filesystem': {u'uuid': u'bbc25de8-f90c-4f7f-bb22-f4c65a37d9b2', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id': 11, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'used_for': u'ext4 formatted filesystem mounted at /', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/11/'}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 40, u'power_state': u'off', u'physicalblockdevice_set': [{u'size': 800109715456, u'available_size': 0, u'uuid': None, u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'ae5a00a3-5140-46e1-b6f5-c7bab0140f44', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'whh8ak', u'device_id': 1, u'filesystem': {u'uuid': u'0922ec0f-cfd4-48a8-ac05-b4c353ded186', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/1/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}], u'name': u'sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'system_id': u'whh8ak', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 1, u'path': u'/dev/disk/by-dname/sda', u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'used_for': u'MBR partitioned with 1 partition', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/1/'}], 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'whh8ak', u'id': 6}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'commissioning_status_name': u'Passed', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'virtualblockdevice_set': [{u'size': 107374182400, u'available_size': 0, u'uuid': u'ab01ff81-c642-407e-a0e6-4276518629e5', u'tags': [], u'used_size': 107374182400, u'partitions': [], u'name': u'vgroot-lvroot', u'id_path': None, u'system_id': u'whh8ak', u'partition_table_type': None, u'filesystem': {u'uuid': u'bbc25de8-f90c-4f7f-bb22-f4c65a37d9b2', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id': 11, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'model': None, u'block_size': 4096, u'type': u'virtual', u'used_for': u'ext4 formatted filesystem mounted at /', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/11/'}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'boot_interface': {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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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'id': 18, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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'mac_address': u'9c:b6:54:8a:10:18', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'whh8ak', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/interfaces/4/'}, u'interface_set': [{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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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'id': 18, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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'mac_address': u'9c:b6:54:8a:10:18', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'whh8ak', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/interfaces/4/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:07:51', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'whh8ak', u'type': u'physical', u'id': 13, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/interfaces/13/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'vlan': None, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:07:50', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'whh8ak', u'type': u'physical', u'id': 14, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/interfaces/14/'}, {u'name': u'ens2f1', u'links': [{u'id': 19, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:49', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'whh8ak', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/interfaces/15/'}, {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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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'id': 20, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}, 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'mac_address': u'9c:b6:54:8a:10:1c', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'whh8ak', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/interfaces/11/'}, {u'name': u'ens2f0', u'links': [{u'id': 21, u'mode': u'link_up'}], u'tags': [u'sriov'], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'38:ea:a7:8f:12:48', u'params': u'', u'effective_mtu': 1500, u'parents': [], u'system_id': u'whh8ak', u'type': u'physical', u'id': 12, u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/interfaces/12/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'boot_disk': {u'size': 800109715456, u'available_size': 0, u'uuid': None, u'tags': [u'ssd'], u'used_size': 800106479616, u'partitions': [{u'uuid': u'ae5a00a3-5140-46e1-b6f5-c7bab0140f44', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'whh8ak', u'device_id': 1, u'filesystem': {u'uuid': u'0922ec0f-cfd4-48a8-ac05-b4c353ded186', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/1/partition/6', u'type': u'partition', u'id': 6, u'size': 800101236736}], u'name': u'sda', u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cb19198eb9a66f8a29401', u'system_id': u'whh8ak', u'partition_table_type': u'MBR', u'filesystem': None, u'id': 1, u'path': u'/dev/disk/by-dname/sda', u'model': u'LOGICAL VOLUME', u'block_size': 4096, u'type': u'physical', u'used_for': u'MBR partitioned with 1 partition', u'serial': u'600508b1001cb19198eb9a66f8a29401', u'resource_uri': u'/MAAS/api/2.0/nodes/whh8ak/blockdevices/1/'}}
2019-05-26 20:37:52,149 [salt.state       :300 ][INFO    ][35138] {'new': {'storage_layout': 'lvm'}}
2019-05-26 20:37:52,149 [salt.state       :1951][INFO    ][35138] Completed state [maas_machines_storage_cmp002_lvm] at time 20:37:52.149285 duration_in_ms=2450.044
2019-05-26 20:37:52,150 [salt.state       :1780][INFO    ][35138] Running state [maas_machines_storage_cmp001_lvm] at time 20:37:52.150127
2019-05-26 20:37:52,150 [salt.state       :1813][INFO    ][35138] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-26 20:37:53,407 [salt.loaded.ext.module.maasng:610 ][INFO    ][35138] c7ncda
2019-05-26 20:37:53,408 [salt.loaded.ext.module.maasng:626 ][INFO    ][35138] sda
2019-05-26 20:37:53,982 [salt.loaded.ext.module.maasng:361 ][INFO    ][35138] c7ncda
2019-05-26 20:37:54,075 [salt.loaded.ext.module.maasng:367 ][INFO    ][35138] [{u'block_size': 4096, u'uuid': None, u'tags': [u'ssd'], u'used_for': u'MBR partitioned with 1 partition', u'type': u'physical', u'partitions': [{u'uuid': u'8a563b32-69e4-456f-a916-d76792f8916c', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'c7ncda', u'device_id': 2, u'filesystem': {u'mount_options': None, u'uuid': u'ba350dee-80e0-4593-83b0-e0cc1a2145de', u'mount_point': None, u'label': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part1', u'size': 800101236736, u'type': u'partition', u'id': 2, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/2/partition/2'}], u'id': 2, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'c7ncda', u'partition_table_type': u'MBR', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x600508b1001cd7e61f5cd3479576479e', u'available_size': 0, u'model': u'LOGICAL VOLUME', u'size': 800109715456, u'used_size': 800106479616, u'serial': u'600508b1001cd7e61f5cd3479576479e', u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/2/'}, {u'block_size': 4096, u'uuid': u'1a9b1cba-9306-401c-b45b-da066e94b1be', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'type': u'virtual', u'partitions': [], u'id': 4, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'c7ncda', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'uuid': u'bb36e240-b2cd-4ee3-96d7-24ebf5f39bb6', u'mount_point': u'/', u'label': u'root', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'size': 800097042432, u'used_size': 800097042432, u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/4/'}]
2019-05-26 20:37:54,076 [salt.loaded.ext.module.maasng:632 ][INFO    ][35138] vgroot
2019-05-26 20:37:54,077 [salt.loaded.ext.module.maasng:635 ][INFO    ][35138] lvroot
2019-05-26 20:37:54,077 [salt.loaded.ext.module.maasng:639 ][INFO    ][35138] 107374182400
2019-05-26 20:37:54,670 [salt.loaded.ext.module.maasng:645 ][INFO    ][35138] {u'hwe_kernel': u'', u'swap_size': None, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'size': 800109715456, u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/2/', u'available_size': 0, 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'system_id': u'c7ncda', 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'used_size': 800106479616, u'id': 2, u'partitions': [{u'uuid': u'3222ee07-d199-4f13-915b-b6b62a55e409', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'c7ncda', u'device_id': 2, u'filesystem': {u'uuid': u'cca7b4da-d406-432c-9ef7-cc95689d59f6', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/2/partition/7', u'type': u'partition', u'id': 7, u'size': 800101236736}]}, {u'size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/12/', u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'uuid': u'074c27c5-e5a7-46c2-995b-93ee24e3b3a3', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'c7ncda', u'partition_table_type': None, u'filesystem': {u'uuid': u'd0fdbb3c-360e-4122-a193-4266699f5d0d', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'partitions': []}], u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'name': u'default', u'description': u''}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 800109.715456, u'testing_status': 2, u'address_ttl': None, u'system_id': u'c7ncda', 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'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/12/', u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'uuid': u'074c27c5-e5a7-46c2-995b-93ee24e3b3a3', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'c7ncda', u'partition_table_type': None, u'filesystem': {u'uuid': u'd0fdbb3c-360e-4122-a193-4266699f5d0d', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'partitions': []}], u'architecture': u'amd64/generic', u'status': 4, u'bcaches': [], u'cpu_count': 40, u'power_state': u'off', u'physicalblockdevice_set': [{u'size': 800109715456, u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/2/', u'available_size': 0, 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'system_id': u'c7ncda', 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'used_size': 800106479616, u'id': 2, u'partitions': [{u'uuid': u'3222ee07-d199-4f13-915b-b6b62a55e409', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'c7ncda', u'device_id': 2, u'filesystem': {u'uuid': u'cca7b4da-d406-432c-9ef7-cc95689d59f6', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/2/partition/7', u'type': u'partition', u'id': 7, u'size': 800101236736}]}], u'ip_addresses': [u'192.168.11.39', u'192.168.11.43'], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'c7ncda', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'size': 800109715456, u'model': u'LOGICAL VOLUME', u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/2/', u'available_size': 0, 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'system_id': u'c7ncda', 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'used_size': 800106479616, u'id': 2, u'partitions': [{u'uuid': u'3222ee07-d199-4f13-915b-b6b62a55e409', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'c7ncda', u'device_id': 2, u'filesystem': {u'uuid': u'cca7b4da-d406-432c-9ef7-cc95689d59f6', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part1', u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/blockdevices/2/partition/7', u'type': u'partition', u'id': 7, u'size': 800101236736}]}, u'interface_set': [{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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', 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'id': 24, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', 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'parents': [], u'system_id': u'c7ncda', u'mac_address': u'9c:b6:54:8a:95:a0', u'params': u'', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/interfaces/5/'}, {u'name': u'ens1f0', u'links': [], u'tags': [u'sriov'], u'enabled': True, u'vlan': None, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'c7ncda', u'mac_address': u'38:ea:a7:8f:1f:d4', u'params': u'', u'type': u'physical', u'id': 17, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/interfaces/17/'}, {u'name': u'ens1f1', u'links': [], u'tags': [u'sriov'], u'enabled': True, u'vlan': None, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'c7ncda', u'mac_address': u'38:ea:a7:8f:1f:d5', u'params': u'', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/interfaces/19/'}, {u'name': u'ens2f0', u'links': [{u'id': 25, u'mode': u'link_up'}], u'tags': [u'sriov'], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'c7ncda', u'mac_address': u'38:ea:a7:8f:52:cc', u'params': u'', u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/interfaces/16/'}, {u'name': u'ens2f1', u'links': [{u'id': 26, u'mode': u'link_up'}], u'tags': [u'sriov'], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'effective_mtu': 1500, u'children': [], u'discovered': None, u'parents': [], u'system_id': u'c7ncda', u'mac_address': u'38:ea:a7:8f:52:cd', u'params': u'', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/interfaces/18/'}, {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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', 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'id': 27, u'mode': u'link_up'}], u'tags': [u'sriov'], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', 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'parents': [], u'system_id': u'c7ncda', u'mac_address': u'9c:b6:54:8a:95:a4', u'params': u'', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/interfaces/20/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'commissioning_status': 2, u'min_hwe_kernel': u'hwe-16.04', u'boot_interface': {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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', 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'id': 24, u'mode': u'dhcp'}], u'tags': [u'sriov'], u'enabled': True, u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}, u'effective_mtu': 1500, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', 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'parents': [], u'system_id': u'c7ncda', u'mac_address': u'9c:b6:54:8a:95:a0', u'params': u'', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/c7ncda/interfaces/5/'}, u'current_commissioning_result_id': 4, u'commissioning_status_name': u'Passed', u'resource_uri': u'/MAAS/api/2.0/machines/c7ncda/', u'distro_series': u'', u'memory_test_status': -1}
2019-05-26 20:37:54,672 [salt.state       :300 ][INFO    ][35138] {'new': {'storage_layout': 'lvm'}}
2019-05-26 20:37:54,673 [salt.state       :1951][INFO    ][35138] Completed state [maas_machines_storage_cmp001_lvm] at time 20:37:54.673105 duration_in_ms=2522.977
2019-05-26 20:37:54,678 [salt.minion      :1711][INFO    ][35138] Returning information for job: 20190526203741423426
2019-05-26 20:37:55,402 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526203755391138
2019-05-26 20:37:55,428 [salt.minion      :1432][INFO    ][35185] Starting a new job with PID 35185
2019-05-26 20:37:56,395 [salt.state       :915 ][INFO    ][35185] Loading fresh modules for state activity
2019-05-26 20:37:56,465 [salt.fileclient  :1219][INFO    ][35185] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-26 20:37:56,511 [salt.state       :1780][INFO    ][35185] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:56.511682
2019-05-26 20:37:56,512 [salt.state       :1813][INFO    ][35185] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 20:37:56,513 [salt.loaded.int.module.cmdmod:395 ][INFO    ][35185] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 20:37:58,406 [salt.state       :300 ][INFO    ][35185] {'pid': 35192, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 20:37:58,408 [salt.state       :1951][INFO    ][35185] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:37:58.407884 duration_in_ms=1896.201
2019-05-26 20:37:58,410 [salt.state       :1780][INFO    ][35185] Running state [maas.deploy_machines] at time 20:37:58.410839
2019-05-26 20:37:58,411 [salt.state       :1813][INFO    ][35185] Executing state module.run for [maas.deploy_machines]
2019-05-26 20:37:58,413 [salt.utils.decorators:613 ][WARNING ][35185] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:37:59,019 [salt.loaded.ext.module.maas:684 ][INFO    ][35185] deploymachines hwe_kernel=hwe-16.04 system_id=whh8ak distro_series=xenial
2019-05-26 20:38:01,534 [salt.loaded.ext.module.maas:684 ][INFO    ][35185] deploymachines hwe_kernel=hwe-16.04 system_id=c7ncda distro_series=xenial
2019-05-26 20:38:04,051 [salt.loaded.ext.module.maas:684 ][INFO    ][35185] deploymachines hwe_kernel=hwe-16.04 system_id=strh4h distro_series=xenial
2019-05-26 20:38:07,057 [salt.loaded.ext.module.maas:684 ][INFO    ][35185] deploymachines hwe_kernel=hwe-16.04 system_id=4wyerw distro_series=xenial
2019-05-26 20:38:09,548 [salt.loaded.ext.module.maas:684 ][INFO    ][35185] deploymachines hwe_kernel=hwe-16.04 system_id=na4ya3 distro_series=xenial
2019-05-26 20:38:10,492 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203810480402
2019-05-26 20:38:10,518 [salt.minion      :1432][INFO    ][35488] Starting a new job with PID 35488
2019-05-26 20:38:10,546 [salt.minion      :1711][INFO    ][35488] Returning information for job: 20190526203810480402
2019-05-26 20:38:12,116 [salt.state       :300 ][INFO    ][35185] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-26 20:38:12,117 [salt.state       :1951][INFO    ][35185] Completed state [maas.deploy_machines] at time 20:38:12.117377 duration_in_ms=13706.536
2019-05-26 20:38:12,127 [salt.minion      :1711][INFO    ][35185] Returning information for job: 20190526203755391138
2019-05-26 20:38:12,857 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526203812847291
2019-05-26 20:38:12,883 [salt.minion      :1432][INFO    ][35527] Starting a new job with PID 35527
2019-05-26 20:38:18,942 [salt.state       :915 ][INFO    ][35527] Loading fresh modules for state activity
2019-05-26 20:38:19,012 [salt.fileclient  :1219][INFO    ][35527] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-26 20:38:19,060 [salt.state       :1780][INFO    ][35527] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:38:19.059921
2019-05-26 20:38:19,060 [salt.state       :1813][INFO    ][35527] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 20:38:19,062 [salt.loaded.int.module.cmdmod:395 ][INFO    ][35527] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 20:38:20,936 [salt.state       :300 ][INFO    ][35527] {'pid': 35550, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 20:38:20,937 [salt.state       :1951][INFO    ][35527] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 20:38:20.937398 duration_in_ms=1877.477
2019-05-26 20:38:20,943 [salt.state       :1780][INFO    ][35527] Running state [maas.wait_for_machine_status] at time 20:38:20.943346
2019-05-26 20:38:20,943 [salt.state       :1813][INFO    ][35527] Executing state module.run for [maas.wait_for_machine_status]
2019-05-26 20:38:20,944 [salt.utils.decorators:613 ][WARNING ][35527] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 20:38:23,875 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2247.08178592s left)
2019-05-26 20:38:27,916 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203827899928
2019-05-26 20:38:27,948 [salt.minion      :1432][INFO    ][35568] Starting a new job with PID 35568
2019-05-26 20:38:27,981 [salt.minion      :1711][INFO    ][35568] Returning information for job: 20190526203827899928
2019-05-26 20:38:56,825 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2214.13148689s left)
2019-05-26 20:38:58,000 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203857980358
2019-05-26 20:38:58,025 [salt.minion      :1432][INFO    ][35596] Starting a new job with PID 35596
2019-05-26 20:38:58,051 [salt.minion      :1711][INFO    ][35596] Returning information for job: 20190526203857980358
2019-05-26 20:39:28,075 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203928061118
2019-05-26 20:39:28,099 [salt.minion      :1432][INFO    ][35640] Starting a new job with PID 35640
2019-05-26 20:39:28,129 [salt.minion      :1711][INFO    ][35640] Returning information for job: 20190526203928061118
2019-05-26 20:39:29,691 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2181.2673068s left)
2019-05-26 20:39:58,146 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526203958132035
2019-05-26 20:39:58,173 [salt.minion      :1432][INFO    ][35674] Starting a new job with PID 35674
2019-05-26 20:39:58,200 [salt.minion      :1711][INFO    ][35674] Returning information for job: 20190526203958132035
2019-05-26 20:40:02,658 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2148.29884386s left)
2019-05-26 20:40:28,239 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204028224358
2019-05-26 20:40:28,267 [salt.minion      :1432][INFO    ][35736] Starting a new job with PID 35736
2019-05-26 20:40:28,299 [salt.minion      :1711][INFO    ][35736] Returning information for job: 20190526204028224358
2019-05-26 20:40:35,679 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2115.27808595s left)
2019-05-26 20:40:58,327 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204058304829
2019-05-26 20:40:58,361 [salt.minion      :1432][INFO    ][35786] Starting a new job with PID 35786
2019-05-26 20:40:58,389 [salt.minion      :1711][INFO    ][35786] Returning information for job: 20190526204058304829
2019-05-26 20:41:08,612 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2082.34420085s left)
2019-05-26 20:41:28,444 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204128423291
2019-05-26 20:41:28,475 [salt.minion      :1432][INFO    ][35935] Starting a new job with PID 35935
2019-05-26 20:41:28,506 [salt.minion      :1711][INFO    ][35935] Returning information for job: 20190526204128423291
2019-05-26 20:41:41,583 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2049.37351298s left)
2019-05-26 20:41:58,543 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204158529575
2019-05-26 20:41:58,566 [salt.minion      :1432][INFO    ][35994] Starting a new job with PID 35994
2019-05-26 20:41:58,596 [salt.minion      :1711][INFO    ][35994] Returning information for job: 20190526204158529575
2019-05-26 20:42:14,532 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2016.42507887s left)
2019-05-26 20:42:28,649 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204228639750
2019-05-26 20:42:28,673 [salt.minion      :1432][INFO    ][36291] Starting a new job with PID 36291
2019-05-26 20:42:28,705 [salt.minion      :1711][INFO    ][36291] Returning information for job: 20190526204228639750
2019-05-26 20:42:47,602 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1983.35452986s left)
2019-05-26 20:42:58,762 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204258749435
2019-05-26 20:42:58,792 [salt.minion      :1432][INFO    ][36394] Starting a new job with PID 36394
2019-05-26 20:42:58,826 [salt.minion      :1711][INFO    ][36394] Returning information for job: 20190526204258749435
2019-05-26 20:43:20,647 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1950.31006694s left)
2019-05-26 20:43:28,939 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204328924677
2019-05-26 20:43:28,967 [salt.minion      :1432][INFO    ][36737] Starting a new job with PID 36737
2019-05-26 20:43:29,005 [salt.minion      :1711][INFO    ][36737] Returning information for job: 20190526204328924677
2019-05-26 20:43:53,743 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1917.21341991s left)
2019-05-26 20:43:59,081 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204359067976
2019-05-26 20:43:59,111 [salt.minion      :1432][INFO    ][36770] Starting a new job with PID 36770
2019-05-26 20:43:59,143 [salt.minion      :1711][INFO    ][36770] Returning information for job: 20190526204359067976
2019-05-26 20:44:26,655 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1884.30180502s left)
2019-05-26 20:44:29,268 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204429251944
2019-05-26 20:44:29,296 [salt.minion      :1432][INFO    ][37125] Starting a new job with PID 37125
2019-05-26 20:44:29,324 [salt.minion      :1711][INFO    ][37125] Returning information for job: 20190526204429251944
2019-05-26 20:44:59,397 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204459386997
2019-05-26 20:44:59,419 [salt.minion      :1432][INFO    ][37173] Starting a new job with PID 37173
2019-05-26 20:44:59,452 [salt.minion      :1711][INFO    ][37173] Returning information for job: 20190526204459386997
2019-05-26 20:44:59,521 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1851.4357419s left)
2019-05-26 20:45:29,583 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204529567632
2019-05-26 20:45:29,605 [salt.minion      :1432][INFO    ][37414] Starting a new job with PID 37414
2019-05-26 20:45:29,636 [salt.minion      :1711][INFO    ][37414] Returning information for job: 20190526204529567632
2019-05-26 20:45:32,464 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1818.49222994s left)
2019-05-26 20:45:59,729 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204559718264
2019-05-26 20:45:59,761 [salt.minion      :1432][INFO    ][37444] Starting a new job with PID 37444
2019-05-26 20:45:59,788 [salt.minion      :1711][INFO    ][37444] Returning information for job: 20190526204559718264
2019-05-26 20:46:05,927 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1785.02920794s left)
2019-05-26 20:46:29,939 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204629926944
2019-05-26 20:46:29,968 [salt.minion      :1432][INFO    ][37743] Starting a new job with PID 37743
2019-05-26 20:46:29,997 [salt.minion      :1711][INFO    ][37743] Returning information for job: 20190526204629926944
2019-05-26 20:46:38,832 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1752.12426782s left)
2019-05-26 20:47:00,119 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204700101533
2019-05-26 20:47:00,144 [salt.minion      :1432][INFO    ][37772] Starting a new job with PID 37772
2019-05-26 20:47:00,175 [salt.minion      :1711][INFO    ][37772] Returning information for job: 20190526204700101533
2019-05-26 20:47:11,707 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1719.25012684s left)
2019-05-26 20:47:30,308 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204730298815
2019-05-26 20:47:30,330 [salt.minion      :1432][INFO    ][37962] Starting a new job with PID 37962
2019-05-26 20:47:30,365 [salt.minion      :1711][INFO    ][37962] Returning information for job: 20190526204730298815
2019-05-26 20:47:44,583 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1686.37563801s left)
2019-05-26 20:48:00,367 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204800350370
2019-05-26 20:48:00,396 [salt.minion      :1432][INFO    ][38006] Starting a new job with PID 38006
2019-05-26 20:48:00,424 [salt.minion      :1711][INFO    ][38006] Returning information for job: 20190526204800350370
2019-05-26 20:48:17,543 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1653.41346097s left)
2019-05-26 20:48:30,501 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204830487170
2019-05-26 20:48:30,529 [salt.minion      :1432][INFO    ][38202] Starting a new job with PID 38202
2019-05-26 20:48:30,560 [salt.minion      :1711][INFO    ][38202] Returning information for job: 20190526204830487170
2019-05-26 20:48:50,381 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1620.57602787s left)
2019-05-26 20:49:00,684 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204900674437
2019-05-26 20:49:00,708 [salt.minion      :1432][INFO    ][38232] Starting a new job with PID 38232
2019-05-26 20:49:00,740 [salt.minion      :1711][INFO    ][38232] Returning information for job: 20190526204900674437
2019-05-26 20:49:23,346 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1587.61077285s left)
2019-05-26 20:49:30,895 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526204930879218
2019-05-26 20:49:30,920 [salt.minion      :1432][INFO    ][38399] Starting a new job with PID 38399
2019-05-26 20:49:30,951 [salt.minion      :1711][INFO    ][38399] Returning information for job: 20190526204930879218
2019-05-26 20:49:56,333 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1554.62374997s left)
2019-05-26 20:50:01,087 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205001072780
2019-05-26 20:50:01,114 [salt.minion      :1432][INFO    ][38562] Starting a new job with PID 38562
2019-05-26 20:50:01,143 [salt.minion      :1711][INFO    ][38562] Returning information for job: 20190526205001072780
2019-05-26 20:50:29,360 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1521.59628201s left)
2019-05-26 20:50:31,294 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205031280533
2019-05-26 20:50:31,321 [salt.minion      :1432][INFO    ][38667] Starting a new job with PID 38667
2019-05-26 20:50:31,355 [salt.minion      :1711][INFO    ][38667] Returning information for job: 20190526205031280533
2019-05-26 20:51:01,423 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205101409134
2019-05-26 20:51:01,443 [salt.minion      :1432][INFO    ][38729] Starting a new job with PID 38729
2019-05-26 20:51:01,474 [salt.minion      :1711][INFO    ][38729] Returning information for job: 20190526205101409134
2019-05-26 20:51:02,525 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1488.43163085s left)
2019-05-26 20:51:31,465 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205131456283
2019-05-26 20:51:31,492 [salt.minion      :1432][INFO    ][38964] Starting a new job with PID 38964
2019-05-26 20:51:31,526 [salt.minion      :1711][INFO    ][38964] Returning information for job: 20190526205131456283
2019-05-26 20:51:35,652 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1455.30476999s left)
2019-05-26 20:52:01,493 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205201480634
2019-05-26 20:52:01,521 [salt.minion      :1432][INFO    ][38992] Starting a new job with PID 38992
2019-05-26 20:52:01,551 [salt.minion      :1711][INFO    ][38992] Returning information for job: 20190526205201480634
2019-05-26 20:52:08,788 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1422.16903591s left)
2019-05-26 20:52:31,536 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205231522788
2019-05-26 20:52:31,564 [salt.minion      :1432][INFO    ][39101] Starting a new job with PID 39101
2019-05-26 20:52:31,604 [salt.minion      :1711][INFO    ][39101] Returning information for job: 20190526205231522788
2019-05-26 20:52:41,836 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1389.12087083s left)
2019-05-26 20:53:01,608 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205301590262
2019-05-26 20:53:01,640 [salt.minion      :1432][INFO    ][39136] Starting a new job with PID 39136
2019-05-26 20:53:01,676 [salt.minion      :1711][INFO    ][39136] Returning information for job: 20190526205301590262
2019-05-26 20:53:14,571 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1356.38576102s left)
2019-05-26 20:53:31,677 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205331664174
2019-05-26 20:53:31,708 [salt.minion      :1432][INFO    ][39183] Starting a new job with PID 39183
2019-05-26 20:53:31,739 [salt.minion      :1711][INFO    ][39183] Returning information for job: 20190526205331664174
2019-05-26 20:53:47,533 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1323.42407584s left)
2019-05-26 20:54:01,758 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205401745535
2019-05-26 20:54:01,781 [salt.minion      :1432][INFO    ][39212] Starting a new job with PID 39212
2019-05-26 20:54:01,808 [salt.minion      :1711][INFO    ][39212] Returning information for job: 20190526205401745535
2019-05-26 20:54:20,300 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1290.65668988s left)
2019-05-26 20:54:31,837 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205431824856
2019-05-26 20:54:31,867 [salt.minion      :1432][INFO    ][39257] Starting a new job with PID 39257
2019-05-26 20:54:31,896 [salt.minion      :1711][INFO    ][39257] Returning information for job: 20190526205431824856
2019-05-26 20:54:53,115 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1257.84147882s left)
2019-05-26 20:55:01,944 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205501927556
2019-05-26 20:55:01,977 [salt.minion      :1432][INFO    ][39293] Starting a new job with PID 39293
2019-05-26 20:55:02,013 [salt.minion      :1711][INFO    ][39293] Returning information for job: 20190526205501927556
2019-05-26 20:55:25,981 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1224.97591901s left)
2019-05-26 20:55:32,065 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205532048521
2019-05-26 20:55:32,094 [salt.minion      :1432][INFO    ][39339] Starting a new job with PID 39339
2019-05-26 20:55:32,130 [salt.minion      :1711][INFO    ][39339] Returning information for job: 20190526205532048521
2019-05-26 20:55:58,841 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1192.11585784s left)
2019-05-26 20:56:02,184 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205602171074
2019-05-26 20:56:02,213 [salt.minion      :1432][INFO    ][39367] Starting a new job with PID 39367
2019-05-26 20:56:02,241 [salt.minion      :1711][INFO    ][39367] Returning information for job: 20190526205602171074
2019-05-26 20:56:31,728 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1159.22853684s left)
2019-05-26 20:56:32,277 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205632266370
2019-05-26 20:56:32,302 [salt.minion      :1432][INFO    ][39412] Starting a new job with PID 39412
2019-05-26 20:56:32,334 [salt.minion      :1711][INFO    ][39412] Returning information for job: 20190526205632266370
2019-05-26 20:57:02,432 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205702418653
2019-05-26 20:57:02,456 [salt.minion      :1432][INFO    ][39438] Starting a new job with PID 39438
2019-05-26 20:57:02,490 [salt.minion      :1711][INFO    ][39438] Returning information for job: 20190526205702418653
2019-05-26 20:57:04,613 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1126.34389186s left)
2019-05-26 20:57:32,583 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205732568797
2019-05-26 20:57:32,609 [salt.minion      :1432][INFO    ][39481] Starting a new job with PID 39481
2019-05-26 20:57:32,641 [salt.minion      :1711][INFO    ][39481] Returning information for job: 20190526205732568797
2019-05-26 20:57:37,333 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1093.62367201s left)
2019-05-26 20:58:02,777 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205802760592
2019-05-26 20:58:02,807 [salt.minion      :1432][INFO    ][39510] Starting a new job with PID 39510
2019-05-26 20:58:02,838 [salt.minion      :1711][INFO    ][39510] Returning information for job: 20190526205802760592
2019-05-26 20:58:10,207 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1060.74961782s left)
2019-05-26 20:58:32,946 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205832929519
2019-05-26 20:58:32,974 [salt.minion      :1432][INFO    ][39555] Starting a new job with PID 39555
2019-05-26 20:58:33,005 [salt.minion      :1711][INFO    ][39555] Returning information for job: 20190526205832929519
2019-05-26 20:58:42,921 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1028.03556681s left)
2019-05-26 20:59:03,157 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205903141255
2019-05-26 20:59:03,197 [salt.minion      :1432][INFO    ][39584] Starting a new job with PID 39584
2019-05-26 20:59:03,234 [salt.minion      :1711][INFO    ][39584] Returning information for job: 20190526205903141255
2019-05-26 20:59:15,711 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (995.245563984s left)
2019-05-26 20:59:33,384 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526205933372032
2019-05-26 20:59:33,409 [salt.minion      :1432][INFO    ][39632] Starting a new job with PID 39632
2019-05-26 20:59:33,445 [salt.minion      :1711][INFO    ][39632] Returning information for job: 20190526205933372032
2019-05-26 20:59:48,573 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (962.383268833s left)
2019-05-26 21:00:03,605 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210003591870
2019-05-26 21:00:03,634 [salt.minion      :1432][INFO    ][39676] Starting a new job with PID 39676
2019-05-26 21:00:03,671 [salt.minion      :1711][INFO    ][39676] Returning information for job: 20190526210003591870
2019-05-26 21:00:21,323 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (929.633773804s left)
2019-05-26 21:00:33,667 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210033648597
2019-05-26 21:00:33,694 [salt.minion      :1432][INFO    ][39735] Starting a new job with PID 39735
2019-05-26 21:00:33,730 [salt.minion      :1711][INFO    ][39735] Returning information for job: 20190526210033648597
2019-05-26 21:00:54,297 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (896.659837008s left)
2019-05-26 21:01:03,709 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210103693644
2019-05-26 21:01:03,737 [salt.minion      :1432][INFO    ][39767] Starting a new job with PID 39767
2019-05-26 21:01:03,769 [salt.minion      :1711][INFO    ][39767] Returning information for job: 20190526210103693644
2019-05-26 21:01:26,974 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (863.982910872s left)
2019-05-26 21:01:33,763 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210133748312
2019-05-26 21:01:33,790 [salt.minion      :1432][INFO    ][39818] Starting a new job with PID 39818
2019-05-26 21:01:33,821 [salt.minion      :1711][INFO    ][39818] Returning information for job: 20190526210133748312
2019-05-26 21:01:59,793 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (831.164103985s left)
2019-05-26 21:02:03,847 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210203830707
2019-05-26 21:02:03,874 [salt.minion      :1432][INFO    ][39847] Starting a new job with PID 39847
2019-05-26 21:02:03,904 [salt.minion      :1711][INFO    ][39847] Returning information for job: 20190526210203830707
2019-05-26 21:02:32,676 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (798.280943871s left)
2019-05-26 21:02:33,949 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210233932619
2019-05-26 21:02:33,977 [salt.minion      :1432][INFO    ][39897] Starting a new job with PID 39897
2019-05-26 21:02:34,007 [salt.minion      :1711][INFO    ][39897] Returning information for job: 20190526210233932619
2019-05-26 21:03:04,063 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210304049066
2019-05-26 21:03:04,083 [salt.minion      :1432][INFO    ][39924] Starting a new job with PID 39924
2019-05-26 21:03:04,114 [salt.minion      :1711][INFO    ][39924] Returning information for job: 20190526210304049066
2019-05-26 21:03:05,436 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (765.520491838s left)
2019-05-26 21:03:34,192 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210334178219
2019-05-26 21:03:34,222 [salt.minion      :1432][INFO    ][39969] Starting a new job with PID 39969
2019-05-26 21:03:34,263 [salt.minion      :1711][INFO    ][39969] Returning information for job: 20190526210334178219
2019-05-26 21:03:38,240 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (732.717064857s left)
2019-05-26 21:04:04,384 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210404367685
2019-05-26 21:04:04,411 [salt.minion      :1432][INFO    ][40001] Starting a new job with PID 40001
2019-05-26 21:04:04,444 [salt.minion      :1711][INFO    ][40001] Returning information for job: 20190526210404367685
2019-05-26 21:04:11,095 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (699.861258984s left)
2019-05-26 21:04:34,567 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210434555501
2019-05-26 21:04:34,596 [salt.minion      :1432][INFO    ][40051] Starting a new job with PID 40051
2019-05-26 21:04:34,631 [salt.minion      :1711][INFO    ][40051] Returning information for job: 20190526210434555501
2019-05-26 21:04:43,852 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (667.104928017s left)
2019-05-26 21:05:04,704 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210504696356
2019-05-26 21:05:04,733 [salt.minion      :1432][INFO    ][40081] Starting a new job with PID 40081
2019-05-26 21:05:04,761 [salt.minion      :1711][INFO    ][40081] Returning information for job: 20190526210504696356
2019-05-26 21:05:16,732 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (634.225044966s left)
2019-05-26 21:05:34,929 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210534915061
2019-05-26 21:05:34,956 [salt.minion      :1432][INFO    ][40127] Starting a new job with PID 40127
2019-05-26 21:05:34,987 [salt.minion      :1711][INFO    ][40127] Returning information for job: 20190526210534915061
2019-05-26 21:05:49,680 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (601.276576996s left)
2019-05-26 21:06:05,152 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210605143704
2019-05-26 21:06:05,172 [salt.minion      :1432][INFO    ][40159] Starting a new job with PID 40159
2019-05-26 21:06:05,208 [salt.minion      :1711][INFO    ][40159] Returning information for job: 20190526210605143704
2019-05-26 21:06:22,446 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (568.510264874s left)
2019-05-26 21:06:35,178 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210635160346
2019-05-26 21:06:35,201 [salt.minion      :1432][INFO    ][40210] Starting a new job with PID 40210
2019-05-26 21:06:35,240 [salt.minion      :1711][INFO    ][40210] Returning information for job: 20190526210635160346
2019-05-26 21:06:55,272 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (535.684332848s left)
2019-05-26 21:07:05,238 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210705225183
2019-05-26 21:07:05,267 [salt.minion      :1432][INFO    ][40244] Starting a new job with PID 40244
2019-05-26 21:07:05,313 [salt.minion      :1711][INFO    ][40244] Returning information for job: 20190526210705225183
2019-05-26 21:07:27,963 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (502.993785858s left)
2019-05-26 21:07:35,293 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210735278330
2019-05-26 21:07:35,317 [salt.minion      :1432][INFO    ][40286] Starting a new job with PID 40286
2019-05-26 21:07:35,352 [salt.minion      :1711][INFO    ][40286] Returning information for job: 20190526210735278330
2019-05-26 21:08:00,676 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (470.280910969s left)
2019-05-26 21:08:05,384 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210805369594
2019-05-26 21:08:05,407 [salt.minion      :1432][INFO    ][40327] Starting a new job with PID 40327
2019-05-26 21:08:05,439 [salt.minion      :1711][INFO    ][40327] Returning information for job: 20190526210805369594
2019-05-26 21:08:33,463 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (437.49323988s left)
2019-05-26 21:08:35,492 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210835479209
2019-05-26 21:08:35,517 [salt.minion      :1432][INFO    ][40364] Starting a new job with PID 40364
2019-05-26 21:08:35,545 [salt.minion      :1711][INFO    ][40364] Returning information for job: 20190526210835479209
2019-05-26 21:09:05,679 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210905667336
2019-05-26 21:09:05,697 [salt.minion      :1432][INFO    ][40405] Starting a new job with PID 40405
2019-05-26 21:09:05,730 [salt.minion      :1711][INFO    ][40405] Returning information for job: 20190526210905667336
2019-05-26 21:09:06,431 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (404.525473833s left)
2019-05-26 21:09:35,794 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526210935778632
2019-05-26 21:09:35,820 [salt.minion      :1432][INFO    ][40438] Starting a new job with PID 40438
2019-05-26 21:09:35,847 [salt.minion      :1711][INFO    ][40438] Returning information for job: 20190526210935778632
2019-05-26 21:09:39,197 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (371.759420872s left)
2019-05-26 21:10:05,986 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211005977342
2019-05-26 21:10:06,009 [salt.minion      :1432][INFO    ][40635] Starting a new job with PID 40635
2019-05-26 21:10:06,040 [salt.minion      :1711][INFO    ][40635] Returning information for job: 20190526211005977342
2019-05-26 21:10:12,184 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (338.77244997s left)
2019-05-26 21:10:36,155 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211036138707
2019-05-26 21:10:36,188 [salt.minion      :1432][INFO    ][40811] Starting a new job with PID 40811
2019-05-26 21:10:36,219 [salt.minion      :1711][INFO    ][40811] Returning information for job: 20190526211036138707
2019-05-26 21:10:44,916 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (306.04031682s left)
2019-05-26 21:11:06,341 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211106329403
2019-05-26 21:11:06,371 [salt.minion      :1432][INFO    ][40868] Starting a new job with PID 40868
2019-05-26 21:11:06,411 [salt.minion      :1711][INFO    ][40868] Returning information for job: 20190526211106329403
2019-05-26 21:11:17,651 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (273.30518198s left)
2019-05-26 21:11:36,377 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211136363390
2019-05-26 21:11:36,396 [salt.minion      :1432][INFO    ][40889] Starting a new job with PID 40889
2019-05-26 21:11:36,425 [salt.minion      :1711][INFO    ][40889] Returning information for job: 20190526211136363390
2019-05-26 21:11:50,452 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (240.504348993s left)
2019-05-26 21:12:06,408 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211206396612
2019-05-26 21:12:06,435 [salt.minion      :1432][INFO    ][40946] Starting a new job with PID 40946
2019-05-26 21:12:06,468 [salt.minion      :1711][INFO    ][40946] Returning information for job: 20190526211206396612
2019-05-26 21:12:23,305 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (207.651592016s left)
2019-05-26 21:12:36,512 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211236497895
2019-05-26 21:12:36,534 [salt.minion      :1432][INFO    ][40973] Starting a new job with PID 40973
2019-05-26 21:12:36,565 [salt.minion      :1711][INFO    ][40973] Returning information for job: 20190526211236497895
2019-05-26 21:12:56,112 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (174.844249964s left)
2019-05-26 21:13:06,564 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211306551276
2019-05-26 21:13:06,594 [salt.minion      :1432][INFO    ][41030] Starting a new job with PID 41030
2019-05-26 21:13:06,628 [salt.minion      :1711][INFO    ][41030] Returning information for job: 20190526211306551276
2019-05-26 21:13:28,952 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (142.005051851s left)
2019-05-26 21:13:36,700 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211336690530
2019-05-26 21:13:36,726 [salt.minion      :1432][INFO    ][41052] Starting a new job with PID 41052
2019-05-26 21:13:36,760 [salt.minion      :1711][INFO    ][41052] Returning information for job: 20190526211336690530
2019-05-26 21:14:01,689 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (109.267591s left)
2019-05-26 21:14:06,865 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211406855053
2019-05-26 21:14:06,892 [salt.minion      :1432][INFO    ][41115] Starting a new job with PID 41115
2019-05-26 21:14:06,927 [salt.minion      :1711][INFO    ][41115] Returning information for job: 20190526211406855053
2019-05-26 21:14:34,421 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (76.5358579159s left)
2019-05-26 21:14:37,041 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211437028684
2019-05-26 21:14:37,068 [salt.minion      :1432][INFO    ][41137] Starting a new job with PID 41137
2019-05-26 21:14:37,103 [salt.minion      :1711][INFO    ][41137] Returning information for job: 20190526211437028684
2019-05-26 21:15:07,104 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211507095169
2019-05-26 21:15:07,129 [salt.minion      :1432][INFO    ][41192] Starting a new job with PID 41192
2019-05-26 21:15:07,165 [salt.minion      :1711][INFO    ][41192] Returning information for job: 20190526211507095169
2019-05-26 21:15:07,576 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (43.3804678917s left)
2019-05-26 21:15:37,128 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211537112151
2019-05-26 21:15:37,155 [salt.minion      :1432][INFO    ][41207] Starting a new job with PID 41207
2019-05-26 21:15:37,188 [salt.minion      :1711][INFO    ][41207] Returning information for job: 20190526211537112151
2019-05-26 21:15:40,428 [salt.loaded.ext.module.maas:1023][INFO    ][35527] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (10.5286128521s left)
2019-05-26 21:16:07,244 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211607232563
2019-05-26 21:16:07,276 [salt.minion      :1432][INFO    ][41265] Starting a new job with PID 41265
2019-05-26 21:16:07,308 [salt.minion      :1711][INFO    ][41265] Returning information for job: 20190526211607232563
2019-05-26 21:16:13,246 [salt.state       :302 ][ERROR   ][35527] Module function maas.wait_for_machine_status threw an exception. Exception: Machines:['kvm02']not in Deployed state
2019-05-26 21:16:13,247 [salt.state       :1951][INFO    ][35527] Completed state [maas.wait_for_machine_status] at time 21:16:13.247515 duration_in_ms=2272304.143
2019-05-26 21:16:13,255 [salt.minion      :1711][INFO    ][35527] Returning information for job: 20190526203812847291
2019-05-26 21:16:24,261 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command pillar.get with jid 20190526211624247908
2019-05-26 21:16:24,293 [salt.minion      :1432][INFO    ][41286] Starting a new job with PID 41286
2019-05-26 21:16:24,304 [salt.minion      :1711][INFO    ][41286] Returning information for job: 20190526211624247908
2019-05-26 21:16:25,018 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command service.status with jid 20190526211625000206
2019-05-26 21:16:25,045 [salt.minion      :1432][INFO    ][41291] Starting a new job with PID 41291
2019-05-26 21:16:25,826 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][41291] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-26 21:16:25,873 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][41291] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-26 21:16:25,895 [salt.minion      :1711][INFO    ][41291] Returning information for job: 20190526211625000206
2019-05-26 21:16:26,612 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526211626602613
2019-05-26 21:16:26,638 [salt.minion      :1432][INFO    ][41302] Starting a new job with PID 41302
2019-05-26 21:16:32,646 [salt.state       :915 ][INFO    ][41302] Loading fresh modules for state activity
2019-05-26 21:16:33,325 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command 'salt-minion --version' in directory '/root'
2019-05-26 21:16:33,690 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command 'salt-minion --version' in directory '/root'
2019-05-26 21:16:34,786 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command 'salt-minion --version' in directory '/root'
2019-05-26 21:16:35,135 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command 'salt-minion --version' in directory '/root'
2019-05-26 21:16:37,452 [salt.state       :1780][INFO    ][41302] Running state [salt-minion] at time 21:16:37.452457
2019-05-26 21:16:37,452 [salt.state       :1813][INFO    ][41302] Executing state pkg.installed for [salt-minion]
2019-05-26 21:16:37,454 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-26 21:16:37,588 [salt.state       :300 ][INFO    ][41302] All specified packages are already installed
2019-05-26 21:16:37,588 [salt.state       :1951][INFO    ][41302] Completed state [salt-minion] at time 21:16:37.588533 duration_in_ms=136.076
2019-05-26 21:16:37,588 [salt.state       :1780][INFO    ][41302] Running state [salt_minion_dependency_packages] at time 21:16:37.588910
2019-05-26 21:16:37,589 [salt.state       :1813][INFO    ][41302] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-26 21:16:37,599 [salt.state       :300 ][INFO    ][41302] All specified packages are already installed
2019-05-26 21:16:37,599 [salt.state       :1951][INFO    ][41302] Completed state [salt_minion_dependency_packages] at time 21:16:37.599243 duration_in_ms=10.333
2019-05-26 21:16:37,602 [salt.state       :1780][INFO    ][41302] Running state [/etc/salt/minion.d/minion.conf] at time 21:16:37.602529
2019-05-26 21:16:37,602 [salt.state       :1813][INFO    ][41302] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-26 21:16:37,905 [salt.state       :300 ][INFO    ][41302] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-26 21:16:37,905 [salt.state       :1951][INFO    ][41302] Completed state [/etc/salt/minion.d/minion.conf] at time 21:16:37.905509 duration_in_ms=302.98
2019-05-26 21:16:37,906 [salt.state       :1780][INFO    ][41302] Running state [python-netaddr] at time 21:16:37.906142
2019-05-26 21:16:37,906 [salt.state       :1813][INFO    ][41302] Executing state pkg.installed for [python-netaddr]
2019-05-26 21:16:37,916 [salt.state       :300 ][INFO    ][41302] All specified packages are already installed
2019-05-26 21:16:37,916 [salt.state       :1951][INFO    ][41302] Completed state [python-netaddr] at time 21:16:37.916626 duration_in_ms=10.484
2019-05-26 21:16:37,920 [salt.state       :1780][INFO    ][41302] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:16:37.920263
2019-05-26 21:16:37,920 [salt.state       :1813][INFO    ][41302] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-26 21:16:37,939 [salt.state       :300 ][INFO    ][41302] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-26 21:16:37,939 [salt.state       :1951][INFO    ][41302] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 21:16:37.939833 duration_in_ms=19.57
2019-05-26 21:16:37,941 [salt.state       :1780][INFO    ][41302] Running state [salt-minion] at time 21:16:37.941197
2019-05-26 21:16:37,941 [salt.state       :1813][INFO    ][41302] Executing state service.running for [salt-minion]
2019-05-26 21:16:37,943 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-26 21:16:37,989 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-26 21:16:38,011 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-26 21:16:38,035 [salt.state       :300 ][INFO    ][41302] The service salt-minion is already running
2019-05-26 21:16:38,036 [salt.state       :1951][INFO    ][41302] Completed state [salt-minion] at time 21:16:38.036115 duration_in_ms=94.917
2019-05-26 21:16:38,038 [salt.state       :1780][INFO    ][41302] Running state [/etc/salt/grains.d] at time 21:16:38.038712
2019-05-26 21:16:38,039 [salt.state       :1813][INFO    ][41302] Executing state file.directory for [/etc/salt/grains.d]
2019-05-26 21:16:38,041 [salt.state       :300 ][INFO    ][41302] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-26 21:16:38,041 [salt.state       :1951][INFO    ][41302] Completed state [/etc/salt/grains.d] at time 21:16:38.041465 duration_in_ms=2.752
2019-05-26 21:16:38,044 [salt.state       :1780][INFO    ][41302] Running state [/etc/salt/grains] at time 21:16:38.044430
2019-05-26 21:16:38,044 [salt.state       :1813][INFO    ][41302] Executing state file.managed for [/etc/salt/grains]
2019-05-26 21:16:38,045 [salt.state       :300 ][INFO    ][41302] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-26 21:16:38,046 [salt.state       :1951][INFO    ][41302] Completed state [/etc/salt/grains] at time 21:16:38.046140 duration_in_ms=1.71
2019-05-26 21:16:38,046 [salt.state       :1780][INFO    ][41302] Running state [/etc/salt/grains.d/placeholder] at time 21:16:38.046749
2019-05-26 21:16:38,047 [salt.state       :1813][INFO    ][41302] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-26 21:16:38,047 [salt.state       :300 ][INFO    ][41302] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-26 21:16:38,048 [salt.state       :1951][INFO    ][41302] Completed state [/etc/salt/grains.d/placeholder] at time 21:16:38.048063 duration_in_ms=1.314
2019-05-26 21:16:38,048 [salt.state       :1780][INFO    ][41302] Running state [/etc/salt/grains.d/sphinx] at time 21:16:38.048668
2019-05-26 21:16:38,049 [salt.state       :1813][INFO    ][41302] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-26 21:16:38,051 [salt.state       :300 ][INFO    ][41302] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-26 21:16:38,051 [salt.state       :1951][INFO    ][41302] Completed state [/etc/salt/grains.d/sphinx] at time 21:16:38.051528 duration_in_ms=2.859
2019-05-26 21:16:38,057 [salt.state       :1780][INFO    ][41302] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:16:38.057808
2019-05-26 21:16:38,058 [salt.state       :1813][INFO    ][41302] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-26 21:16:38,058 [salt.state       :300 ][INFO    ][41302] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-26 21:16:38,059 [salt.state       :1951][INFO    ][41302] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 21:16:38.059183 duration_in_ms=1.374
2019-05-26 21:16:38,060 [salt.state       :1780][INFO    ][41302] Running state [/etc/salt/grains.d/dns_records] at time 21:16:38.060114
2019-05-26 21:16:38,060 [salt.state       :1813][INFO    ][41302] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-26 21:16:38,062 [salt.state       :300 ][INFO    ][41302] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-26 21:16:38,063 [salt.state       :1951][INFO    ][41302] Completed state [/etc/salt/grains.d/dns_records] at time 21:16:38.063169 duration_in_ms=3.055
2019-05-26 21:16:38,064 [salt.state       :1780][INFO    ][41302] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:16:38.064632
2019-05-26 21:16:38,065 [salt.state       :1813][INFO    ][41302] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-05-26 21:16:38,065 [salt.state       :300 ][INFO    ][41302] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-26 21:16:38,067 [salt.state       :1951][INFO    ][41302] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 21:16:38.067820 duration_in_ms=3.188
2019-05-26 21:16:38,068 [salt.state       :1780][INFO    ][41302] Running state [/etc/salt/grains.d/salt] at time 21:16:38.068515
2019-05-26 21:16:38,068 [salt.state       :1813][INFO    ][41302] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-26 21:16:38,070 [salt.state       :300 ][INFO    ][41302] File /etc/salt/grains.d/salt is in the correct state
2019-05-26 21:16:38,071 [salt.state       :1951][INFO    ][41302] Completed state [/etc/salt/grains.d/salt] at time 21:16:38.071459 duration_in_ms=2.943
2019-05-26 21:16:38,073 [salt.state       :1780][INFO    ][41302] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:16:38.073496
2019-05-26 21:16:38,074 [salt.state       :1813][INFO    ][41302] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-26 21:16:38,074 [salt.state       :300 ][INFO    ][41302] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-26 21:16:38,075 [salt.state       :1951][INFO    ][41302] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 21:16:38.075283 duration_in_ms=1.788
2019-05-26 21:16:38,080 [salt.state       :1780][INFO    ][41302] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:16:38.080200
2019-05-26 21:16:38,080 [salt.state       :1813][INFO    ][41302] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-26 21:16:38,080 [salt.state       :300 ][INFO    ][41302] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-26 21:16:38,081 [salt.state       :1951][INFO    ][41302] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 21:16:38.081054 duration_in_ms=0.854
2019-05-26 21:16:38,082 [salt.state       :1780][INFO    ][41302] Running state [mine.update] at time 21:16:38.082102
2019-05-26 21:16:38,082 [salt.state       :1813][INFO    ][41302] Executing state module.wait for [mine.update]
2019-05-26 21:16:38,082 [salt.state       :300 ][INFO    ][41302] No changes made for mine.update
2019-05-26 21:16:38,082 [salt.state       :1951][INFO    ][41302] Completed state [mine.update] at time 21:16:38.082888 duration_in_ms=0.785
2019-05-26 21:16:38,083 [salt.state       :1780][INFO    ][41302] Running state [ca-certificates] at time 21:16:38.083166
2019-05-26 21:16:38,083 [salt.state       :1813][INFO    ][41302] Executing state pkg.installed for [ca-certificates]
2019-05-26 21:16:38,093 [salt.state       :300 ][INFO    ][41302] All specified packages are already installed
2019-05-26 21:16:38,094 [salt.state       :1951][INFO    ][41302] Completed state [ca-certificates] at time 21:16:38.094008 duration_in_ms=10.842
2019-05-26 21:16:38,094 [salt.state       :1780][INFO    ][41302] Running state [update-ca-certificates] at time 21:16:38.094731
2019-05-26 21:16:38,095 [salt.state       :1813][INFO    ][41302] Executing state cmd.wait for [update-ca-certificates]
2019-05-26 21:16:38,095 [salt.state       :300 ][INFO    ][41302] No changes made for update-ca-certificates
2019-05-26 21:16:38,095 [salt.state       :1951][INFO    ][41302] Completed state [update-ca-certificates] at time 21:16:38.095554 duration_in_ms=0.823
2019-05-26 21:16:38,095 [salt.state       :1780][INFO    ][41302] Running state [iptables] at time 21:16:38.095832
2019-05-26 21:16:38,096 [salt.state       :1813][INFO    ][41302] Executing state pkg.installed for [iptables]
2019-05-26 21:16:38,105 [salt.state       :300 ][INFO    ][41302] All specified packages are already installed
2019-05-26 21:16:38,106 [salt.state       :1951][INFO    ][41302] Completed state [iptables] at time 21:16:38.106019 duration_in_ms=10.187
2019-05-26 21:16:38,106 [salt.state       :1780][INFO    ][41302] Running state [iptables-persistent] at time 21:16:38.106417
2019-05-26 21:16:38,106 [salt.state       :1813][INFO    ][41302] Executing state pkg.installed for [iptables-persistent]
2019-05-26 21:16:38,120 [salt.state       :300 ][INFO    ][41302] All specified packages are already installed
2019-05-26 21:16:38,120 [salt.state       :1951][INFO    ][41302] Completed state [iptables-persistent] at time 21:16:38.120442 duration_in_ms=14.026
2019-05-26 21:16:38,122 [salt.state       :1780][INFO    ][41302] Running state [iptables_modules_v4_load] at time 21:16:38.122411
2019-05-26 21:16:38,122 [salt.state       :1813][INFO    ][41302] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-26 21:16:38,123 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command 'lsmod' in directory '/root'
2019-05-26 21:16:38,152 [salt.state       :300 ][INFO    ][41302] Kernel modules iptable_filter, ip_tables are already present
2019-05-26 21:16:38,152 [salt.state       :1951][INFO    ][41302] Completed state [iptables_modules_v4_load] at time 21:16:38.152822 duration_in_ms=30.411
2019-05-26 21:16:38,154 [salt.state       :1780][INFO    ][41302] Running state [/etc/iptables/rules.v4] at time 21:16:38.154597
2019-05-26 21:16:38,155 [salt.state       :1813][INFO    ][41302] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-26 21:16:38,262 [salt.state       :300 ][INFO    ][41302] File /etc/iptables/rules.v4 is in the correct state
2019-05-26 21:16:38,263 [salt.state       :1951][INFO    ][41302] Completed state [/etc/iptables/rules.v4] at time 21:16:38.262937 duration_in_ms=108.34
2019-05-26 21:16:38,264 [salt.state       :1780][INFO    ][41302] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:16:38.264130
2019-05-26 21:16:38,264 [salt.state       :1813][INFO    ][41302] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-26 21:16:38,265 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-26 21:16:38,292 [salt.state       :300 ][INFO    ][41302] onlyif execution failed
2019-05-26 21:16:38,293 [salt.state       :1951][INFO    ][41302] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 21:16:38.292852 duration_in_ms=28.72
2019-05-26 21:16:38,297 [salt.state       :1780][INFO    ][41302] Running state [netfilter-persistent] at time 21:16:38.297150
2019-05-26 21:16:38,298 [salt.state       :1813][INFO    ][41302] Executing state service.running for [netfilter-persistent]
2019-05-26 21:16:38,299 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-26 21:16:38,325 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-26 21:16:38,350 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-26 21:16:38,373 [salt.state       :300 ][INFO    ][41302] The service netfilter-persistent is already running
2019-05-26 21:16:38,374 [salt.state       :1951][INFO    ][41302] Completed state [netfilter-persistent] at time 21:16:38.374194 duration_in_ms=77.044
2019-05-26 21:16:38,375 [salt.state       :1780][INFO    ][41302] Running state [iptables_extra.remove_stale_tables] at time 21:16:38.375674
2019-05-26 21:16:38,376 [salt.state       :1813][INFO    ][41302] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-26 21:16:38,376 [salt.state       :300 ][INFO    ][41302] No changes made for iptables_extra.remove_stale_tables
2019-05-26 21:16:38,377 [salt.state       :1951][INFO    ][41302] Completed state [iptables_extra.remove_stale_tables] at time 21:16:38.377132 duration_in_ms=1.458
2019-05-26 21:16:38,377 [salt.state       :1780][INFO    ][41302] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:16:38.377591
2019-05-26 21:16:38,379 [salt.state       :1813][INFO    ][41302] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-26 21:16:38,380 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41302] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-26 21:16:38,399 [salt.state       :300 ][INFO    ][41302] onlyif execution failed
2019-05-26 21:16:38,400 [salt.state       :1951][INFO    ][41302] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 21:16:38.399885 duration_in_ms=22.294
2019-05-26 21:16:38,404 [salt.state       :1780][INFO    ][41302] Running state [/etc/iptables/rules.v6] at time 21:16:38.402635
2019-05-26 21:16:38,404 [salt.state       :1813][INFO    ][41302] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-26 21:16:38,405 [salt.state       :300 ][INFO    ][41302] File /etc/iptables/rules.v6 is not present
2019-05-26 21:16:38,406 [salt.state       :1951][INFO    ][41302] Completed state [/etc/iptables/rules.v6] at time 21:16:38.406306 duration_in_ms=4.599
2019-05-26 21:16:38,407 [salt.state       :1780][INFO    ][41302] Running state [iptables_extra.flush_all] at time 21:16:38.407419
2019-05-26 21:16:38,407 [salt.state       :1813][INFO    ][41302] Executing state module.wait for [iptables_extra.flush_all]
2019-05-26 21:16:38,408 [salt.state       :300 ][INFO    ][41302] No changes made for iptables_extra.flush_all
2019-05-26 21:16:38,408 [salt.state       :1951][INFO    ][41302] Completed state [iptables_extra.flush_all] at time 21:16:38.408666 duration_in_ms=1.246
2019-05-26 21:16:38,413 [salt.minion      :1711][INFO    ][41302] Returning information for job: 20190526211626602613
2019-05-26 21:16:39,139 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526211639125301
2019-05-26 21:16:39,171 [salt.minion      :1432][INFO    ][41383] Starting a new job with PID 41383
2019-05-26 21:16:40,136 [salt.state       :915 ][INFO    ][41383] Loading fresh modules for state activity
2019-05-26 21:16:41,451 [salt.state       :1780][INFO    ][41383] Running state [maas-rack-controller] at time 21:16:41.451552
2019-05-26 21:16:41,452 [salt.state       :1813][INFO    ][41383] Executing state pkg.installed for [maas-rack-controller]
2019-05-26 21:16:41,452 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41383] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-26 21:16:41,576 [salt.state       :300 ][INFO    ][41383] All specified packages are already installed
2019-05-26 21:16:41,576 [salt.state       :1951][INFO    ][41383] Completed state [maas-rack-controller] at time 21:16:41.576416 duration_in_ms=124.865
2019-05-26 21:16:41,576 [salt.state       :1780][INFO    ][41383] Running state [ipmitool] at time 21:16:41.576787
2019-05-26 21:16:41,577 [salt.state       :1813][INFO    ][41383] Executing state pkg.installed for [ipmitool]
2019-05-26 21:16:41,586 [salt.state       :300 ][INFO    ][41383] All specified packages are already installed
2019-05-26 21:16:41,586 [salt.state       :1951][INFO    ][41383] Completed state [ipmitool] at time 21:16:41.586827 duration_in_ms=10.04
2019-05-26 21:16:41,590 [salt.state       :1780][INFO    ][41383] Running state [/etc/maas/rackd.conf] at time 21:16:41.590247
2019-05-26 21:16:41,590 [salt.state       :1813][INFO    ][41383] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-26 21:16:41,591 [salt.state       :300 ][INFO    ][41383] No changes needed to be made
2019-05-26 21:16:41,591 [salt.state       :1951][INFO    ][41383] Completed state [/etc/maas/rackd.conf] at time 21:16:41.591841 duration_in_ms=1.594
2019-05-26 21:16:41,592 [salt.state       :1780][INFO    ][41383] Running state [/etc/maas/rackd.conf] at time 21:16:41.592126
2019-05-26 21:16:41,592 [salt.state       :1813][INFO    ][41383] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-26 21:16:41,592 [salt.loaded.int.states.file:2298][WARNING ][41383] State for file: /etc/maas/rackd.conf - Neither 'source' nor 'contents' nor 'contents_pillar' nor 'contents_grains' was defined, yet 'replace' was set to 'True'. As there is no source to replace the file with, 'replace' has been set to 'False' to avoid reading the file unnecessarily.
2019-05-26 21:16:41,593 [salt.state       :300 ][INFO    ][41383] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-26 21:16:41,594 [salt.state       :1951][INFO    ][41383] Completed state [/etc/maas/rackd.conf] at time 21:16:41.594131 duration_in_ms=2.005
2019-05-26 21:16:41,595 [salt.state       :1780][INFO    ][41383] Running state [maas-rackd] at time 21:16:41.595193
2019-05-26 21:16:41,595 [salt.state       :1813][INFO    ][41383] Executing state service.running for [maas-rackd]
2019-05-26 21:16:41,596 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41383] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-26 21:16:41,637 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41383] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-26 21:16:41,662 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41383] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-26 21:16:41,686 [salt.state       :300 ][INFO    ][41383] The service maas-rackd is already running
2019-05-26 21:16:41,687 [salt.state       :1951][INFO    ][41383] Completed state [maas-rackd] at time 21:16:41.686938 duration_in_ms=91.744
2019-05-26 21:16:41,689 [salt.minion      :1711][INFO    ][41383] Returning information for job: 20190526211639125301
2019-05-26 21:16:42,413 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526211642399006
2019-05-26 21:16:42,441 [salt.minion      :1432][INFO    ][41406] Starting a new job with PID 41406
2019-05-26 21:16:43,420 [salt.state       :915 ][INFO    ][41406] Loading fresh modules for state activity
2019-05-26 21:16:44,841 [salt.state       :1780][INFO    ][41406] Running state [maas-region-controller] at time 21:16:44.841573
2019-05-26 21:16:44,842 [salt.state       :1813][INFO    ][41406] Executing state pkg.installed for [maas-region-controller]
2019-05-26 21:16:44,842 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-26 21:16:44,967 [salt.state       :300 ][INFO    ][41406] All specified packages are already installed
2019-05-26 21:16:44,968 [salt.state       :1951][INFO    ][41406] Completed state [maas-region-controller] at time 21:16:44.968311 duration_in_ms=126.739
2019-05-26 21:16:44,968 [salt.state       :1780][INFO    ][41406] Running state [python-oauth] at time 21:16:44.968700
2019-05-26 21:16:44,969 [salt.state       :1813][INFO    ][41406] Executing state pkg.installed for [python-oauth]
2019-05-26 21:16:44,978 [salt.state       :300 ][INFO    ][41406] All specified packages are already installed
2019-05-26 21:16:44,979 [salt.state       :1951][INFO    ][41406] Completed state [python-oauth] at time 21:16:44.979045 duration_in_ms=10.345
2019-05-26 21:16:44,982 [salt.state       :1780][INFO    ][41406] Running state [/etc/maas/regiond.conf] at time 21:16:44.982419
2019-05-26 21:16:44,982 [salt.state       :1813][INFO    ][41406] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-26 21:16:44,987 [salt.state       :300 ][INFO    ][41406] No changes needed to be made
2019-05-26 21:16:44,987 [salt.state       :1951][INFO    ][41406] Completed state [/etc/maas/regiond.conf] at time 21:16:44.987717 duration_in_ms=5.298
2019-05-26 21:16:44,988 [salt.state       :1780][INFO    ][41406] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:16:44.988384
2019-05-26 21:16:44,988 [salt.state       :1813][INFO    ][41406] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-26 21:16:45,061 [salt.state       :300 ][INFO    ][41406] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-26 21:16:45,062 [salt.state       :1951][INFO    ][41406] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 21:16:45.061679 duration_in_ms=73.294
2019-05-26 21:16:45,063 [salt.state       :1780][INFO    ][41406] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:16:45.063198
2019-05-26 21:16:45,063 [salt.state       :1813][INFO    ][41406] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-26 21:16:45,067 [salt.state       :300 ][INFO    ][41406] No changes needed to be made
2019-05-26 21:16:45,068 [salt.state       :1951][INFO    ][41406] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:16:45.068157 duration_in_ms=4.958
2019-05-26 21:16:45,068 [salt.state       :1780][INFO    ][41406] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:16:45.068670
2019-05-26 21:16:45,068 [salt.state       :1813][INFO    ][41406] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-26 21:16:45,073 [salt.state       :300 ][INFO    ][41406] No changes needed to be made
2019-05-26 21:16:45,073 [salt.state       :1951][INFO    ][41406] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 21:16:45.073442 duration_in_ms=4.772
2019-05-26 21:16:45,074 [salt.state       :1780][INFO    ][41406] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:16:45.074569
2019-05-26 21:16:45,074 [salt.state       :1813][INFO    ][41406] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-26 21:16:45,100 [salt.state       :300 ][INFO    ][41406] No changes needed to be made
2019-05-26 21:16:45,100 [salt.state       :1951][INFO    ][41406] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 21:16:45.100770 duration_in_ms=26.2
2019-05-26 21:16:45,101 [salt.state       :1780][INFO    ][41406] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:16:45.101293
2019-05-26 21:16:45,101 [salt.state       :1813][INFO    ][41406] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-26 21:16:45,116 [salt.state       :300 ][INFO    ][41406] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-26 21:16:45,117 [salt.state       :1951][INFO    ][41406] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 21:16:45.116970 duration_in_ms=15.676
2019-05-26 21:16:45,118 [salt.state       :1780][INFO    ][41406] Running state [a2enmod headers] at time 21:16:45.118801
2019-05-26 21:16:45,119 [salt.state       :1813][INFO    ][41406] Executing state cmd.run for [a2enmod headers]
2019-05-26 21:16:45,120 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command 'a2enmod headers' in directory '/root'
2019-05-26 21:16:45,197 [salt.state       :300 ][INFO    ][41406] {'pid': 41427, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-26 21:16:45,198 [salt.state       :1951][INFO    ][41406] Completed state [a2enmod headers] at time 21:16:45.198572 duration_in_ms=79.77
2019-05-26 21:16:45,199 [salt.state       :1780][INFO    ][41406] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:16:45.199345
2019-05-26 21:16:45,200 [salt.state       :1813][INFO    ][41406] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-26 21:16:45,226 [salt.state       :300 ][INFO    ][41406] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-26 21:16:45,226 [salt.state       :1951][INFO    ][41406] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 21:16:45.226829 duration_in_ms=27.484
2019-05-26 21:16:45,228 [salt.state       :1780][INFO    ][41406] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:16:45.227897
2019-05-26 21:16:45,228 [salt.state       :1813][INFO    ][41406] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-26 21:16:45,294 [salt.state       :300 ][INFO    ][41406] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-26 21:16:45,294 [salt.state       :1951][INFO    ][41406] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 21:16:45.294689 duration_in_ms=66.792
2019-05-26 21:16:45,295 [salt.state       :1780][INFO    ][41406] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:16:45.295223
2019-05-26 21:16:45,295 [salt.state       :1813][INFO    ][41406] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-26 21:16:45,357 [salt.state       :300 ][INFO    ][41406] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-26 21:16:45,357 [salt.state       :1951][INFO    ][41406] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 21:16:45.357897 duration_in_ms=62.674
2019-05-26 21:16:45,358 [salt.state       :1780][INFO    ][41406] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:16:45.358470
2019-05-26 21:16:45,358 [salt.state       :1813][INFO    ][41406] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-26 21:16:45,451 [salt.state       :300 ][INFO    ][41406] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-26 21:16:45,451 [salt.state       :1951][INFO    ][41406] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 21:16:45.451841 duration_in_ms=93.371
2019-05-26 21:16:45,452 [salt.state       :1780][INFO    ][41406] Running state [/root/.pgpass] at time 21:16:45.452136
2019-05-26 21:16:45,452 [salt.state       :1813][INFO    ][41406] Executing state file.managed for [/root/.pgpass]
2019-05-26 21:16:45,498 [salt.state       :300 ][INFO    ][41406] File /root/.pgpass is in the correct state
2019-05-26 21:16:45,498 [salt.state       :1951][INFO    ][41406] Completed state [/root/.pgpass] at time 21:16:45.498453 duration_in_ms=46.317
2019-05-26 21:16:45,503 [salt.state       :1780][INFO    ][41406] Running state [maas-region syncdb --noinput] at time 21:16:45.503585
2019-05-26 21:16:45,503 [salt.state       :1813][INFO    ][41406] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-26 21:16:45,504 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-26 21:16:48,243 [salt.state       :300 ][INFO    ][41406] {'pid': 41440, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sites, auth, sessions, metadataserver, piston3, contenttypes, maasserver\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-26 21:16:48,244 [salt.state       :1951][INFO    ][41406] Completed state [maas-region syncdb --noinput] at time 21:16:48.244666 duration_in_ms=2741.079
2019-05-26 21:16:48,245 [salt.state       :2022][WARNING ][41406] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-26 21:16:48,250 [salt.state       :1780][INFO    ][41406] Running state [maas-regiond] at time 21:16:48.249697
2019-05-26 21:16:48,250 [salt.state       :1813][INFO    ][41406] Executing state service.running for [maas-regiond]
2019-05-26 21:16:48,252 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-26 21:16:48,299 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-26 21:16:48,323 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-26 21:16:48,345 [salt.state       :300 ][INFO    ][41406] The service maas-regiond is already running
2019-05-26 21:16:48,346 [salt.state       :1951][INFO    ][41406] Completed state [maas-regiond] at time 21:16:48.346185 duration_in_ms=96.489
2019-05-26 21:16:48,349 [salt.state       :1780][INFO    ][41406] Running state [bind9] at time 21:16:48.349548
2019-05-26 21:16:48,351 [salt.state       :1813][INFO    ][41406] Executing state service.running for [bind9]
2019-05-26 21:16:48,352 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-26 21:16:48,373 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-26 21:16:48,397 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-26 21:16:48,419 [salt.state       :300 ][INFO    ][41406] The service bind9 is already running
2019-05-26 21:16:48,420 [salt.state       :1951][INFO    ][41406] Completed state [bind9] at time 21:16:48.420313 duration_in_ms=70.765
2019-05-26 21:16:48,424 [salt.state       :1780][INFO    ][41406] Running state [apache2] at time 21:16:48.424325
2019-05-26 21:16:48,424 [salt.state       :1813][INFO    ][41406] Executing state service.running for [apache2]
2019-05-26 21:16:48,425 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-26 21:16:48,445 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-26 21:16:48,462 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-26 21:16:48,490 [salt.state       :300 ][INFO    ][41406] The service apache2 is already running
2019-05-26 21:16:48,490 [salt.state       :1951][INFO    ][41406] Completed state [apache2] at time 21:16:48.490813 duration_in_ms=66.487
2019-05-26 21:16:48,493 [salt.state       :1780][INFO    ][41406] Running state [maasng.wait_for_http_code] at time 21:16:48.493169
2019-05-26 21:16:48,497 [salt.state       :1813][INFO    ][41406] Executing state module.run for [maasng.wait_for_http_code]
2019-05-26 21:16:48,498 [salt.utils.decorators:613 ][WARNING ][41406] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 21:16:48,624 [salt.state       :300 ][INFO    ][41406] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-26 21:16:48,625 [salt.state       :1951][INFO    ][41406] Completed state [maasng.wait_for_http_code] at time 21:16:48.625349 duration_in_ms=132.179
2019-05-26 21:16:48,628 [salt.state       :1780][INFO    ][41406] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:16:48.628796
2019-05-26 21:16:48,629 [salt.state       :1813][INFO    ][41406] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-26 21:16:48,630 [salt.state       :300 ][INFO    ][41406] /var/lib/maas/.setup_admin exists
2019-05-26 21:16:48,631 [salt.state       :1951][INFO    ][41406] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 21:16:48.631174 duration_in_ms=2.378
2019-05-26 21:16:48,632 [salt.state       :1780][INFO    ][41406] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:16:48.632567
2019-05-26 21:16:48,633 [salt.state       :1813][INFO    ][41406] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 21:16:48,634 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41406] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 21:16:50,525 [salt.state       :300 ][INFO    ][41406] {'pid': 41461, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 21:16:50,531 [salt.state       :1951][INFO    ][41406] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:16:50.530791 duration_in_ms=1898.22
2019-05-26 21:16:50,543 [salt.state       :1780][INFO    ][41406] Running state [maas_region_boot_source_resources_mirror] at time 21:16:50.543018
2019-05-26 21:16:50,543 [salt.state       :1813][INFO    ][41406] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-26 21:16:50,644 [salt.state       :300 ][INFO    ][41406] {'changes': {}}
2019-05-26 21:16:50,645 [salt.state       :1951][INFO    ][41406] Completed state [maas_region_boot_source_resources_mirror] at time 21:16:50.644958 duration_in_ms=101.94
2019-05-26 21:16:50,646 [salt.state       :1780][INFO    ][41406] Running state [maasng.boot_resources_import] at time 21:16:50.646501
2019-05-26 21:16:50,647 [salt.state       :1813][INFO    ][41406] Executing state module.run for [maasng.boot_resources_import]
2019-05-26 21:16:50,647 [salt.utils.decorators:613 ][WARNING ][41406] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 21:16:50,736 [salt.loaded.ext.module.maasng:1600][INFO    ][41406] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-26 21:16:55,788 [salt.loaded.ext.module.maasng:1600][INFO    ][41406] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-26 21:16:57,487 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211657476077
2019-05-26 21:16:57,512 [salt.minion      :1432][INFO    ][41502] Starting a new job with PID 41502
2019-05-26 21:16:57,545 [salt.minion      :1711][INFO    ][41502] Returning information for job: 20190526211657476077
2019-05-26 21:17:00,891 [salt.state       :300 ][INFO    ][41406] {'ret': True}
2019-05-26 21:17:00,892 [salt.state       :1951][INFO    ][41406] Completed state [maasng.boot_resources_import] at time 21:17:00.891957 duration_in_ms=10245.455
2019-05-26 21:17:00,893 [salt.state       :1780][INFO    ][41406] Running state [maas_region_boot_sources_selection_xenial] at time 21:17:00.893383
2019-05-26 21:17:00,894 [salt.state       :1813][INFO    ][41406] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-26 21:17:01,056 [salt.state       :300 ][INFO    ][41406] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-26 21:17:01,057 [salt.state       :1951][INFO    ][41406] Completed state [maas_region_boot_sources_selection_xenial] at time 21:17:01.057366 duration_in_ms=163.983
2019-05-26 21:17:01,060 [salt.state       :1780][INFO    ][41406] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 21:17:01.060177
2019-05-26 21:17:01,060 [salt.state       :1813][INFO    ][41406] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-26 21:17:01,061 [salt.utils.decorators:613 ][WARNING ][41406] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 21:17:01,062 [salt.loaded.ext.module.maasng:1771][INFO    ][41406] boot-sources sync initiated for ALL Rack's
2019-05-26 21:17:02,065 [salt.state       :300 ][INFO    ][41406] {'ret': True}
2019-05-26 21:17:02,066 [salt.state       :1951][INFO    ][41406] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 21:17:02.065690 duration_in_ms=1005.513
2019-05-26 21:17:02,067 [salt.state       :1780][INFO    ][41406] Running state [maas.process_maas_config] at time 21:17:02.067581
2019-05-26 21:17:02,068 [salt.state       :1813][INFO    ][41406] Executing state module.run for [maas.process_maas_config]
2019-05-26 21:17:02,068 [salt.utils.decorators:613 ][WARNING ][41406] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 21:17:02,069 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=enable_http_proxy value=True
2019-05-26 21:17:02,120 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=upstream_dns value=8.8.8.8
2019-05-26 21:17:03,573 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=commissioning_distro_series value=xenial
2019-05-26 21:17:03,634 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=default_osystem value=ubuntu
2019-05-26 21:17:03,694 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=active_discovery_interval value=600
2019-05-26 21:17:03,743 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=dnssec_validation value=no
2019-05-26 21:17:03,783 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=maas_name value=mas01
2019-05-26 21:17:03,830 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=network_discovery value=enabled
2019-05-26 21:17:03,933 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=enable_third_party_drivers value=True
2019-05-26 21:17:03,977 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=default_storage_layout value=lvm
2019-05-26 21:17:04,025 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=ntp_external_only value=True
2019-05-26 21:17:04,084 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-26 21:17:04,124 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=default_distro_series value=xenial
2019-05-26 21:17:04,181 [salt.loaded.ext.module.maas:92  ][INFO    ][41406] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-26 21:17:04,291 [salt.state       :300 ][INFO    ][41406] {'ret': {'updated': [], 'errors': {}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'network_discovery', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}}
2019-05-26 21:17:04,291 [salt.state       :1951][INFO    ][41406] Completed state [maas.process_maas_config] at time 21:17:04.291616 duration_in_ms=2224.033
2019-05-26 21:17:04,292 [salt.state       :1780][INFO    ][41406] Running state [pxe_admin] at time 21:17:04.292349
2019-05-26 21:17:04,292 [salt.state       :1813][INFO    ][41406] Executing state maasng.fabric_present for [pxe_admin]
2019-05-26 21:17:04,359 [salt.loaded.ext.module.maasng:945 ][INFO    ][41406] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-05-26 21:17:04,430 [salt.loaded.ext.module.maasng:1008][WARNING ][41406] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-26 21:17:04,430 [salt.loaded.ext.module.maasng:1011][WARNING ][41406] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-26 21:17:04,485 [salt.state       :300 ][INFO    ][41406] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-26 21:17:04,486 [salt.state       :1951][INFO    ][41406] Completed state [pxe_admin] at time 21:17:04.486482 duration_in_ms=194.133
2019-05-26 21:17:04,486 [salt.state       :1780][INFO    ][41406] Running state [vlan 0] at time 21:17:04.486905
2019-05-26 21:17:04,487 [salt.state       :1813][INFO    ][41406] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-26 21:17:04,543 [salt.loaded.ext.module.maasng:945 ][INFO    ][41406] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-2', u'relay_vlan': None, u'primary_rack': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'fabric-2'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'pxe_admin'}]
2019-05-26 21:17:04,652 [salt.loaded.ext.module.maasng:945 ][INFO    ][41406] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': u''}]
2019-05-26 21:17:04,912 [salt.loaded.ext.module.maasng:945 ][INFO    ][41406] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-2', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'fabric-2'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': u'ae4y36', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'pxe_admin'}]
2019-05-26 21:17:04,991 [salt.state       :300 ][INFO    ][41406] {'new': 'Vlan untagged was updated'}
2019-05-26 21:17:04,991 [salt.state       :1951][INFO    ][41406] Completed state [vlan 0] at time 21:17:04.991362 duration_in_ms=504.456
2019-05-26 21:17:04,992 [salt.state       :1780][INFO    ][41406] Running state [192.168.11.0/24] at time 21:17:04.992503
2019-05-26 21:17:04,992 [salt.state       :1813][INFO    ][41406] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-26 21:17:05,158 [salt.loaded.ext.module.maasng:945 ][INFO    ][41406] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-2', u'relay_vlan': None, u'primary_rack': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'fabric-2'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'ae4y36', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'pxe_admin'}]
2019-05-26 21:17:05,159 [salt.loaded.ext.module.maasng:1235][WARNING ][41406] Ignoring parameter vlan:0
2019-05-26 21:17:05,264 [salt.state       :300 ][INFO    ][41406] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-26 21:17:05,264 [salt.state       :1951][INFO    ][41406] Completed state [192.168.11.0/24] at time 21:17:05.264420 duration_in_ms=271.917
2019-05-26 21:17:05,265 [salt.state       :1780][INFO    ][41406] Running state [maas_create_iprange_1] at time 21:17:05.265273
2019-05-26 21:17:05,265 [salt.state       :1813][INFO    ][41406] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-26 21:17:05,323 [salt.state       :300 ][INFO    ][41406] Iprange maas_create_iprange_1 already exist.
2019-05-26 21:17:05,323 [salt.state       :1951][INFO    ][41406] Completed state [maas_create_iprange_1] at time 21:17:05.323466 duration_in_ms=58.192
2019-05-26 21:17:05,323 [salt.state       :1780][INFO    ][41406] Running state [vlan 0] at time 21:17:05.323807
2019-05-26 21:17:05,324 [salt.state       :1813][INFO    ][41406] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-26 21:17:05,387 [salt.loaded.ext.module.maasng:945 ][INFO    ][41406] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-05-26 21:17:05,469 [salt.loaded.ext.module.maasng:945 ][INFO    ][41406] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-05-26 21:17:05,680 [salt.loaded.ext.module.maasng:945 ][INFO    ][41406] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'fabric-2'}], 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'ae4y36', u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}]
2019-05-26 21:17:05,789 [salt.state       :300 ][INFO    ][41406] {'new': 'Vlan untagged was updated'}
2019-05-26 21:17:05,792 [salt.state       :1951][INFO    ][41406] Completed state [vlan 0] at time 21:17:05.791974 duration_in_ms=468.166
2019-05-26 21:17:05,792 [salt.state       :1780][INFO    ][41406] Running state [opnfv] at time 21:17:05.792725
2019-05-26 21:17:05,793 [salt.state       :1813][INFO    ][41406] Executing state maasng.sshkey_present for [opnfv]
2019-05-26 21:17:05,845 [salt.loaded.ext.module.maasng:1903][INFO    ][41406] [{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-05-26 21:17:05,845 [salt.state       :300 ][INFO    ][41406] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC74OvZ7y776Wj5A8gYoVsdCbbUonA1WMCs5kfze0DkD4BUfOiRckbCWpDsZ84y0q/A3tHj3u8/a9JnDyohIIAiswijSxajjvrLfPHa87S25OtoMcjousRMdy5O/WDRfSsgNJrbNYYytMurQMLHMKJHwSY8Z950wKP852g6WoQxv3Lhd7WrZgbPOLo2Y2J/ZywpakYaLeAJOaHe66ZX8b55yS1IL9oYVbrpD/ixBh+PaZrOjoGobYU82xY8RKfpfmTWLm/CO0BgrLk1vIKEVwfIxu+wleagZCUL/XHbO6owtVjXE3l9ZFGE3ZF/WyS4/CuXNomG+pHCQ91fcP3EGx6b already exist for user opnfv.
2019-05-26 21:17:05,850 [salt.state       :1951][INFO    ][41406] Completed state [opnfv] at time 21:17:05.850625 duration_in_ms=57.899
2019-05-26 21:17:05,854 [salt.minion      :1711][INFO    ][41406] Returning information for job: 20190526211642399006
2019-05-26 21:17:06,516 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526211706507321
2019-05-26 21:17:06,534 [salt.minion      :1432][INFO    ][41881] Starting a new job with PID 41881
2019-05-26 21:17:12,566 [salt.state       :915 ][INFO    ][41881] Loading fresh modules for state activity
2019-05-26 21:17:12,673 [salt.state       :1780][INFO    ][41881] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:17:12.672950
2019-05-26 21:17:12,673 [salt.state       :1813][INFO    ][41881] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 21:17:12,675 [salt.loaded.int.module.cmdmod:395 ][INFO    ][41881] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 21:17:14,456 [salt.state       :300 ][INFO    ][41881] {'pid': 41907, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 21:17:14,457 [salt.state       :1951][INFO    ][41881] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:17:14.457288 duration_in_ms=1784.338
2019-05-26 21:17:14,460 [salt.state       :1780][INFO    ][41881] Running state [maas.process_machines] at time 21:17:14.460666
2019-05-26 21:17:14,461 [salt.state       :1813][INFO    ][41881] Executing state module.run for [maas.process_machines]
2019-05-26 21:17:14,463 [salt.utils.decorators:613 ][WARNING ][41881] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 21:17:15,048 [salt.loaded.ext.module.maas:412 ][WARNING ][41881] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 21:17:15,049 [salt.loaded.ext.module.maas:92  ][INFO    ][41881] 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 system_id=whh8ak architecture=amd64/generic power_parameters_power_user=opnfv
2019-05-26 21:17:16,331 [salt.loaded.ext.module.maas:412 ][WARNING ][41881] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 21:17:16,332 [salt.loaded.ext.module.maas:92  ][INFO    ][41881] 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 system_id=c7ncda architecture=amd64/generic power_parameters_power_user=opnfv
2019-05-26 21:17:17,518 [salt.loaded.ext.module.maas:412 ][WARNING ][41881] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 21:17:17,519 [salt.loaded.ext.module.maas:92  ][INFO    ][41881] machine hostname=kvm01 power_type=ipmi mac_addresses=['14:58:d0:54:e7:88'] power_parameters_power_address=172.16.1.16 power_parameters_power_pass=Winter2017 system_id=strh4h architecture=amd64/generic power_parameters_power_user=opnfv
2019-05-26 21:17:18,742 [salt.loaded.ext.module.maas:412 ][WARNING ][41881] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 21:17:18,743 [salt.loaded.ext.module.maas:92  ][INFO    ][41881] machine hostname=kvm03 power_type=ipmi mac_addresses=['14:58:d0:54:7a:28'] power_parameters_power_address=172.16.1.18 power_parameters_power_pass=Winter2017 system_id=4wyerw architecture=amd64/generic power_parameters_power_user=opnfv
2019-05-26 21:17:19,947 [salt.loaded.ext.module.maas:412 ][WARNING ][41881] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-26 21:17:19,947 [salt.loaded.ext.module.maas:92  ][INFO    ][41881] machine hostname=kvm02 power_type=ipmi mac_addresses=['14:58:d0:54:6a:60'] power_parameters_power_address=172.16.1.17 power_parameters_power_pass=Winter2017 system_id=na4ya3 architecture=amd64/generic power_parameters_power_user=opnfv
2019-05-26 21:17:21,108 [salt.state       :300 ][INFO    ][41881] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-26 21:17:21,109 [salt.state       :1951][INFO    ][41881] Completed state [maas.process_machines] at time 21:17:21.109276 duration_in_ms=6648.609
2019-05-26 21:17:21,114 [salt.minion      :1711][INFO    ][41881] Returning information for job: 20190526211706507321
2019-05-26 21:17:54,156 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526211754142483
2019-05-26 21:17:54,190 [salt.minion      :1432][INFO    ][42145] Starting a new job with PID 42145
2019-05-26 21:18:00,133 [salt.state       :915 ][INFO    ][42145] Loading fresh modules for state activity
2019-05-26 21:18:00,241 [salt.state       :1780][INFO    ][42145] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:00.241515
2019-05-26 21:18:00,241 [salt.state       :1813][INFO    ][42145] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 21:18:00,243 [salt.loaded.int.module.cmdmod:395 ][INFO    ][42145] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 21:18:01,953 [salt.state       :300 ][INFO    ][42145] {'pid': 42153, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 21:18:01,955 [salt.state       :1951][INFO    ][42145] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:01.954963 duration_in_ms=1713.447
2019-05-26 21:18:01,959 [salt.state       :1780][INFO    ][42145] Running state [maas.wait_for_machine_status] at time 21:18:01.959601
2019-05-26 21:18:01,960 [salt.state       :1813][INFO    ][42145] Executing state module.run for [maas.wait_for_machine_status]
2019-05-26 21:18:01,960 [salt.utils.decorators:613 ][WARNING ][42145] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 21:18:04,824 [salt.state       :300 ][INFO    ][42145] {'ret': True}
2019-05-26 21:18:04,825 [salt.state       :1951][INFO    ][42145] Completed state [maas.wait_for_machine_status] at time 21:18:04.825239 duration_in_ms=2865.637
2019-05-26 21:18:04,830 [salt.minion      :1711][INFO    ][42145] Returning information for job: 20190526211754142483
2019-05-26 21:18:05,440 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526211805427251
2019-05-26 21:18:05,465 [salt.minion      :1432][INFO    ][42183] Starting a new job with PID 42183
2019-05-26 21:18:06,472 [salt.state       :915 ][INFO    ][42183] Loading fresh modules for state activity
2019-05-26 21:18:06,619 [salt.state       :1780][INFO    ][42183] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:06.618985
2019-05-26 21:18:06,619 [salt.state       :1813][INFO    ][42183] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 21:18:06,621 [salt.loaded.int.module.cmdmod:395 ][INFO    ][42183] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 21:18:08,410 [salt.state       :300 ][INFO    ][42183] {'pid': 42206, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 21:18:08,411 [salt.state       :1951][INFO    ][42183] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:08.411416 duration_in_ms=1792.43
2019-05-26 21:18:08,417 [salt.state       :1780][INFO    ][42183] Running state [maas_machines_storage_cmp002_lvm] at time 21:18:08.417227
2019-05-26 21:18:08,417 [salt.state       :1813][INFO    ][42183] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-26 21:18:08,960 [salt.state       :300 ][INFO    ][42183] Machine cmp002 is not in Ready state.
2019-05-26 21:18:08,961 [salt.state       :1951][INFO    ][42183] Completed state [maas_machines_storage_cmp002_lvm] at time 21:18:08.961284 duration_in_ms=544.057
2019-05-26 21:18:08,962 [salt.state       :1780][INFO    ][42183] Running state [maas_machines_storage_cmp001_lvm] at time 21:18:08.962134
2019-05-26 21:18:08,962 [salt.state       :1813][INFO    ][42183] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-26 21:18:09,508 [salt.state       :300 ][INFO    ][42183] Machine cmp001 is not in Ready state.
2019-05-26 21:18:09,510 [salt.state       :1951][INFO    ][42183] Completed state [maas_machines_storage_cmp001_lvm] at time 21:18:09.509698 duration_in_ms=547.562
2019-05-26 21:18:09,514 [salt.minion      :1711][INFO    ][42183] Returning information for job: 20190526211805427251
2019-05-26 21:18:10,055 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526211810044549
2019-05-26 21:18:10,075 [salt.minion      :1432][INFO    ][42217] Starting a new job with PID 42217
2019-05-26 21:18:11,067 [salt.state       :915 ][INFO    ][42217] Loading fresh modules for state activity
2019-05-26 21:18:11,154 [salt.state       :1780][INFO    ][42217] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:11.153999
2019-05-26 21:18:11,154 [salt.state       :1813][INFO    ][42217] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 21:18:11,156 [salt.loaded.int.module.cmdmod:395 ][INFO    ][42217] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 21:18:12,974 [salt.state       :300 ][INFO    ][42217] {'pid': 42224, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 21:18:12,975 [salt.state       :1951][INFO    ][42217] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:12.974995 duration_in_ms=1820.996
2019-05-26 21:18:12,976 [salt.state       :1780][INFO    ][42217] Running state [maas.deploy_machines] at time 21:18:12.976489
2019-05-26 21:18:12,976 [salt.state       :1813][INFO    ][42217] Executing state module.run for [maas.deploy_machines]
2019-05-26 21:18:12,977 [salt.utils.decorators:613 ][WARNING ][42217] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 21:18:13,479 [salt.loaded.ext.module.maas:684 ][INFO    ][42217] deploymachines hwe_kernel=hwe-16.04 system_id=na4ya3 distro_series=xenial
2019-05-26 21:18:15,932 [salt.state       :300 ][INFO    ][42217] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03'], 'errors': {}, 'success': ['kvm02']}}
2019-05-26 21:18:15,932 [salt.state       :1951][INFO    ][42217] Completed state [maas.deploy_machines] at time 21:18:15.932722 duration_in_ms=2956.23
2019-05-26 21:18:15,936 [salt.minion      :1711][INFO    ][42217] Returning information for job: 20190526211810044549
2019-05-26 21:18:16,581 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command state.apply with jid 20190526211816520507
2019-05-26 21:18:16,604 [salt.minion      :1432][INFO    ][42286] Starting a new job with PID 42286
2019-05-26 21:18:22,645 [salt.state       :915 ][INFO    ][42286] Loading fresh modules for state activity
2019-05-26 21:18:22,745 [salt.state       :1780][INFO    ][42286] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:22.745603
2019-05-26 21:18:22,745 [salt.state       :1813][INFO    ][42286] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-26 21:18:22,747 [salt.loaded.int.module.cmdmod:395 ][INFO    ][42286] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-26 21:18:24,464 [salt.state       :300 ][INFO    ][42286] {'pid': 42302, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-26 21:18:24,466 [salt.state       :1951][INFO    ][42286] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 21:18:24.465660 duration_in_ms=1720.057
2019-05-26 21:18:24,469 [salt.state       :1780][INFO    ][42286] Running state [maas.wait_for_machine_status] at time 21:18:24.468912
2019-05-26 21:18:24,469 [salt.state       :1813][INFO    ][42286] Executing state module.run for [maas.wait_for_machine_status]
2019-05-26 21:18:24,471 [salt.utils.decorators:613 ][WARNING ][42286] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-26 21:18:27,436 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2247.04774904s left)
2019-05-26 21:18:31,620 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211831605620
2019-05-26 21:18:31,652 [salt.minion      :1432][INFO    ][42317] Starting a new job with PID 42317
2019-05-26 21:18:31,679 [salt.minion      :1711][INFO    ][42317] Returning information for job: 20190526211831605620
2019-05-26 21:19:00,275 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2214.20887113s left)
2019-05-26 21:19:01,711 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211901695626
2019-05-26 21:19:01,738 [salt.minion      :1432][INFO    ][42347] Starting a new job with PID 42347
2019-05-26 21:19:01,761 [salt.minion      :1711][INFO    ][42347] Returning information for job: 20190526211901695626
2019-05-26 21:19:31,796 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526211931783031
2019-05-26 21:19:31,820 [salt.minion      :1432][INFO    ][42393] Starting a new job with PID 42393
2019-05-26 21:19:31,845 [salt.minion      :1711][INFO    ][42393] Returning information for job: 20190526211931783031
2019-05-26 21:19:33,025 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2181.45898819s left)
2019-05-26 21:20:01,889 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212001874819
2019-05-26 21:20:01,917 [salt.minion      :1432][INFO    ][42427] Starting a new job with PID 42427
2019-05-26 21:20:01,941 [salt.minion      :1711][INFO    ][42427] Returning information for job: 20190526212001874819
2019-05-26 21:20:05,783 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2148.70059013s left)
2019-05-26 21:20:31,975 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212031961089
2019-05-26 21:20:32,002 [salt.minion      :1432][INFO    ][42488] Starting a new job with PID 42488
2019-05-26 21:20:32,032 [salt.minion      :1711][INFO    ][42488] Returning information for job: 20190526212031961089
2019-05-26 21:20:38,555 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2115.9286902s left)
2019-05-26 21:21:02,073 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212102057978
2019-05-26 21:21:02,105 [salt.minion      :1432][INFO    ][42520] Starting a new job with PID 42520
2019-05-26 21:21:02,129 [salt.minion      :1711][INFO    ][42520] Returning information for job: 20190526212102057978
2019-05-26 21:21:11,513 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2082.97028208s left)
2019-05-26 21:21:32,179 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212132161050
2019-05-26 21:21:32,209 [salt.minion      :1432][INFO    ][42568] Starting a new job with PID 42568
2019-05-26 21:21:32,230 [salt.minion      :1711][INFO    ][42568] Returning information for job: 20190526212132161050
2019-05-26 21:21:44,242 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2050.24184918s left)
2019-05-26 21:22:02,276 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212202265101
2019-05-26 21:22:02,305 [salt.minion      :1432][INFO    ][42597] Starting a new job with PID 42597
2019-05-26 21:22:02,328 [salt.minion      :1711][INFO    ][42597] Returning information for job: 20190526212202265101
2019-05-26 21:22:17,083 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (2017.40061212s left)
2019-05-26 21:22:32,371 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212232362662
2019-05-26 21:22:32,395 [salt.minion      :1432][INFO    ][42672] Starting a new job with PID 42672
2019-05-26 21:22:32,422 [salt.minion      :1711][INFO    ][42672] Returning information for job: 20190526212232362662
2019-05-26 21:22:49,998 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1984.48545623s left)
2019-05-26 21:23:02,479 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212302457481
2019-05-26 21:23:02,506 [salt.minion      :1432][INFO    ][42710] Starting a new job with PID 42710
2019-05-26 21:23:02,537 [salt.minion      :1711][INFO    ][42710] Returning information for job: 20190526212302457481
2019-05-26 21:23:22,883 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1951.60074902s left)
2019-05-26 21:23:32,608 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212332595333
2019-05-26 21:23:32,639 [salt.minion      :1432][INFO    ][42823] Starting a new job with PID 42823
2019-05-26 21:23:32,668 [salt.minion      :1711][INFO    ][42823] Returning information for job: 20190526212332595333
2019-05-26 21:23:55,820 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1918.66357017s left)
2019-05-26 21:24:02,728 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212402713510
2019-05-26 21:24:02,758 [salt.minion      :1432][INFO    ][42861] Starting a new job with PID 42861
2019-05-26 21:24:02,795 [salt.minion      :1711][INFO    ][42861] Returning information for job: 20190526212402713510
2019-05-26 21:24:28,652 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1885.83142614s left)
2019-05-26 21:24:32,900 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212432887606
2019-05-26 21:24:32,928 [salt.minion      :1432][INFO    ][43025] Starting a new job with PID 43025
2019-05-26 21:24:32,957 [salt.minion      :1711][INFO    ][43025] Returning information for job: 20190526212432887606
2019-05-26 21:25:01,476 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1853.00750899s left)
2019-05-26 21:25:03,020 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212503007838
2019-05-26 21:25:03,047 [salt.minion      :1432][INFO    ][43056] Starting a new job with PID 43056
2019-05-26 21:25:03,068 [salt.minion      :1711][INFO    ][43056] Returning information for job: 20190526212503007838
2019-05-26 21:25:33,185 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212533170513
2019-05-26 21:25:33,207 [salt.minion      :1432][INFO    ][43147] Starting a new job with PID 43147
2019-05-26 21:25:33,233 [salt.minion      :1711][INFO    ][43147] Returning information for job: 20190526212533170513
2019-05-26 21:25:34,362 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1820.12137103s left)
2019-05-26 21:26:03,313 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212603303458
2019-05-26 21:26:03,343 [salt.minion      :1432][INFO    ][43176] Starting a new job with PID 43176
2019-05-26 21:26:03,367 [salt.minion      :1711][INFO    ][43176] Returning information for job: 20190526212603303458
2019-05-26 21:26:08,356 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1786.12764406s left)
2019-05-26 21:26:33,488 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212633478469
2019-05-26 21:26:33,514 [salt.minion      :1432][INFO    ][43363] Starting a new job with PID 43363
2019-05-26 21:26:33,538 [salt.minion      :1711][INFO    ][43363] Returning information for job: 20190526212633478469
2019-05-26 21:26:41,328 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1753.15574121s left)
2019-05-26 21:27:03,631 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212703618113
2019-05-26 21:27:03,654 [salt.minion      :1432][INFO    ][43393] Starting a new job with PID 43393
2019-05-26 21:27:03,680 [salt.minion      :1711][INFO    ][43393] Returning information for job: 20190526212703618113
2019-05-26 21:27:14,394 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1720.09022212s left)
2019-05-26 21:27:33,804 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212733787331
2019-05-26 21:27:33,829 [salt.minion      :1432][INFO    ][43443] Starting a new job with PID 43443
2019-05-26 21:27:33,853 [salt.minion      :1711][INFO    ][43443] Returning information for job: 20190526212733787331
2019-05-26 21:27:47,236 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1687.24786305s left)
2019-05-26 21:28:03,977 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212803966583
2019-05-26 21:28:04,000 [salt.minion      :1432][INFO    ][43473] Starting a new job with PID 43473
2019-05-26 21:28:04,026 [salt.minion      :1711][INFO    ][43473] Returning information for job: 20190526212803966583
2019-05-26 21:28:20,142 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1654.34172821s left)
2019-05-26 21:28:34,152 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212834136542
2019-05-26 21:28:34,173 [salt.minion      :1432][INFO    ][43519] Starting a new job with PID 43519
2019-05-26 21:28:34,196 [salt.minion      :1711][INFO    ][43519] Returning information for job: 20190526212834136542
2019-05-26 21:28:52,940 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1621.54375505s left)
2019-05-26 21:29:04,328 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212904318627
2019-05-26 21:29:04,356 [salt.minion      :1432][INFO    ][43548] Starting a new job with PID 43548
2019-05-26 21:29:04,380 [salt.minion      :1711][INFO    ][43548] Returning information for job: 20190526212904318627
2019-05-26 21:29:25,979 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1588.50492716s left)
2019-05-26 21:29:34,504 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526212934489056
2019-05-26 21:29:34,532 [salt.minion      :1432][INFO    ][43595] Starting a new job with PID 43595
2019-05-26 21:29:34,555 [salt.minion      :1711][INFO    ][43595] Returning information for job: 20190526212934489056
2019-05-26 21:29:56,016 [salt.utils.schedule:1377][INFO    ][32435] Running scheduled job: __mine_interval
2019-05-26 21:29:58,856 [salt.loaded.ext.module.maas:1023][INFO    ][42286] Waiting status:Deployed for machines:['kvm02']
sleep for:30s Timeout:2250s (1555.6274581s left)
2019-05-26 21:30:04,696 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command saltutil.find_job with jid 20190526213004679149
2019-05-26 21:30:04,724 [salt.minion      :1432][INFO    ][43647] Starting a new job with PID 43647
2019-05-26 21:30:04,746 [salt.minion      :1711][INFO    ][43647] Returning information for job: 20190526213004679149
2019-05-26 21:30:31,818 [salt.state       :300 ][INFO    ][42286] {'ret': True}
2019-05-26 21:30:31,819 [salt.state       :1951][INFO    ][42286] Completed state [maas.wait_for_machine_status] at time 21:30:31.818920 duration_in_ms=727350.004
2019-05-26 21:30:31,824 [salt.minion      :1711][INFO    ][42286] Returning information for job: 20190526211816520507
2019-05-26 22:29:56,015 [salt.utils.schedule:1377][INFO    ][32435] Running scheduled job: __mine_interval
2019-05-26 22:53:27,231 [salt.minion      :1308][INFO    ][32435] User sudo_ubuntu Executing command cp.push_dir with jid 20190526225327223534
2019-05-26 22:53:27,252 [salt.minion      :1432][INFO    ][49583] Starting a new job with PID 49583
