2019-05-21 07:35:51,113 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-21 07:36:41,162 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-21 07:37:31,206 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-21 07:38:21,260 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-21 07:39:11,311 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-21 07:41:20,080 [salt.utils.decorators:613 ][WARNING ][2720] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 07:41:20,702 [salt.utils.decorators:613 ][WARNING ][2720] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 07:41:22,931 [salt.loaded.int.states.file:2298][WARNING ][2863] 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-21 07:41:28,803 [salt.state       :2022][WARNING ][2970] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-21 07:41:31,378 [salt.utils.decorators:613 ][WARNING ][2970] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 07:56:38,352 [salt.utils.decorators:613 ][WARNING ][2970] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:26:49,947 [salt.utils.decorators:613 ][WARNING ][2970] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:41:46,815 [salt.utils.decorators:613 ][WARNING ][2970] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:47:50,137 [salt.loaded.ext.module.maas:160 ][ERROR   ][2970] Failed for object network_discovery reason Authorization Error: 'Expired timestamp: given 1558428111 and now 1558428470 has a greater difference than threshold 300'
2019-05-21 08:47:51,160 [salt.state       :302 ][ERROR   ][2970] Module function maas.process_maas_config threw an exception. Exception: {'updated': [], 'errors': {'network_discovery': "Authorization Error: 'Expired timestamp: given 1558428111 and now 1558428470 has a greater difference than threshold 300'"}, 'success': ['enable_http_proxy', 'upstream_dns', 'commissioning_distro_series', 'default_osystem', 'active_discovery_interval', 'dnssec_validation', 'maas_name', 'enable_third_party_drivers', 'default_storage_layout', 'ntp_external_only', 'disk_erase_with_secure_erase', 'default_distro_series', 'default_min_hwe_kernel']}
2019-05-21 08:47:51,442 [salt.loaded.ext.module.maasng:1008][WARNING ][2970] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-21 08:47:51,443 [salt.loaded.ext.module.maasng:1011][WARNING ][2970] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-21 08:47:55,940 [salt.loaded.ext.module.maasng:1235][WARNING ][2970] Ignoring parameter vlan:0
2019-05-21 08:47:57,618 [salt.utils.decorators:613 ][WARNING ][2970] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:48:00,584 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27234] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-21 08:48:00,617 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27234] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-21 08:48:00,640 [salt.utils.parsers:1051][WARNING ][363] Minion received a SIGTERM. Exiting.
2019-05-21 08:48:01,714 [salt.cli.daemons :293 ][INFO    ][27296] Setting up the Salt Minion "mas01.mcp-ovs-dpdk-ha.local"
2019-05-21 08:48:01,810 [salt.cli.daemons :82  ][INFO    ][27296] Starting up the Salt Minion
2019-05-21 08:48:01,811 [salt.utils.event :1017][INFO    ][27296] Starting pull socket on /var/run/salt/minion/minion_event_967fbee23e_pull.ipc
2019-05-21 08:48:02,662 [salt.minion      :976 ][INFO    ][27296] Creating minion process manager
2019-05-21 08:48:04,110 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][27296] Executing command ['date', '+%z'] in directory '/root'
2019-05-21 08:48:04,129 [salt.utils.schedule:568 ][INFO    ][27296] Updating job settings for scheduled job: __mine_interval
2019-05-21 08:48:04,131 [salt.minion      :1108][INFO    ][27296] Added mine.update to scheduler
2019-05-21 08:48:04,134 [salt.minion      :1975][INFO    ][27296] Minion is starting as user 'root'
2019-05-21 08:48:04,145 [salt.minion      :2336][INFO    ][27296] Minion is ready to receive requests!
2019-05-21 08:48:08,780 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521084808767740
2019-05-21 08:48:08,802 [salt.minion      :1432][INFO    ][27376] Starting a new job with PID 27376
2019-05-21 08:48:12,592 [salt.state       :915 ][INFO    ][27376] Loading fresh modules for state activity
2019-05-21 08:48:13,274 [salt.state       :1780][INFO    ][27376] Running state [maas-region-controller] at time 08:48:13.274745
2019-05-21 08:48:13,275 [salt.state       :1813][INFO    ][27376] Executing state pkg.installed for [maas-region-controller]
2019-05-21 08:48:13,275 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-21 08:48:13,370 [salt.state       :300 ][INFO    ][27376] All specified packages are already installed
2019-05-21 08:48:13,370 [salt.state       :1951][INFO    ][27376] Completed state [maas-region-controller] at time 08:48:13.370512 duration_in_ms=95.766
2019-05-21 08:48:13,370 [salt.state       :1780][INFO    ][27376] Running state [python-oauth] at time 08:48:13.370870
2019-05-21 08:48:13,371 [salt.state       :1813][INFO    ][27376] Executing state pkg.installed for [python-oauth]
2019-05-21 08:48:13,378 [salt.state       :300 ][INFO    ][27376] All specified packages are already installed
2019-05-21 08:48:13,378 [salt.state       :1951][INFO    ][27376] Completed state [python-oauth] at time 08:48:13.378394 duration_in_ms=7.524
2019-05-21 08:48:13,381 [salt.state       :1780][INFO    ][27376] Running state [/etc/maas/regiond.conf] at time 08:48:13.381739
2019-05-21 08:48:13,382 [salt.state       :1813][INFO    ][27376] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-21 08:48:13,430 [salt.state       :300 ][INFO    ][27376] No changes needed to be made
2019-05-21 08:48:13,430 [salt.state       :1951][INFO    ][27376] Completed state [/etc/maas/regiond.conf] at time 08:48:13.430394 duration_in_ms=48.654
2019-05-21 08:48:13,431 [salt.state       :1780][INFO    ][27376] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 08:48:13.431150
2019-05-21 08:48:13,431 [salt.state       :1813][INFO    ][27376] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-21 08:48:13,506 [salt.state       :300 ][INFO    ][27376] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-21 08:48:13,507 [salt.state       :1951][INFO    ][27376] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 08:48:13.507043 duration_in_ms=75.894
2019-05-21 08:48:13,507 [salt.state       :1780][INFO    ][27376] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:48:13.507613
2019-05-21 08:48:13,507 [salt.state       :1813][INFO    ][27376] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-21 08:48:13,538 [salt.state       :300 ][INFO    ][27376] No changes needed to be made
2019-05-21 08:48:13,538 [salt.state       :1951][INFO    ][27376] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:48:13.538601 duration_in_ms=30.988
2019-05-21 08:48:13,539 [salt.state       :1780][INFO    ][27376] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:48:13.539135
2019-05-21 08:48:13,539 [salt.state       :1813][INFO    ][27376] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-21 08:48:13,568 [salt.state       :300 ][INFO    ][27376] No changes needed to be made
2019-05-21 08:48:13,568 [salt.state       :1951][INFO    ][27376] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 08:48:13.568481 duration_in_ms=29.346
2019-05-21 08:48:13,569 [salt.state       :1780][INFO    ][27376] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 08:48:13.569041
2019-05-21 08:48:13,569 [salt.state       :1813][INFO    ][27376] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-21 08:48:13,595 [salt.state       :300 ][INFO    ][27376] No changes needed to be made
2019-05-21 08:48:13,595 [salt.state       :1951][INFO    ][27376] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 08:48:13.595245 duration_in_ms=26.204
2019-05-21 08:48:13,595 [salt.state       :1780][INFO    ][27376] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 08:48:13.595758
2019-05-21 08:48:13,596 [salt.state       :1813][INFO    ][27376] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-21 08:48:13,608 [salt.state       :300 ][INFO    ][27376] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-21 08:48:13,608 [salt.state       :1951][INFO    ][27376] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 08:48:13.608460 duration_in_ms=12.703
2019-05-21 08:48:13,609 [salt.state       :1780][INFO    ][27376] Running state [a2enmod headers] at time 08:48:13.609737
2019-05-21 08:48:13,610 [salt.state       :1813][INFO    ][27376] Executing state cmd.run for [a2enmod headers]
2019-05-21 08:48:13,610 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command 'a2enmod headers' in directory '/root'
2019-05-21 08:48:13,684 [salt.state       :300 ][INFO    ][27376] {'pid': 27396, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-21 08:48:13,684 [salt.state       :1951][INFO    ][27376] Completed state [a2enmod headers] at time 08:48:13.684678 duration_in_ms=74.942
2019-05-21 08:48:13,685 [salt.state       :1780][INFO    ][27376] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 08:48:13.685183
2019-05-21 08:48:13,685 [salt.state       :1813][INFO    ][27376] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-21 08:48:13,700 [salt.state       :300 ][INFO    ][27376] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-21 08:48:13,700 [salt.state       :1951][INFO    ][27376] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 08:48:13.700442 duration_in_ms=15.259
2019-05-21 08:48:13,701 [salt.state       :1780][INFO    ][27376] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 08:48:13.700981
2019-05-21 08:48:13,701 [salt.state       :1813][INFO    ][27376] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-21 08:48:13,758 [salt.state       :300 ][INFO    ][27376] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-21 08:48:13,758 [salt.state       :1951][INFO    ][27376] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 08:48:13.758520 duration_in_ms=57.539
2019-05-21 08:48:13,758 [salt.state       :1780][INFO    ][27376] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 08:48:13.758899
2019-05-21 08:48:13,759 [salt.state       :1813][INFO    ][27376] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-21 08:48:13,806 [salt.state       :300 ][INFO    ][27376] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-21 08:48:13,806 [salt.state       :1951][INFO    ][27376] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 08:48:13.806507 duration_in_ms=47.608
2019-05-21 08:48:13,806 [salt.state       :1780][INFO    ][27376] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 08:48:13.806856
2019-05-21 08:48:13,807 [salt.state       :1813][INFO    ][27376] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-21 08:48:13,854 [salt.state       :300 ][INFO    ][27376] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-21 08:48:13,854 [salt.state       :1951][INFO    ][27376] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 08:48:13.854258 duration_in_ms=47.402
2019-05-21 08:48:13,854 [salt.state       :1780][INFO    ][27376] Running state [/root/.pgpass] at time 08:48:13.854459
2019-05-21 08:48:13,854 [salt.state       :1813][INFO    ][27376] Executing state file.managed for [/root/.pgpass]
2019-05-21 08:48:13,895 [salt.state       :300 ][INFO    ][27376] File /root/.pgpass is in the correct state
2019-05-21 08:48:13,896 [salt.state       :1951][INFO    ][27376] Completed state [/root/.pgpass] at time 08:48:13.896149 duration_in_ms=41.689
2019-05-21 08:48:13,899 [salt.state       :1780][INFO    ][27376] Running state [maas-region syncdb --noinput] at time 08:48:13.899622
2019-05-21 08:48:13,899 [salt.state       :1813][INFO    ][27376] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-21 08:48:13,900 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-21 08:48:15,883 [salt.state       :300 ][INFO    ][27376] {'pid': 27409, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: sites, piston3, maasserver, contenttypes, auth, sessions, 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-21 08:48:15,884 [salt.state       :1951][INFO    ][27376] Completed state [maas-region syncdb --noinput] at time 08:48:15.884033 duration_in_ms=1984.411
2019-05-21 08:48:15,884 [salt.state       :2022][WARNING ][27376] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-21 08:48:15,885 [salt.state       :1780][INFO    ][27376] Running state [maas-regiond] at time 08:48:15.885283
2019-05-21 08:48:15,885 [salt.state       :1813][INFO    ][27376] Executing state service.running for [maas-regiond]
2019-05-21 08:48:15,886 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-21 08:48:15,923 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-21 08:48:15,941 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-21 08:48:15,958 [salt.state       :300 ][INFO    ][27376] The service maas-regiond is already running
2019-05-21 08:48:15,958 [salt.state       :1951][INFO    ][27376] Completed state [maas-regiond] at time 08:48:15.958424 duration_in_ms=73.141
2019-05-21 08:48:15,959 [salt.state       :1780][INFO    ][27376] Running state [bind9] at time 08:48:15.959764
2019-05-21 08:48:15,960 [salt.state       :1813][INFO    ][27376] Executing state service.running for [bind9]
2019-05-21 08:48:15,960 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-21 08:48:15,979 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-21 08:48:15,996 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-21 08:48:16,013 [salt.state       :300 ][INFO    ][27376] The service bind9 is already running
2019-05-21 08:48:16,013 [salt.state       :1951][INFO    ][27376] Completed state [bind9] at time 08:48:16.013640 duration_in_ms=53.876
2019-05-21 08:48:16,015 [salt.state       :1780][INFO    ][27376] Running state [apache2] at time 08:48:16.015148
2019-05-21 08:48:16,015 [salt.state       :1813][INFO    ][27376] Executing state service.running for [apache2]
2019-05-21 08:48:16,016 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-21 08:48:16,035 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-21 08:48:16,053 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-21 08:48:16,078 [salt.state       :300 ][INFO    ][27376] The service apache2 is already running
2019-05-21 08:48:16,078 [salt.state       :1951][INFO    ][27376] Completed state [apache2] at time 08:48:16.078733 duration_in_ms=63.584
2019-05-21 08:48:16,081 [salt.state       :1780][INFO    ][27376] Running state [maasng.wait_for_http_code] at time 08:48:16.080997
2019-05-21 08:48:16,081 [salt.state       :1813][INFO    ][27376] Executing state module.run for [maasng.wait_for_http_code]
2019-05-21 08:48:16,082 [salt.utils.decorators:613 ][WARNING ][27376] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:48:16,218 [salt.state       :300 ][INFO    ][27376] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-21 08:48:16,219 [salt.state       :1951][INFO    ][27376] Completed state [maasng.wait_for_http_code] at time 08:48:16.219001 duration_in_ms=138.002
2019-05-21 08:48:16,220 [salt.state       :1780][INFO    ][27376] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 08:48:16.220549
2019-05-21 08:48:16,221 [salt.state       :1813][INFO    ][27376] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-21 08:48:16,221 [salt.state       :300 ][INFO    ][27376] /var/lib/maas/.setup_admin exists
2019-05-21 08:48:16,222 [salt.state       :1951][INFO    ][27376] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 08:48:16.222191 duration_in_ms=1.641
2019-05-21 08:48:16,223 [salt.state       :1780][INFO    ][27376] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:48:16.223365
2019-05-21 08:48:16,223 [salt.state       :1813][INFO    ][27376] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 08:48:16,224 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27376] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 08:48:17,573 [salt.state       :300 ][INFO    ][27376] {'pid': 27431, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 08:48:17,574 [salt.state       :1951][INFO    ][27376] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:48:17.574257 duration_in_ms=1350.894
2019-05-21 08:48:17,577 [salt.state       :1780][INFO    ][27376] Running state [maas_region_boot_source_resources_mirror] at time 08:48:17.577558
2019-05-21 08:48:17,577 [salt.state       :1813][INFO    ][27376] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-21 08:48:17,653 [salt.state       :300 ][INFO    ][27376] {'changes': {}}
2019-05-21 08:48:17,653 [salt.state       :1951][INFO    ][27376] Completed state [maas_region_boot_source_resources_mirror] at time 08:48:17.653452 duration_in_ms=75.891
2019-05-21 08:48:17,654 [salt.state       :1780][INFO    ][27376] Running state [maasng.boot_resources_import] at time 08:48:17.654562
2019-05-21 08:48:17,655 [salt.state       :1813][INFO    ][27376] Executing state module.run for [maasng.boot_resources_import]
2019-05-21 08:48:17,655 [salt.utils.decorators:613 ][WARNING ][27376] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:48:17,751 [salt.loaded.ext.module.maasng:1600][INFO    ][27376] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-21 08:48:22,819 [salt.loaded.ext.module.maasng:1600][INFO    ][27376] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-21 08:48:23,880 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521084823867512
2019-05-21 08:48:23,903 [salt.minion      :1432][INFO    ][27453] Starting a new job with PID 27453
2019-05-21 08:48:23,927 [salt.minion      :1711][INFO    ][27453] Returning information for job: 20190521084823867512
2019-05-21 08:48:27,879 [salt.loaded.ext.module.maasng:1600][INFO    ][27376] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-21 08:48:33,095 [salt.state       :300 ][INFO    ][27376] {'ret': True}
2019-05-21 08:48:33,095 [salt.state       :1951][INFO    ][27376] Completed state [maasng.boot_resources_import] at time 08:48:33.095791 duration_in_ms=15441.227
2019-05-21 08:48:33,097 [salt.state       :1780][INFO    ][27376] Running state [maas_region_boot_sources_selection_xenial] at time 08:48:33.097660
2019-05-21 08:48:33,098 [salt.state       :1813][INFO    ][27376] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-21 08:48:33,352 [salt.state       :300 ][INFO    ][27376] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-21 08:48:33,352 [salt.state       :1951][INFO    ][27376] Completed state [maas_region_boot_sources_selection_xenial] at time 08:48:33.352741 duration_in_ms=255.08
2019-05-21 08:48:33,354 [salt.state       :1780][INFO    ][27376] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 08:48:33.354042
2019-05-21 08:48:33,354 [salt.state       :1813][INFO    ][27376] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-21 08:48:33,355 [salt.utils.decorators:613 ][WARNING ][27376] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:48:33,355 [salt.loaded.ext.module.maasng:1771][INFO    ][27376] boot-sources sync initiated for ALL Rack's
2019-05-21 08:48:34,196 [salt.state       :300 ][INFO    ][27376] {'ret': True}
2019-05-21 08:48:34,197 [salt.state       :1951][INFO    ][27376] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 08:48:34.197443 duration_in_ms=843.399
2019-05-21 08:48:34,199 [salt.state       :1780][INFO    ][27376] Running state [maas.process_maas_config] at time 08:48:34.199606
2019-05-21 08:48:34,200 [salt.state       :1813][INFO    ][27376] Executing state module.run for [maas.process_maas_config]
2019-05-21 08:48:34,200 [salt.utils.decorators:613 ][WARNING ][27376] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:48:34,201 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=enable_http_proxy value=True
2019-05-21 08:48:34,246 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=upstream_dns value=8.8.8.8
2019-05-21 08:48:34,292 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=commissioning_distro_series value=xenial
2019-05-21 08:48:37,097 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=default_osystem value=ubuntu
2019-05-21 08:48:37,144 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=active_discovery_interval value=600
2019-05-21 08:48:37,192 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=dnssec_validation value=no
2019-05-21 08:48:37,251 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=maas_name value=mas01
2019-05-21 08:48:37,301 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=network_discovery value=enabled
2019-05-21 08:48:37,388 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=enable_third_party_drivers value=True
2019-05-21 08:48:37,436 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=default_storage_layout value=lvm
2019-05-21 08:48:37,496 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=ntp_external_only value=True
2019-05-21 08:48:37,553 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-21 08:48:37,605 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=default_distro_series value=xenial
2019-05-21 08:48:37,684 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-21 08:48:37,818 [salt.state       :300 ][INFO    ][27376] {'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-21 08:48:37,818 [salt.state       :1951][INFO    ][27376] Completed state [maas.process_maas_config] at time 08:48:37.818678 duration_in_ms=3619.072
2019-05-21 08:48:37,819 [salt.state       :1780][INFO    ][27376] Running state [pxe_admin] at time 08:48:37.819586
2019-05-21 08:48:37,820 [salt.state       :1813][INFO    ][27376] Executing state maasng.fabric_present for [pxe_admin]
2019-05-21 08:48:37,865 [salt.loaded.ext.module.maasng:945 ][INFO    ][27376] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-21 08:48:37,913 [salt.loaded.ext.module.maasng:1008][WARNING ][27376] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-21 08:48:37,914 [salt.loaded.ext.module.maasng:1011][WARNING ][27376] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-21 08:48:37,967 [salt.state       :300 ][INFO    ][27376] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-21 08:48:37,967 [salt.state       :1951][INFO    ][27376] Completed state [pxe_admin] at time 08:48:37.967334 duration_in_ms=147.749
2019-05-21 08:48:37,967 [salt.state       :1780][INFO    ][27376] Running state [vlan 0] at time 08:48:37.967600
2019-05-21 08:48:37,967 [salt.state       :1813][INFO    ][27376] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-21 08:48:37,996 [salt.loaded.ext.module.maasng:945 ][INFO    ][27376] [{u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-05-21 08:48:38,093 [salt.loaded.ext.module.maasng:945 ][INFO    ][27376] [{u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-05-21 08:48:38,240 [salt.loaded.ext.module.maasng:945 ][INFO    ][27376] [{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'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-21 08:48:38,315 [salt.state       :300 ][INFO    ][27376] {'new': 'Vlan untagged was updated'}
2019-05-21 08:48:38,316 [salt.state       :1951][INFO    ][27376] Completed state [vlan 0] at time 08:48:38.316227 duration_in_ms=348.624
2019-05-21 08:48:38,318 [salt.state       :1780][INFO    ][27376] Running state [192.168.11.0/24] at time 08:48:38.318145
2019-05-21 08:48:38,318 [salt.state       :1813][INFO    ][27376] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-21 08:48:38,513 [salt.loaded.ext.module.maasng:945 ][INFO    ][27376] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-21 08:48:38,514 [salt.loaded.ext.module.maasng:1235][WARNING ][27376] Ignoring parameter vlan:0
2019-05-21 08:48:38,595 [salt.state       :300 ][INFO    ][27376] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-21 08:48:38,595 [salt.state       :1951][INFO    ][27376] Completed state [192.168.11.0/24] at time 08:48:38.595402 duration_in_ms=277.257
2019-05-21 08:48:38,596 [salt.state       :1780][INFO    ][27376] Running state [maas_create_iprange_1] at time 08:48:38.596773
2019-05-21 08:48:38,597 [salt.state       :1813][INFO    ][27376] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-21 08:48:38,648 [salt.state       :300 ][INFO    ][27376] Iprange maas_create_iprange_1 already exist.
2019-05-21 08:48:38,648 [salt.state       :1951][INFO    ][27376] Completed state [maas_create_iprange_1] at time 08:48:38.648632 duration_in_ms=51.858
2019-05-21 08:48:38,649 [salt.state       :1780][INFO    ][27376] Running state [vlan 0] at time 08:48:38.649295
2019-05-21 08:48:38,650 [salt.state       :1813][INFO    ][27376] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-21 08:48:38,683 [salt.loaded.ext.module.maasng:945 ][INFO    ][27376] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-21 08:48:38,779 [salt.loaded.ext.module.maasng:945 ][INFO    ][27376] [{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'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-21 08:48:38,989 [salt.loaded.ext.module.maasng:945 ][INFO    ][27376] [{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'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-21 08:48:39,085 [salt.state       :300 ][INFO    ][27376] {'new': 'Vlan untagged was updated'}
2019-05-21 08:48:39,085 [salt.state       :1951][INFO    ][27376] Completed state [vlan 0] at time 08:48:39.085845 duration_in_ms=436.551
2019-05-21 08:48:39,086 [salt.state       :1780][INFO    ][27376] Running state [opnfv] at time 08:48:39.086783
2019-05-21 08:48:39,087 [salt.state       :1813][INFO    ][27376] Executing state maasng.sshkey_present for [opnfv]
2019-05-21 08:48:39,138 [salt.loaded.ext.module.maasng:1903][INFO    ][27376] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-05-21 08:48:39,139 [salt.state       :300 ][INFO    ][27376] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-21 08:48:39,139 [salt.state       :1951][INFO    ][27376] Completed state [opnfv] at time 08:48:39.139556 duration_in_ms=52.773
2019-05-21 08:48:39,140 [salt.state       :1780][INFO    ][27376] Running state [maas.process_tags] at time 08:48:39.140410
2019-05-21 08:48:39,140 [salt.state       :1813][INFO    ][27376] Executing state module.run for [maas.process_tags]
2019-05-21 08:48:39,141 [salt.utils.decorators:613 ][WARNING ][27376] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:48:39,192 [salt.loaded.ext.module.maas:92  ][INFO    ][27376] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-05-21 08:48:39,274 [salt.state       :300 ][INFO    ][27376] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-05-21 08:48:39,274 [salt.state       :1951][INFO    ][27376] Completed state [maas.process_tags] at time 08:48:39.274839 duration_in_ms=134.429
2019-05-21 08:48:39,278 [salt.minion      :1711][INFO    ][27376] Returning information for job: 20190521084808767740
2019-05-21 08:48:39,864 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521084839853292
2019-05-21 08:48:39,883 [salt.minion      :1432][INFO    ][27868] Starting a new job with PID 27868
2019-05-21 08:48:43,521 [salt.state       :915 ][INFO    ][27868] Loading fresh modules for state activity
2019-05-21 08:48:43,580 [salt.fileclient  :1219][INFO    ][27868] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-05-21 08:48:43,621 [salt.state       :1780][INFO    ][27868] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:48:43.621495
2019-05-21 08:48:43,621 [salt.state       :1813][INFO    ][27868] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 08:48:43,623 [salt.loaded.int.module.cmdmod:395 ][INFO    ][27868] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 08:48:45,024 [salt.state       :300 ][INFO    ][27868] {'pid': 27891, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 08:48:45,024 [salt.state       :1951][INFO    ][27868] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:48:45.024915 duration_in_ms=1403.42
2019-05-21 08:48:45,026 [salt.state       :1780][INFO    ][27868] Running state [maas.process_machines] at time 08:48:45.026418
2019-05-21 08:48:45,026 [salt.state       :1813][INFO    ][27868] Executing state module.run for [maas.process_machines]
2019-05-21 08:48:45,026 [salt.utils.decorators:613 ][WARNING ][27868] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:48:45,086 [salt.loaded.ext.module.maas:412 ][WARNING ][27868] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 08:48:45,086 [salt.loaded.ext.module.maas:92  ][INFO    ][27868] machine hostname=cmp002 power_type=ipmi mac_addresses=00:25:b5:a0:00:6a power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 08:48:46,670 [salt.loaded.ext.module.maas:412 ][WARNING ][27868] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 08:48:46,671 [salt.loaded.ext.module.maas:92  ][INFO    ][27868] machine hostname=cmp001 power_type=ipmi mac_addresses=00:25:b5:a0:00:5a power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 08:48:48,119 [salt.loaded.ext.module.maas:412 ][WARNING ][27868] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 08:48:48,120 [salt.loaded.ext.module.maas:92  ][INFO    ][27868] machine hostname=kvm01 power_type=ipmi mac_addresses=00:25:b5:a0:00:2a power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 08:48:49,623 [salt.loaded.ext.module.maas:412 ][WARNING ][27868] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 08:48:49,623 [salt.loaded.ext.module.maas:92  ][INFO    ][27868] machine hostname=kvm03 power_type=ipmi mac_addresses=00:25:b5:a0:00:4a power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 08:48:51,162 [salt.loaded.ext.module.maas:412 ][WARNING ][27868] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 08:48:51,162 [salt.loaded.ext.module.maas:92  ][INFO    ][27868] machine hostname=kvm02 power_type=ipmi mac_addresses=00:25:b5:a0:00:3a power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 08:48:52,570 [salt.state       :300 ][INFO    ][27868] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-21 08:48:52,571 [salt.state       :1951][INFO    ][27868] Completed state [maas.process_machines] at time 08:48:52.571020 duration_in_ms=7544.599
2019-05-21 08:48:52,574 [salt.minion      :1711][INFO    ][27868] Returning information for job: 20190521084839853292
2019-05-21 08:49:23,693 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521084923679865
2019-05-21 08:49:23,714 [salt.minion      :1432][INFO    ][28187] Starting a new job with PID 28187
2019-05-21 08:49:27,422 [salt.state       :915 ][INFO    ][28187] Loading fresh modules for state activity
2019-05-21 08:49:27,475 [salt.fileclient  :1219][INFO    ][28187] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-21 08:49:27,518 [salt.state       :1780][INFO    ][28187] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:49:27.517998
2019-05-21 08:49:27,518 [salt.state       :1813][INFO    ][28187] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 08:49:27,520 [salt.loaded.int.module.cmdmod:395 ][INFO    ][28187] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 08:49:28,978 [salt.state       :300 ][INFO    ][28187] {'pid': 28209, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 08:49:28,978 [salt.state       :1951][INFO    ][28187] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:49:28.978749 duration_in_ms=1460.752
2019-05-21 08:49:28,980 [salt.state       :1780][INFO    ][28187] Running state [maas.wait_for_machine_status] at time 08:49:28.980170
2019-05-21 08:49:28,980 [salt.state       :1813][INFO    ][28187] Executing state module.run for [maas.wait_for_machine_status]
2019-05-21 08:49:28,980 [salt.utils.decorators:613 ][WARNING ][28187] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:49:29,842 [salt.loaded.ext.module.maas:1023][INFO    ][28187] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.14239097s left)
2019-05-21 08:49:38,813 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521084938801170
2019-05-21 08:49:38,832 [salt.minion      :1432][INFO    ][28246] Starting a new job with PID 28246
2019-05-21 08:49:38,854 [salt.minion      :1711][INFO    ][28246] Returning information for job: 20190521084938801170
2019-05-21 08:50:00,770 [salt.loaded.ext.module.maas:1023][INFO    ][28187] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.21429682s left)
2019-05-21 08:50:08,861 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085008848620
2019-05-21 08:50:08,883 [salt.minion      :1432][INFO    ][28266] Starting a new job with PID 28266
2019-05-21 08:50:08,908 [salt.minion      :1711][INFO    ][28266] Returning information for job: 20190521085008848620
2019-05-21 08:50:32,064 [salt.loaded.ext.module.maas:1023][INFO    ][28187] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1436.92056489s left)
2019-05-21 08:50:38,949 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085038937678
2019-05-21 08:50:38,970 [salt.minion      :1432][INFO    ][28437] Starting a new job with PID 28437
2019-05-21 08:50:38,991 [salt.minion      :1711][INFO    ][28437] Returning information for job: 20190521085038937678
2019-05-21 08:51:03,325 [salt.loaded.ext.module.maas:1023][INFO    ][28187] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.66008997s left)
2019-05-21 08:51:08,993 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085108980727
2019-05-21 08:51:09,016 [salt.minion      :1432][INFO    ][28553] Starting a new job with PID 28553
2019-05-21 08:51:09,041 [salt.minion      :1711][INFO    ][28553] Returning information for job: 20190521085108980727
2019-05-21 08:51:34,322 [salt.loaded.ext.module.maas:1023][INFO    ][28187] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.66265392s left)
2019-05-21 08:51:39,048 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085139034865
2019-05-21 08:51:39,070 [salt.minion      :1432][INFO    ][29309] Starting a new job with PID 29309
2019-05-21 08:51:39,093 [salt.minion      :1711][INFO    ][29309] Returning information for job: 20190521085139034865
2019-05-21 08:52:06,453 [salt.loaded.ext.module.maas:1023][INFO    ][28187] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.53157878s left)
2019-05-21 08:52:09,098 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085209085780
2019-05-21 08:52:09,120 [salt.minion      :1432][INFO    ][29337] Starting a new job with PID 29337
2019-05-21 08:52:09,145 [salt.minion      :1711][INFO    ][29337] Returning information for job: 20190521085209085780
2019-05-21 08:52:39,157 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085239144725
2019-05-21 08:52:39,179 [salt.minion      :1432][INFO    ][29524] Starting a new job with PID 29524
2019-05-21 08:52:39,202 [salt.minion      :1711][INFO    ][29524] Returning information for job: 20190521085239144725
2019-05-21 08:52:39,967 [salt.state       :300 ][INFO    ][28187] {'ret': True}
2019-05-21 08:52:39,967 [salt.state       :1951][INFO    ][28187] Completed state [maas.wait_for_machine_status] at time 08:52:39.967842 duration_in_ms=190987.67
2019-05-21 08:52:39,971 [salt.minion      :1711][INFO    ][28187] Returning information for job: 20190521084923679865
2019-05-21 08:52:40,603 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521085240589845
2019-05-21 08:52:40,625 [salt.minion      :1432][INFO    ][29533] Starting a new job with PID 29533
2019-05-21 08:52:44,427 [salt.state       :915 ][INFO    ][29533] Loading fresh modules for state activity
2019-05-21 08:52:44,478 [salt.fileclient  :1219][INFO    ][29533] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-21 08:52:44,571 [salt.state       :1780][INFO    ][29533] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:44.571009
2019-05-21 08:52:44,571 [salt.state       :1813][INFO    ][29533] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 08:52:44,573 [salt.loaded.int.module.cmdmod:395 ][INFO    ][29533] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 08:52:46,021 [salt.state       :300 ][INFO    ][29533] {'pid': 29540, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 08:52:46,021 [salt.state       :1951][INFO    ][29533] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:46.021421 duration_in_ms=1450.412
2019-05-21 08:52:46,022 [salt.state       :1780][INFO    ][29533] Running state [maas_machines_storage_cmp002_lvm] at time 08:52:46.022910
2019-05-21 08:52:46,023 [salt.state       :1813][INFO    ][29533] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-21 08:52:47,447 [salt.loaded.ext.module.maasng:610 ][INFO    ][29533] dpaq7b
2019-05-21 08:52:47,448 [salt.loaded.ext.module.maasng:626 ][INFO    ][29533] sda
2019-05-21 08:52:48,140 [salt.loaded.ext.module.maasng:361 ][INFO    ][29533] dpaq7b
2019-05-21 08:52:48,268 [salt.loaded.ext.module.maasng:367 ][INFO    ][29533] [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 4, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'dpaq7b', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'a4629a72-bc06-4776-ac9f-0e88c2803068', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dpaq7b', u'filesystem': {u'label': None, u'uuid': u'40bb696a-1bb9-40fb-b44f-cca214a1e967', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/4/partition/7', u'type': u'partition', u'id': 7, u'device_id': 4}], u'type': u'physical', u'serial': u'618e728372755980239b15112698bc66', u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/4/'}, {u'size': 2397988454400, u'block_size': 4096, u'uuid': u'bfd4cadc-ac5d-4fb7-bb2d-72b7e23591ec', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'id': 12, u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'dpaq7b', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'uuid': u'6bdb1c4c-e164-41e8-a54c-f211385457e1', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/12/'}]
2019-05-21 08:52:48,269 [salt.loaded.ext.module.maasng:632 ][INFO    ][29533] vgroot
2019-05-21 08:52:48,269 [salt.loaded.ext.module.maasng:635 ][INFO    ][29533] lvroot
2019-05-21 08:52:48,270 [salt.loaded.ext.module.maasng:639 ][INFO    ][29533] 107374182400
2019-05-21 08:52:49,032 [salt.loaded.ext.module.maasng:645 ][INFO    ][29533] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'modules-final', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/4/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 4, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'dpaq7b', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'd6b7dc03-e28c-457f-b449-bbef655e8d92', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dpaq7b', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'1da9d881-679f-42f5-a477-2c7306810a28', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/4/partition/9', u'type': u'partition', u'id': 9, u'device_id': 4}]}, u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'node_type_name': u'Machine', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'dpaq7b', u'power_state': u'on', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'virtualblockdevice_set': [{u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/14/', u'available_size': 0, u'uuid': u'4ee909c7-bafe-4d13-b89e-9f4f3381e5e2', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 14, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'dpaq7b', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'c09d43d7-400d-44b6-8f4a-7505712dea1a', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'partitions': []}], u'blockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/4/', u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'id': 4, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'dpaq7b', u'block_size': 4096, u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'd6b7dc03-e28c-457f-b449-bbef655e8d92', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dpaq7b', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'1da9d881-679f-42f5-a477-2c7306810a28', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/4/partition/9', u'type': u'partition', u'id': 9, u'device_id': 4}]}, {u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/14/', u'uuid': u'4ee909c7-bafe-4d13-b89e-9f4f3381e5e2', u'tags': [], u'type': u'virtual', u'id': 14, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'dpaq7b', u'block_size': 4096, u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'c09d43d7-400d-44b6-8f4a-7505712dea1a', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'model': None, u'partitions': []}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'ip_addresses': [u'192.168.11.42'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'dpaq7b', u'id': 9}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'mode': u'dhcp', u'id': 40}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'dpaq7b', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/interfaces/4/'}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'mode': u'dhcp', u'id': 40}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:6a', u'parents': [], u'system_id': u'dpaq7b', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/interfaces/4/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 45}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'enabled': True, u'effective_mtu': 1500, u'id': 12, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6b', u'parents': [], u'system_id': u'dpaq7b', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/interfaces/12/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 46}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'enabled': True, u'effective_mtu': 1500, u'id': 16, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6d', u'parents': [], u'system_id': u'dpaq7b', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/interfaces/16/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 42}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'enabled': True, u'effective_mtu': 1500, u'id': 11, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:6c', u'parents': [], u'system_id': u'dpaq7b', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/interfaces/11/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/4/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 4, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'dpaq7b', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'd6b7dc03-e28c-457f-b449-bbef655e8d92', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'dpaq7b', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'1da9d881-679f-42f5-a477-2c7306810a28', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/dpaq7b/blockdevices/4/partition/9', u'type': u'partition', u'id': 9, u'device_id': 4}]}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/dpaq7b/', u'distro_series': u'', u'memory_test_status': -1}
2019-05-21 08:52:49,034 [salt.state       :300 ][INFO    ][29533] {'new': {'storage_layout': 'lvm'}}
2019-05-21 08:52:49,034 [salt.state       :1951][INFO    ][29533] Completed state [maas_machines_storage_cmp002_lvm] at time 08:52:49.034771 duration_in_ms=3011.858
2019-05-21 08:52:49,035 [salt.state       :1780][INFO    ][29533] Running state [maas_machines_storage_cmp001_lvm] at time 08:52:49.035314
2019-05-21 08:52:49,035 [salt.state       :1813][INFO    ][29533] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-21 08:52:50,477 [salt.loaded.ext.module.maasng:610 ][INFO    ][29533] cf8sgr
2019-05-21 08:52:50,478 [salt.loaded.ext.module.maasng:626 ][INFO    ][29533] sda
2019-05-21 08:52:51,108 [salt.loaded.ext.module.maasng:361 ][INFO    ][29533] cf8sgr
2019-05-21 08:52:51,194 [salt.loaded.ext.module.maasng:367 ][INFO    ][29533] [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 3, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'cf8sgr', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'8f23c0a2-8050-4c54-be1c-ac29fb617839', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cf8sgr', u'filesystem': {u'label': None, u'uuid': u'a9f7f159-6176-4365-8d43-11a87ff8f6fb', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/3/partition/8', u'type': u'partition', u'id': 8, u'device_id': 3}], u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/3/'}, {u'size': 2397988454400, u'block_size': 4096, u'uuid': u'efe9a682-57e9-4c4d-85a5-b320136364ca', u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'id': 13, u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'cf8sgr', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'uuid': u'a40ec315-cfcb-4fd2-8fdd-356ea8e90228', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'model': None, u'partitions': [], u'type': u'virtual', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/13/'}]
2019-05-21 08:52:51,194 [salt.loaded.ext.module.maasng:632 ][INFO    ][29533] vgroot
2019-05-21 08:52:51,194 [salt.loaded.ext.module.maasng:635 ][INFO    ][29533] lvroot
2019-05-21 08:52:51,195 [salt.loaded.ext.module.maasng:639 ][INFO    ][29533] 107374182400
2019-05-21 08:52:51,751 [salt.loaded.ext.module.maasng:645 ][INFO    ][29533] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'swap_size': None, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'hwe-16.04', u'status_action': u'modules-final', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/3/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 3, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cf8sgr', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'6fb65c26-61b1-439d-9397-4394c3ba6358', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cf8sgr', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'ad108e23-8c3e-4ffb-8fbe-a4ba0e447a0a', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/3/partition/10', u'type': u'partition', u'id': 10, u'device_id': 3}]}, u'zone': {u'id': 1, u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'description': u'', u'name': u'default'}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'cf8sgr', u'power_state': u'on', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'virtualblockdevice_set': [{u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/15/', u'available_size': 0, u'uuid': u'868b3888-87ca-4854-a0b4-419458ec77c6', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 15, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cf8sgr', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'dcfb4c2a-4bb0-4470-8a5b-264ed3e79efe', u'fstype': u'ext4'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'model': None, u'partitions': []}], u'blockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/3/', u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'id': 3, u'name': u'sda', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'cf8sgr', u'block_size': 4096, u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'used_for': u'GPT partitioned with 1 partition', u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'6fb65c26-61b1-439d-9397-4394c3ba6358', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cf8sgr', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'ad108e23-8c3e-4ffb-8fbe-a4ba0e447a0a', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/3/partition/10', u'type': u'partition', u'id': 10, u'device_id': 3}]}, {u'size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/15/', u'uuid': u'868b3888-87ca-4854-a0b4-419458ec77c6', u'tags': [], u'type': u'virtual', u'id': 15, u'name': u'vgroot-lvroot', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'cf8sgr', u'block_size': 4096, u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'dcfb4c2a-4bb0-4470-8a5b-264ed3e79efe', u'fstype': u'ext4'}, u'id_path': None, u'available_size': 0, u'serial': None, u'used_for': u'ext4 formatted filesystem mounted at /', u'used_size': 107374182400, u'model': None, u'partitions': []}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'owner_data': {}, u'ip_addresses': [u'192.168.11.38'], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'cf8sgr', u'id': 10}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_interface': {u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 47}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'cf8sgr', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/interfaces/5/'}, u'interface_set': [{u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'mode': u'dhcp', u'id': 47}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'enabled': True, u'effective_mtu': 1500, u'id': 5, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'cf8sgr', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/interfaces/5/'}, {u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 48}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'enabled': True, u'effective_mtu': 1500, u'id': 9, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'system_id': u'cf8sgr', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/interfaces/9/'}, {u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 49}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'enabled': True, u'effective_mtu': 1500, u'id': 10, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'system_id': u'cf8sgr', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/interfaces/10/'}, {u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 50}], u'tags': [], u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'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'enabled': True, u'effective_mtu': 1500, u'id': 13, u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'system_id': u'cf8sgr', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/interfaces/13/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/3/', u'available_size': 0, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 3, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cf8sgr', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'partitions': [{u'size': 2397992648704, u'uuid': u'6fb65c26-61b1-439d-9397-4394c3ba6358', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cf8sgr', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'ad108e23-8c3e-4ffb-8fbe-a4ba0e447a0a', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/cf8sgr/blockdevices/3/partition/10', u'type': u'partition', u'id': 10, u'device_id': 3}]}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'node_type': 0, u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/cf8sgr/', u'distro_series': u'', u'memory_test_status': -1}
2019-05-21 08:52:51,752 [salt.state       :300 ][INFO    ][29533] {'new': {'storage_layout': 'lvm'}}
2019-05-21 08:52:51,752 [salt.state       :1951][INFO    ][29533] Completed state [maas_machines_storage_cmp001_lvm] at time 08:52:51.752636 duration_in_ms=2717.321
2019-05-21 08:52:51,754 [salt.minion      :1711][INFO    ][29533] Returning information for job: 20190521085240589845
2019-05-21 08:52:52,154 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521085252146049
2019-05-21 08:52:52,166 [salt.minion      :1432][INFO    ][29603] Starting a new job with PID 29603
2019-05-21 08:52:52,795 [salt.state       :915 ][INFO    ][29603] Loading fresh modules for state activity
2019-05-21 08:52:52,846 [salt.fileclient  :1219][INFO    ][29603] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-21 08:52:52,885 [salt.state       :1780][INFO    ][29603] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:52.885701
2019-05-21 08:52:52,886 [salt.state       :1813][INFO    ][29603] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 08:52:52,888 [salt.loaded.int.module.cmdmod:395 ][INFO    ][29603] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 08:52:54,140 [salt.state       :300 ][INFO    ][29603] {'pid': 29610, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 08:52:54,141 [salt.state       :1951][INFO    ][29603] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:52:54.141163 duration_in_ms=1255.463
2019-05-21 08:52:54,142 [salt.state       :1780][INFO    ][29603] Running state [maas.deploy_machines] at time 08:52:54.142214
2019-05-21 08:52:54,142 [salt.state       :1813][INFO    ][29603] Executing state module.run for [maas.deploy_machines]
2019-05-21 08:52:54,142 [salt.utils.decorators:613 ][WARNING ][29603] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:52:54,572 [salt.loaded.ext.module.maas:684 ][INFO    ][29603] deploymachines hwe_kernel=hwe-16.04 system_id=dpaq7b distro_series=xenial
2019-05-21 08:52:57,228 [salt.loaded.ext.module.maas:684 ][INFO    ][29603] deploymachines hwe_kernel=hwe-16.04 system_id=cf8sgr distro_series=xenial
2019-05-21 08:53:00,019 [salt.loaded.ext.module.maas:684 ][INFO    ][29603] deploymachines hwe_kernel=hwe-16.04 system_id=mfydxg distro_series=xenial
2019-05-21 08:53:02,724 [salt.loaded.ext.module.maas:684 ][INFO    ][29603] deploymachines hwe_kernel=hwe-16.04 system_id=6hkq78 distro_series=xenial
2019-05-21 08:53:04,936 [salt.loaded.ext.module.maas:684 ][INFO    ][29603] deploymachines hwe_kernel=hwe-16.04 system_id=dwe637 distro_series=xenial
2019-05-21 08:53:07,177 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085307165356
2019-05-21 08:53:07,198 [salt.minion      :1432][INFO    ][29876] Starting a new job with PID 29876
2019-05-21 08:53:07,221 [salt.minion      :1711][INFO    ][29876] Returning information for job: 20190521085307165356
2019-05-21 08:53:07,470 [salt.state       :300 ][INFO    ][29603] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-21 08:53:07,471 [salt.state       :1951][INFO    ][29603] Completed state [maas.deploy_machines] at time 08:53:07.471410 duration_in_ms=13329.193
2019-05-21 08:53:07,475 [salt.minion      :1711][INFO    ][29603] Returning information for job: 20190521085252146049
2019-05-21 08:53:08,087 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521085308073968
2019-05-21 08:53:08,110 [salt.minion      :1432][INFO    ][29891] Starting a new job with PID 29891
2019-05-21 08:53:11,827 [salt.state       :915 ][INFO    ][29891] Loading fresh modules for state activity
2019-05-21 08:53:11,856 [salt.fileclient  :1219][INFO    ][29891] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-21 08:53:11,881 [salt.state       :1780][INFO    ][29891] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:53:11.881413
2019-05-21 08:53:11,881 [salt.state       :1813][INFO    ][29891] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 08:53:11,882 [salt.loaded.int.module.cmdmod:395 ][INFO    ][29891] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 08:53:13,210 [salt.state       :300 ][INFO    ][29891] {'pid': 29906, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 08:53:13,210 [salt.state       :1951][INFO    ][29891] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 08:53:13.210825 duration_in_ms=1329.41
2019-05-21 08:53:13,214 [salt.state       :1780][INFO    ][29891] Running state [maas.wait_for_machine_status] at time 08:53:13.214045
2019-05-21 08:53:13,214 [salt.state       :1813][INFO    ][29891] Executing state module.run for [maas.wait_for_machine_status]
2019-05-21 08:53:13,215 [salt.utils.decorators:613 ][WARNING ][29891] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 08:53:16,820 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.40498209s left)
2019-05-21 08:53:23,120 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085323107892
2019-05-21 08:53:23,143 [salt.minion      :1432][INFO    ][29919] Starting a new job with PID 29919
2019-05-21 08:53:23,168 [salt.minion      :1711][INFO    ][29919] Returning information for job: 20190521085323107892
2019-05-21 08:53:51,062 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2212.16338801s left)
2019-05-21 08:53:53,165 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085353153527
2019-05-21 08:53:53,188 [salt.minion      :1432][INFO    ][29977] Starting a new job with PID 29977
2019-05-21 08:53:53,212 [salt.minion      :1711][INFO    ][29977] Returning information for job: 20190521085353153527
2019-05-21 08:54:23,236 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085423224333
2019-05-21 08:54:23,256 [salt.minion      :1432][INFO    ][29997] Starting a new job with PID 29997
2019-05-21 08:54:23,275 [salt.minion      :1711][INFO    ][29997] Returning information for job: 20190521085423224333
2019-05-21 08:54:24,583 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2178.64157009s left)
2019-05-21 08:54:53,278 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085453266230
2019-05-21 08:54:53,298 [salt.minion      :1432][INFO    ][30150] Starting a new job with PID 30150
2019-05-21 08:54:53,320 [salt.minion      :1711][INFO    ][30150] Returning information for job: 20190521085453266230
2019-05-21 08:54:57,051 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.17418408s left)
2019-05-21 08:55:23,335 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085523323089
2019-05-21 08:55:23,357 [salt.minion      :1432][INFO    ][30321] Starting a new job with PID 30321
2019-05-21 08:55:23,379 [salt.minion      :1711][INFO    ][30321] Returning information for job: 20190521085523323089
2019-05-21 08:55:30,431 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2112.793787s left)
2019-05-21 08:55:53,386 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085553373872
2019-05-21 08:55:53,408 [salt.minion      :1432][INFO    ][30929] Starting a new job with PID 30929
2019-05-21 08:55:53,433 [salt.minion      :1711][INFO    ][30929] Returning information for job: 20190521085553373872
2019-05-21 08:56:03,881 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.34372091s left)
2019-05-21 08:56:23,450 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085623437985
2019-05-21 08:56:23,473 [salt.minion      :1432][INFO    ][30950] Starting a new job with PID 30950
2019-05-21 08:56:23,496 [salt.minion      :1711][INFO    ][30950] Returning information for job: 20190521085623437985
2019-05-21 08:56:37,393 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2045.83211088s left)
2019-05-21 08:56:53,507 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085653495135
2019-05-21 08:56:53,530 [salt.minion      :1432][INFO    ][31272] Starting a new job with PID 31272
2019-05-21 08:56:53,553 [salt.minion      :1711][INFO    ][31272] Returning information for job: 20190521085653495135
2019-05-21 08:57:10,563 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2012.66227007s left)
2019-05-21 08:57:23,570 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085723557792
2019-05-21 08:57:23,593 [salt.minion      :1432][INFO    ][31303] Starting a new job with PID 31303
2019-05-21 08:57:23,616 [salt.minion      :1711][INFO    ][31303] Returning information for job: 20190521085723557792
2019-05-21 08:57:44,186 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.03888392s left)
2019-05-21 08:57:53,644 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085753632802
2019-05-21 08:57:53,667 [salt.minion      :1432][INFO    ][31708] Starting a new job with PID 31708
2019-05-21 08:57:53,691 [salt.minion      :1711][INFO    ][31708] Returning information for job: 20190521085753632802
2019-05-21 08:58:17,228 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1945.99714303s left)
2019-05-21 08:58:23,716 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085823703890
2019-05-21 08:58:23,738 [salt.minion      :1432][INFO    ][31735] Starting a new job with PID 31735
2019-05-21 08:58:23,760 [salt.minion      :1711][INFO    ][31735] Returning information for job: 20190521085823703890
2019-05-21 08:58:51,123 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1912.10186601s left)
2019-05-21 08:58:53,798 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085853785289
2019-05-21 08:58:53,821 [salt.minion      :1432][INFO    ][32153] Starting a new job with PID 32153
2019-05-21 08:58:53,845 [salt.minion      :1711][INFO    ][32153] Returning information for job: 20190521085853785289
2019-05-21 08:59:23,886 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085923878069
2019-05-21 08:59:23,907 [salt.minion      :1432][INFO    ][32174] Starting a new job with PID 32174
2019-05-21 08:59:23,935 [salt.minion      :1711][INFO    ][32174] Returning information for job: 20190521085923878069
2019-05-21 08:59:24,486 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1878.73885608s left)
2019-05-21 08:59:53,975 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521085953962915
2019-05-21 08:59:53,998 [salt.minion      :1432][INFO    ][32443] Starting a new job with PID 32443
2019-05-21 08:59:54,020 [salt.minion      :1711][INFO    ][32443] Returning information for job: 20190521085953962915
2019-05-21 08:59:57,982 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1845.24294591s left)
2019-05-21 09:00:24,061 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090024049316
2019-05-21 09:00:24,080 [salt.minion      :1432][INFO    ][32508] Starting a new job with PID 32508
2019-05-21 09:00:24,103 [salt.minion      :1711][INFO    ][32508] Returning information for job: 20190521090024049316
2019-05-21 09:00:31,088 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1812.13709998s left)
2019-05-21 09:00:54,228 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090054216677
2019-05-21 09:00:54,251 [salt.minion      :1432][INFO    ][32716] Starting a new job with PID 32716
2019-05-21 09:00:54,278 [salt.minion      :1711][INFO    ][32716] Returning information for job: 20190521090054216677
2019-05-21 09:01:04,389 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1778.835747s left)
2019-05-21 09:01:24,342 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090124329876
2019-05-21 09:01:24,362 [salt.minion      :1432][INFO    ][324] Starting a new job with PID 324
2019-05-21 09:01:24,380 [salt.minion      :1711][INFO    ][324] Returning information for job: 20190521090124329876
2019-05-21 09:01:37,767 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1745.45781803s left)
2019-05-21 09:01:54,445 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090154432500
2019-05-21 09:01:54,468 [salt.minion      :1432][INFO    ][694] Starting a new job with PID 694
2019-05-21 09:01:54,492 [salt.minion      :1711][INFO    ][694] Returning information for job: 20190521090154432500
2019-05-21 09:02:11,025 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1712.19985294s left)
2019-05-21 09:02:24,565 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090224552464
2019-05-21 09:02:24,586 [salt.minion      :1432][INFO    ][722] Starting a new job with PID 722
2019-05-21 09:02:24,609 [salt.minion      :1711][INFO    ][722] Returning information for job: 20190521090224552464
2019-05-21 09:02:44,492 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1678.73252511s left)
2019-05-21 09:02:54,681 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090254668999
2019-05-21 09:02:54,703 [salt.minion      :1432][INFO    ][767] Starting a new job with PID 767
2019-05-21 09:02:54,726 [salt.minion      :1711][INFO    ][767] Returning information for job: 20190521090254668999
2019-05-21 09:03:17,977 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1645.24815989s left)
2019-05-21 09:03:24,816 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090324802795
2019-05-21 09:03:24,838 [salt.minion      :1432][INFO    ][797] Starting a new job with PID 797
2019-05-21 09:03:24,863 [salt.minion      :1711][INFO    ][797] Returning information for job: 20190521090324802795
2019-05-21 09:03:51,327 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1611.89837193s left)
2019-05-21 09:03:54,952 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090354939862
2019-05-21 09:03:54,975 [salt.minion      :1432][INFO    ][840] Starting a new job with PID 840
2019-05-21 09:03:54,999 [salt.minion      :1711][INFO    ][840] Returning information for job: 20190521090354939862
2019-05-21 09:04:24,617 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1578.60767388s left)
2019-05-21 09:04:25,101 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090425089022
2019-05-21 09:04:25,123 [salt.minion      :1432][INFO    ][872] Starting a new job with PID 872
2019-05-21 09:04:25,147 [salt.minion      :1711][INFO    ][872] Returning information for job: 20190521090425089022
2019-05-21 09:04:55,256 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090455245437
2019-05-21 09:04:55,277 [salt.minion      :1432][INFO    ][922] Starting a new job with PID 922
2019-05-21 09:04:55,300 [salt.minion      :1711][INFO    ][922] Returning information for job: 20190521090455245437
2019-05-21 09:04:58,212 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1545.01325798s left)
2019-05-21 09:05:25,428 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090525416370
2019-05-21 09:05:25,450 [salt.minion      :1432][INFO    ][956] Starting a new job with PID 956
2019-05-21 09:05:25,469 [salt.minion      :1711][INFO    ][956] Returning information for job: 20190521090525416370
2019-05-21 09:05:31,506 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1511.71929002s left)
2019-05-21 09:05:55,598 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090555585979
2019-05-21 09:05:55,620 [salt.minion      :1432][INFO    ][1004] Starting a new job with PID 1004
2019-05-21 09:05:55,644 [salt.minion      :1711][INFO    ][1004] Returning information for job: 20190521090555585979
2019-05-21 09:06:04,880 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1478.34512806s left)
2019-05-21 09:06:25,791 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090625778621
2019-05-21 09:06:25,812 [salt.minion      :1432][INFO    ][1159] Starting a new job with PID 1159
2019-05-21 09:06:25,835 [salt.minion      :1711][INFO    ][1159] Returning information for job: 20190521090625778621
2019-05-21 09:06:38,431 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1444.79383492s left)
2019-05-21 09:06:55,991 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090655977717
2019-05-21 09:06:56,013 [salt.minion      :1432][INFO    ][1207] Starting a new job with PID 1207
2019-05-21 09:06:56,038 [salt.minion      :1711][INFO    ][1207] Returning information for job: 20190521090655977717
2019-05-21 09:07:11,739 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1411.48600006s left)
2019-05-21 09:07:26,203 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090726191214
2019-05-21 09:07:26,226 [salt.minion      :1432][INFO    ][1237] Starting a new job with PID 1237
2019-05-21 09:07:26,247 [salt.minion      :1711][INFO    ][1237] Returning information for job: 20190521090726191214
2019-05-21 09:07:45,224 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1378.00061488s left)
2019-05-21 09:07:56,429 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090756416740
2019-05-21 09:07:56,451 [salt.minion      :1432][INFO    ][1284] Starting a new job with PID 1284
2019-05-21 09:07:56,475 [salt.minion      :1711][INFO    ][1284] Returning information for job: 20190521090756416740
2019-05-21 09:08:18,770 [salt.loaded.ext.module.maas:1023][INFO    ][29891] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1344.45520806s left)
2019-05-21 09:08:26,451 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090826438653
2019-05-21 09:08:26,474 [salt.minion      :1432][INFO    ][1313] Starting a new job with PID 1313
2019-05-21 09:08:26,497 [salt.minion      :1711][INFO    ][1313] Returning information for job: 20190521090826438653
2019-05-21 09:08:51,004 [salt.loaded.ext.module.maas:993 ][INFO    ][29891] Machine mfydxg mark broken
2019-05-21 09:08:51,748 [salt.loaded.ext.module.maas:996 ][INFO    ][29891] Machine mfydxg mark fixed
2019-05-21 09:08:53,016 [salt.loaded.ext.module.maas:684 ][INFO    ][29891] deploymachines hwe_kernel=hwe-16.04 system_id=mfydxg distro_series=xenial
2019-05-21 09:08:55,342 [salt.loaded.ext.module.maas:160 ][ERROR   ][29891] Failed for object kvm01 reason Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node.
2019-05-21 09:08:55,344 [salt.state       :302 ][ERROR   ][29891] Module function maas.wait_for_machine_status threw an exception. Exception: {'updated': ['cmp002', 'cmp001', 'kvm03', 'kvm02'], 'errors': {'kvm01': "Unable to change power state to 'cycle' for node kvm01: another action is already in progress for that node."}, 'success': []}
2019-05-21 09:08:55,344 [salt.state       :1951][INFO    ][29891] Completed state [maas.wait_for_machine_status] at time 09:08:55.344587 duration_in_ms=942130.537
2019-05-21 09:08:55,350 [salt.minion      :1711][INFO    ][29891] Returning information for job: 20190521085308073968
2019-05-21 09:09:06,099 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command pillar.get with jid 20190521090906087051
2019-05-21 09:09:06,120 [salt.minion      :1432][INFO    ][1434] Starting a new job with PID 1434
2019-05-21 09:09:06,129 [salt.minion      :1711][INFO    ][1434] Returning information for job: 20190521090906087051
2019-05-21 09:09:06,620 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command service.status with jid 20190521090906613752
2019-05-21 09:09:06,641 [salt.minion      :1432][INFO    ][1439] Starting a new job with PID 1439
2019-05-21 09:09:07,027 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][1439] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-21 09:09:07,059 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][1439] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-21 09:09:07,073 [salt.minion      :1711][INFO    ][1439] Returning information for job: 20190521090906613752
2019-05-21 09:09:07,617 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521090907604530
2019-05-21 09:09:07,636 [salt.minion      :1432][INFO    ][1450] Starting a new job with PID 1450
2019-05-21 09:09:11,378 [salt.state       :915 ][INFO    ][1450] Loading fresh modules for state activity
2019-05-21 09:09:11,720 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command 'salt-minion --version' in directory '/root'
2019-05-21 09:09:12,082 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command 'salt-minion --version' in directory '/root'
2019-05-21 09:09:12,971 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command 'salt-minion --version' in directory '/root'
2019-05-21 09:09:13,331 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command 'salt-minion --version' in directory '/root'
2019-05-21 09:09:14,698 [salt.state       :1780][INFO    ][1450] Running state [salt-minion] at time 09:09:14.698492
2019-05-21 09:09:14,698 [salt.state       :1813][INFO    ][1450] Executing state pkg.installed for [salt-minion]
2019-05-21 09:09:14,699 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-21 09:09:14,796 [salt.state       :300 ][INFO    ][1450] All specified packages are already installed
2019-05-21 09:09:14,797 [salt.state       :1951][INFO    ][1450] Completed state [salt-minion] at time 09:09:14.797186 duration_in_ms=98.695
2019-05-21 09:09:14,797 [salt.state       :1780][INFO    ][1450] Running state [salt_minion_dependency_packages] at time 09:09:14.797605
2019-05-21 09:09:14,798 [salt.state       :1813][INFO    ][1450] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-21 09:09:14,806 [salt.state       :300 ][INFO    ][1450] All specified packages are already installed
2019-05-21 09:09:14,806 [salt.state       :1951][INFO    ][1450] Completed state [salt_minion_dependency_packages] at time 09:09:14.806366 duration_in_ms=8.761
2019-05-21 09:09:14,810 [salt.state       :1780][INFO    ][1450] Running state [/etc/salt/minion.d/minion.conf] at time 09:09:14.810144
2019-05-21 09:09:14,810 [salt.state       :1813][INFO    ][1450] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-21 09:09:15,037 [salt.state       :300 ][INFO    ][1450] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-21 09:09:15,038 [salt.state       :1951][INFO    ][1450] Completed state [/etc/salt/minion.d/minion.conf] at time 09:09:15.038055 duration_in_ms=227.912
2019-05-21 09:09:15,038 [salt.state       :1780][INFO    ][1450] Running state [python-netaddr] at time 09:09:15.038243
2019-05-21 09:09:15,038 [salt.state       :1813][INFO    ][1450] Executing state pkg.installed for [python-netaddr]
2019-05-21 09:09:15,042 [salt.state       :300 ][INFO    ][1450] All specified packages are already installed
2019-05-21 09:09:15,042 [salt.state       :1951][INFO    ][1450] Completed state [python-netaddr] at time 09:09:15.042959 duration_in_ms=4.715
2019-05-21 09:09:15,045 [salt.state       :1780][INFO    ][1450] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 09:09:15.044998
2019-05-21 09:09:15,045 [salt.state       :1813][INFO    ][1450] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-21 09:09:15,055 [salt.state       :300 ][INFO    ][1450] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-21 09:09:15,055 [salt.state       :1951][INFO    ][1450] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 09:09:15.055629 duration_in_ms=10.63
2019-05-21 09:09:15,056 [salt.state       :1780][INFO    ][1450] Running state [salt-minion] at time 09:09:15.056255
2019-05-21 09:09:15,056 [salt.state       :1813][INFO    ][1450] Executing state service.running for [salt-minion]
2019-05-21 09:09:15,056 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-21 09:09:15,089 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-21 09:09:15,108 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-21 09:09:15,126 [salt.state       :300 ][INFO    ][1450] The service salt-minion is already running
2019-05-21 09:09:15,127 [salt.state       :1951][INFO    ][1450] Completed state [salt-minion] at time 09:09:15.127115 duration_in_ms=70.858
2019-05-21 09:09:15,129 [salt.state       :1780][INFO    ][1450] Running state [/etc/salt/grains.d] at time 09:09:15.129523
2019-05-21 09:09:15,130 [salt.state       :1813][INFO    ][1450] Executing state file.directory for [/etc/salt/grains.d]
2019-05-21 09:09:15,131 [salt.state       :300 ][INFO    ][1450] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-21 09:09:15,131 [salt.state       :1951][INFO    ][1450] Completed state [/etc/salt/grains.d] at time 09:09:15.131767 duration_in_ms=2.244
2019-05-21 09:09:15,132 [salt.state       :1780][INFO    ][1450] Running state [/etc/salt/grains] at time 09:09:15.132811
2019-05-21 09:09:15,133 [salt.state       :1813][INFO    ][1450] Executing state file.managed for [/etc/salt/grains]
2019-05-21 09:09:15,134 [salt.state       :300 ][INFO    ][1450] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-21 09:09:15,134 [salt.state       :1951][INFO    ][1450] Completed state [/etc/salt/grains] at time 09:09:15.134421 duration_in_ms=1.61
2019-05-21 09:09:15,135 [salt.state       :1780][INFO    ][1450] Running state [/etc/salt/grains.d/placeholder] at time 09:09:15.135178
2019-05-21 09:09:15,135 [salt.state       :1813][INFO    ][1450] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-21 09:09:15,136 [salt.state       :300 ][INFO    ][1450] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-21 09:09:15,136 [salt.state       :1951][INFO    ][1450] Completed state [/etc/salt/grains.d/placeholder] at time 09:09:15.136770 duration_in_ms=1.593
2019-05-21 09:09:15,137 [salt.state       :1780][INFO    ][1450] Running state [/etc/salt/grains.d/sphinx] at time 09:09:15.137506
2019-05-21 09:09:15,137 [salt.state       :1813][INFO    ][1450] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-21 09:09:15,152 [salt.state       :300 ][INFO    ][1450] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-21 09:09:15,152 [salt.state       :1951][INFO    ][1450] Completed state [/etc/salt/grains.d/sphinx] at time 09:09:15.152307 duration_in_ms=14.801
2019-05-21 09:09:15,155 [salt.state       :1780][INFO    ][1450] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 09:09:15.155769
2019-05-21 09:09:15,156 [salt.state       :1813][INFO    ][1450] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-21 09:09:15,156 [salt.state       :300 ][INFO    ][1450] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-21 09:09:15,157 [salt.state       :1951][INFO    ][1450] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 09:09:15.157096 duration_in_ms=1.327
2019-05-21 09:09:15,157 [salt.state       :1780][INFO    ][1450] Running state [/etc/salt/grains.d/dns_records] at time 09:09:15.157840
2019-05-21 09:09:15,158 [salt.state       :1813][INFO    ][1450] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-21 09:09:15,169 [salt.state       :300 ][INFO    ][1450] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-21 09:09:15,170 [salt.state       :1951][INFO    ][1450] Completed state [/etc/salt/grains.d/dns_records] at time 09:09:15.170045 duration_in_ms=12.205
2019-05-21 09:09:15,171 [salt.state       :1780][INFO    ][1450] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 09:09:15.171423
2019-05-21 09:09:15,171 [salt.state       :1813][INFO    ][1450] 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-21 09:09:15,172 [salt.state       :300 ][INFO    ][1450] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-21 09:09:15,172 [salt.state       :1951][INFO    ][1450] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 09:09:15.172668 duration_in_ms=1.245
2019-05-21 09:09:15,173 [salt.state       :1780][INFO    ][1450] Running state [/etc/salt/grains.d/salt] at time 09:09:15.173353
2019-05-21 09:09:15,173 [salt.state       :1813][INFO    ][1450] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-21 09:09:15,181 [salt.state       :300 ][INFO    ][1450] File /etc/salt/grains.d/salt is in the correct state
2019-05-21 09:09:15,182 [salt.state       :1951][INFO    ][1450] Completed state [/etc/salt/grains.d/salt] at time 09:09:15.182187 duration_in_ms=8.834
2019-05-21 09:09:15,183 [salt.state       :1780][INFO    ][1450] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 09:09:15.183609
2019-05-21 09:09:15,184 [salt.state       :1813][INFO    ][1450] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-21 09:09:15,184 [salt.state       :300 ][INFO    ][1450] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-21 09:09:15,185 [salt.state       :1951][INFO    ][1450] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 09:09:15.184946 duration_in_ms=1.337
2019-05-21 09:09:15,188 [salt.state       :1780][INFO    ][1450] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 09:09:15.188006
2019-05-21 09:09:15,188 [salt.state       :1813][INFO    ][1450] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-21 09:09:15,189 [salt.state       :300 ][INFO    ][1450] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-21 09:09:15,189 [salt.state       :1951][INFO    ][1450] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 09:09:15.189342 duration_in_ms=1.336
2019-05-21 09:09:15,190 [salt.state       :1780][INFO    ][1450] Running state [mine.update] at time 09:09:15.190423
2019-05-21 09:09:15,190 [salt.state       :1813][INFO    ][1450] Executing state module.wait for [mine.update]
2019-05-21 09:09:15,191 [salt.state       :300 ][INFO    ][1450] No changes made for mine.update
2019-05-21 09:09:15,191 [salt.state       :1951][INFO    ][1450] Completed state [mine.update] at time 09:09:15.191673 duration_in_ms=1.25
2019-05-21 09:09:15,192 [salt.state       :1780][INFO    ][1450] Running state [ca-certificates] at time 09:09:15.192067
2019-05-21 09:09:15,192 [salt.state       :1813][INFO    ][1450] Executing state pkg.installed for [ca-certificates]
2019-05-21 09:09:15,203 [salt.state       :300 ][INFO    ][1450] All specified packages are already installed
2019-05-21 09:09:15,203 [salt.state       :1951][INFO    ][1450] Completed state [ca-certificates] at time 09:09:15.203905 duration_in_ms=11.837
2019-05-21 09:09:15,204 [salt.state       :1780][INFO    ][1450] Running state [update-ca-certificates] at time 09:09:15.204902
2019-05-21 09:09:15,205 [salt.state       :1813][INFO    ][1450] Executing state cmd.wait for [update-ca-certificates]
2019-05-21 09:09:15,205 [salt.state       :300 ][INFO    ][1450] No changes made for update-ca-certificates
2019-05-21 09:09:15,206 [salt.state       :1951][INFO    ][1450] Completed state [update-ca-certificates] at time 09:09:15.206050 duration_in_ms=1.148
2019-05-21 09:09:15,206 [salt.state       :1780][INFO    ][1450] Running state [iptables] at time 09:09:15.206386
2019-05-21 09:09:15,206 [salt.state       :1813][INFO    ][1450] Executing state pkg.installed for [iptables]
2019-05-21 09:09:15,216 [salt.state       :300 ][INFO    ][1450] All specified packages are already installed
2019-05-21 09:09:15,216 [salt.state       :1951][INFO    ][1450] Completed state [iptables] at time 09:09:15.216850 duration_in_ms=10.464
2019-05-21 09:09:15,217 [salt.state       :1780][INFO    ][1450] Running state [iptables-persistent] at time 09:09:15.217183
2019-05-21 09:09:15,217 [salt.state       :1813][INFO    ][1450] Executing state pkg.installed for [iptables-persistent]
2019-05-21 09:09:15,226 [salt.state       :300 ][INFO    ][1450] All specified packages are already installed
2019-05-21 09:09:15,227 [salt.state       :1951][INFO    ][1450] Completed state [iptables-persistent] at time 09:09:15.227145 duration_in_ms=9.962
2019-05-21 09:09:15,228 [salt.state       :1780][INFO    ][1450] Running state [iptables_modules_v4_load] at time 09:09:15.228444
2019-05-21 09:09:15,228 [salt.state       :1813][INFO    ][1450] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-21 09:09:15,229 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command 'lsmod' in directory '/root'
2019-05-21 09:09:15,254 [salt.state       :300 ][INFO    ][1450] Kernel modules iptable_filter, ip_tables are already present
2019-05-21 09:09:15,254 [salt.state       :1951][INFO    ][1450] Completed state [iptables_modules_v4_load] at time 09:09:15.254633 duration_in_ms=26.189
2019-05-21 09:09:15,255 [salt.state       :1780][INFO    ][1450] Running state [/etc/iptables/rules.v4] at time 09:09:15.255539
2019-05-21 09:09:15,256 [salt.state       :1813][INFO    ][1450] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-21 09:09:15,361 [salt.state       :300 ][INFO    ][1450] File /etc/iptables/rules.v4 is in the correct state
2019-05-21 09:09:15,361 [salt.state       :1951][INFO    ][1450] Completed state [/etc/iptables/rules.v4] at time 09:09:15.361900 duration_in_ms=106.361
2019-05-21 09:09:15,363 [salt.state       :1780][INFO    ][1450] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 09:09:15.362962
2019-05-21 09:09:15,363 [salt.state       :1813][INFO    ][1450] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-21 09:09:15,363 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-21 09:09:15,383 [salt.state       :300 ][INFO    ][1450] onlyif execution failed
2019-05-21 09:09:15,383 [salt.state       :1951][INFO    ][1450] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 09:09:15.383745 duration_in_ms=20.782
2019-05-21 09:09:15,384 [salt.state       :1780][INFO    ][1450] Running state [netfilter-persistent] at time 09:09:15.384751
2019-05-21 09:09:15,385 [salt.state       :1813][INFO    ][1450] Executing state service.running for [netfilter-persistent]
2019-05-21 09:09:15,385 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-21 09:09:15,405 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-21 09:09:15,423 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-21 09:09:15,442 [salt.state       :300 ][INFO    ][1450] The service netfilter-persistent is already running
2019-05-21 09:09:15,443 [salt.state       :1951][INFO    ][1450] Completed state [netfilter-persistent] at time 09:09:15.443149 duration_in_ms=58.397
2019-05-21 09:09:15,444 [salt.state       :1780][INFO    ][1450] Running state [iptables_extra.remove_stale_tables] at time 09:09:15.444198
2019-05-21 09:09:15,444 [salt.state       :1813][INFO    ][1450] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-21 09:09:15,445 [salt.state       :300 ][INFO    ][1450] No changes made for iptables_extra.remove_stale_tables
2019-05-21 09:09:15,445 [salt.state       :1951][INFO    ][1450] Completed state [iptables_extra.remove_stale_tables] at time 09:09:15.445345 duration_in_ms=1.148
2019-05-21 09:09:15,445 [salt.state       :1780][INFO    ][1450] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 09:09:15.445686
2019-05-21 09:09:15,446 [salt.state       :1813][INFO    ][1450] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-21 09:09:15,446 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1450] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-21 09:09:15,461 [salt.state       :300 ][INFO    ][1450] onlyif execution failed
2019-05-21 09:09:15,462 [salt.state       :1951][INFO    ][1450] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 09:09:15.462092 duration_in_ms=16.406
2019-05-21 09:09:15,463 [salt.state       :1780][INFO    ][1450] Running state [/etc/iptables/rules.v6] at time 09:09:15.463347
2019-05-21 09:09:15,463 [salt.state       :1813][INFO    ][1450] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-21 09:09:15,464 [salt.state       :300 ][INFO    ][1450] File /etc/iptables/rules.v6 is not present
2019-05-21 09:09:15,464 [salt.state       :1951][INFO    ][1450] Completed state [/etc/iptables/rules.v6] at time 09:09:15.464711 duration_in_ms=1.364
2019-05-21 09:09:15,465 [salt.state       :1780][INFO    ][1450] Running state [iptables_extra.flush_all] at time 09:09:15.465615
2019-05-21 09:09:15,466 [salt.state       :1813][INFO    ][1450] Executing state module.wait for [iptables_extra.flush_all]
2019-05-21 09:09:15,466 [salt.state       :300 ][INFO    ][1450] No changes made for iptables_extra.flush_all
2019-05-21 09:09:15,466 [salt.state       :1951][INFO    ][1450] Completed state [iptables_extra.flush_all] at time 09:09:15.466673 duration_in_ms=1.057
2019-05-21 09:09:15,470 [salt.minion      :1711][INFO    ][1450] Returning information for job: 20190521090907604530
2019-05-21 09:09:16,106 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521090916093522
2019-05-21 09:09:16,128 [salt.minion      :1432][INFO    ][1527] Starting a new job with PID 1527
2019-05-21 09:09:16,827 [salt.state       :915 ][INFO    ][1527] Loading fresh modules for state activity
2019-05-21 09:09:17,439 [salt.state       :1780][INFO    ][1527] Running state [maas-rack-controller] at time 09:09:17.439200
2019-05-21 09:09:17,439 [salt.state       :1813][INFO    ][1527] Executing state pkg.installed for [maas-rack-controller]
2019-05-21 09:09:17,440 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1527] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-21 09:09:17,515 [salt.state       :300 ][INFO    ][1527] All specified packages are already installed
2019-05-21 09:09:17,516 [salt.state       :1951][INFO    ][1527] Completed state [maas-rack-controller] at time 09:09:17.516102 duration_in_ms=76.902
2019-05-21 09:09:17,516 [salt.state       :1780][INFO    ][1527] Running state [ipmitool] at time 09:09:17.516340
2019-05-21 09:09:17,516 [salt.state       :1813][INFO    ][1527] Executing state pkg.installed for [ipmitool]
2019-05-21 09:09:17,521 [salt.state       :300 ][INFO    ][1527] All specified packages are already installed
2019-05-21 09:09:17,521 [salt.state       :1951][INFO    ][1527] Completed state [ipmitool] at time 09:09:17.521182 duration_in_ms=4.842
2019-05-21 09:09:17,523 [salt.state       :1780][INFO    ][1527] Running state [/etc/maas/rackd.conf] at time 09:09:17.523439
2019-05-21 09:09:17,523 [salt.state       :1813][INFO    ][1527] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-21 09:09:17,524 [salt.state       :300 ][INFO    ][1527] No changes needed to be made
2019-05-21 09:09:17,524 [salt.state       :1951][INFO    ][1527] Completed state [/etc/maas/rackd.conf] at time 09:09:17.524581 duration_in_ms=1.142
2019-05-21 09:09:17,524 [salt.state       :1780][INFO    ][1527] Running state [/etc/maas/rackd.conf] at time 09:09:17.524745
2019-05-21 09:09:17,524 [salt.state       :1813][INFO    ][1527] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-21 09:09:17,525 [salt.loaded.int.states.file:2298][WARNING ][1527] 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-21 09:09:17,525 [salt.state       :300 ][INFO    ][1527] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-21 09:09:17,525 [salt.state       :1951][INFO    ][1527] Completed state [/etc/maas/rackd.conf] at time 09:09:17.525639 duration_in_ms=0.893
2019-05-21 09:09:17,526 [salt.state       :1780][INFO    ][1527] Running state [maas-rackd] at time 09:09:17.526327
2019-05-21 09:09:17,526 [salt.state       :1813][INFO    ][1527] Executing state service.running for [maas-rackd]
2019-05-21 09:09:17,526 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1527] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-21 09:09:17,560 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1527] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-21 09:09:17,575 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1527] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-21 09:09:17,590 [salt.state       :300 ][INFO    ][1527] The service maas-rackd is already running
2019-05-21 09:09:17,590 [salt.state       :1951][INFO    ][1527] Completed state [maas-rackd] at time 09:09:17.590822 duration_in_ms=64.494
2019-05-21 09:09:17,591 [salt.minion      :1711][INFO    ][1527] Returning information for job: 20190521090916093522
2019-05-21 09:09:18,134 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521090918121964
2019-05-21 09:09:18,155 [salt.minion      :1432][INFO    ][1550] Starting a new job with PID 1550
2019-05-21 09:09:18,891 [salt.state       :915 ][INFO    ][1550] Loading fresh modules for state activity
2019-05-21 09:09:19,665 [salt.state       :1780][INFO    ][1550] Running state [maas-region-controller] at time 09:09:19.665619
2019-05-21 09:09:19,665 [salt.state       :1813][INFO    ][1550] Executing state pkg.installed for [maas-region-controller]
2019-05-21 09:09:19,666 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-21 09:09:19,771 [salt.state       :300 ][INFO    ][1550] All specified packages are already installed
2019-05-21 09:09:19,771 [salt.state       :1951][INFO    ][1550] Completed state [maas-region-controller] at time 09:09:19.771533 duration_in_ms=105.912
2019-05-21 09:09:19,772 [salt.state       :1780][INFO    ][1550] Running state [python-oauth] at time 09:09:19.771998
2019-05-21 09:09:19,772 [salt.state       :1813][INFO    ][1550] Executing state pkg.installed for [python-oauth]
2019-05-21 09:09:19,780 [salt.state       :300 ][INFO    ][1550] All specified packages are already installed
2019-05-21 09:09:19,781 [salt.state       :1951][INFO    ][1550] Completed state [python-oauth] at time 09:09:19.781065 duration_in_ms=9.068
2019-05-21 09:09:19,784 [salt.state       :1780][INFO    ][1550] Running state [/etc/maas/regiond.conf] at time 09:09:19.784927
2019-05-21 09:09:19,785 [salt.state       :1813][INFO    ][1550] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-21 09:09:19,823 [salt.state       :300 ][INFO    ][1550] No changes needed to be made
2019-05-21 09:09:19,824 [salt.state       :1951][INFO    ][1550] Completed state [/etc/maas/regiond.conf] at time 09:09:19.824137 duration_in_ms=39.21
2019-05-21 09:09:19,827 [salt.state       :1780][INFO    ][1550] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:09:19.826837
2019-05-21 09:09:19,828 [salt.state       :1813][INFO    ][1550] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-21 09:09:19,912 [salt.state       :300 ][INFO    ][1550] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-21 09:09:19,913 [salt.state       :1951][INFO    ][1550] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 09:09:19.913100 duration_in_ms=86.267
2019-05-21 09:09:19,913 [salt.state       :1780][INFO    ][1550] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:09:19.913814
2019-05-21 09:09:19,914 [salt.state       :1813][INFO    ][1550] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-21 09:09:19,926 [salt.state       :300 ][INFO    ][1550] No changes needed to be made
2019-05-21 09:09:19,926 [salt.state       :1951][INFO    ][1550] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:09:19.926784 duration_in_ms=12.97
2019-05-21 09:09:19,927 [salt.state       :1780][INFO    ][1550] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:09:19.927389
2019-05-21 09:09:19,927 [salt.state       :1813][INFO    ][1550] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-21 09:09:19,950 [salt.state       :300 ][INFO    ][1550] No changes needed to be made
2019-05-21 09:09:19,950 [salt.state       :1951][INFO    ][1550] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 09:09:19.950441 duration_in_ms=23.052
2019-05-21 09:09:19,951 [salt.state       :1780][INFO    ][1550] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:09:19.951061
2019-05-21 09:09:19,951 [salt.state       :1813][INFO    ][1550] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-21 09:09:19,977 [salt.state       :300 ][INFO    ][1550] No changes needed to be made
2019-05-21 09:09:19,978 [salt.state       :1951][INFO    ][1550] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 09:09:19.978126 duration_in_ms=27.064
2019-05-21 09:09:19,978 [salt.state       :1780][INFO    ][1550] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:09:19.978684
2019-05-21 09:09:19,979 [salt.state       :1813][INFO    ][1550] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-21 09:09:19,990 [salt.state       :300 ][INFO    ][1550] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-21 09:09:19,991 [salt.state       :1951][INFO    ][1550] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 09:09:19.991118 duration_in_ms=12.434
2019-05-21 09:09:19,992 [salt.state       :1780][INFO    ][1550] Running state [a2enmod headers] at time 09:09:19.992830
2019-05-21 09:09:19,993 [salt.state       :1813][INFO    ][1550] Executing state cmd.run for [a2enmod headers]
2019-05-21 09:09:19,993 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command 'a2enmod headers' in directory '/root'
2019-05-21 09:09:20,058 [salt.state       :300 ][INFO    ][1550] {'pid': 1569, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-21 09:09:20,059 [salt.state       :1951][INFO    ][1550] Completed state [a2enmod headers] at time 09:09:20.059107 duration_in_ms=66.275
2019-05-21 09:09:20,059 [salt.state       :1780][INFO    ][1550] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:09:20.059758
2019-05-21 09:09:20,060 [salt.state       :1813][INFO    ][1550] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-21 09:09:20,079 [salt.state       :300 ][INFO    ][1550] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-21 09:09:20,079 [salt.state       :1951][INFO    ][1550] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 09:09:20.079547 duration_in_ms=19.787
2019-05-21 09:09:20,080 [salt.state       :1780][INFO    ][1550] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:09:20.080438
2019-05-21 09:09:20,080 [salt.state       :1813][INFO    ][1550] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-21 09:09:20,160 [salt.state       :300 ][INFO    ][1550] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-21 09:09:20,160 [salt.state       :1951][INFO    ][1550] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 09:09:20.160340 duration_in_ms=79.901
2019-05-21 09:09:20,161 [salt.state       :1780][INFO    ][1550] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:09:20.161143
2019-05-21 09:09:20,161 [salt.state       :1813][INFO    ][1550] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-21 09:09:20,225 [salt.state       :300 ][INFO    ][1550] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-21 09:09:20,226 [salt.state       :1951][INFO    ][1550] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 09:09:20.226120 duration_in_ms=64.977
2019-05-21 09:09:20,226 [salt.state       :1780][INFO    ][1550] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:09:20.226786
2019-05-21 09:09:20,227 [salt.state       :1813][INFO    ][1550] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-21 09:09:20,291 [salt.state       :300 ][INFO    ][1550] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-21 09:09:20,291 [salt.state       :1951][INFO    ][1550] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 09:09:20.291777 duration_in_ms=64.991
2019-05-21 09:09:20,292 [salt.state       :1780][INFO    ][1550] Running state [/root/.pgpass] at time 09:09:20.292105
2019-05-21 09:09:20,292 [salt.state       :1813][INFO    ][1550] Executing state file.managed for [/root/.pgpass]
2019-05-21 09:09:20,339 [salt.state       :300 ][INFO    ][1550] File /root/.pgpass is in the correct state
2019-05-21 09:09:20,339 [salt.state       :1951][INFO    ][1550] Completed state [/root/.pgpass] at time 09:09:20.339780 duration_in_ms=47.675
2019-05-21 09:09:20,345 [salt.state       :1780][INFO    ][1550] Running state [maas-region syncdb --noinput] at time 09:09:20.344991
2019-05-21 09:09:20,345 [salt.state       :1813][INFO    ][1550] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-21 09:09:20,346 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-21 09:09:22,319 [salt.state       :300 ][INFO    ][1550] {'pid': 1582, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: piston3, contenttypes, auth, metadataserver, maasserver, sessions, sites\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-21 09:09:22,319 [salt.state       :1951][INFO    ][1550] Completed state [maas-region syncdb --noinput] at time 09:09:22.319659 duration_in_ms=1974.667
2019-05-21 09:09:22,320 [salt.state       :2022][WARNING ][1550] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-21 09:09:22,322 [salt.state       :1780][INFO    ][1550] Running state [maas-regiond] at time 09:09:22.322636
2019-05-21 09:09:22,323 [salt.state       :1813][INFO    ][1550] Executing state service.running for [maas-regiond]
2019-05-21 09:09:22,324 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-21 09:09:22,360 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-21 09:09:22,376 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-21 09:09:22,391 [salt.state       :300 ][INFO    ][1550] The service maas-regiond is already running
2019-05-21 09:09:22,392 [salt.state       :1951][INFO    ][1550] Completed state [maas-regiond] at time 09:09:22.392275 duration_in_ms=69.639
2019-05-21 09:09:22,393 [salt.state       :1780][INFO    ][1550] Running state [bind9] at time 09:09:22.393901
2019-05-21 09:09:22,394 [salt.state       :1813][INFO    ][1550] Executing state service.running for [bind9]
2019-05-21 09:09:22,394 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-21 09:09:22,412 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-21 09:09:22,427 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-21 09:09:22,443 [salt.state       :300 ][INFO    ][1550] The service bind9 is already running
2019-05-21 09:09:22,443 [salt.state       :1951][INFO    ][1550] Completed state [bind9] at time 09:09:22.443781 duration_in_ms=49.879
2019-05-21 09:09:22,445 [salt.state       :1780][INFO    ][1550] Running state [apache2] at time 09:09:22.445424
2019-05-21 09:09:22,445 [salt.state       :1813][INFO    ][1550] Executing state service.running for [apache2]
2019-05-21 09:09:22,446 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-21 09:09:22,463 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-21 09:09:22,478 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-21 09:09:22,498 [salt.state       :300 ][INFO    ][1550] The service apache2 is already running
2019-05-21 09:09:22,499 [salt.state       :1951][INFO    ][1550] Completed state [apache2] at time 09:09:22.499218 duration_in_ms=53.795
2019-05-21 09:09:22,500 [salt.state       :1780][INFO    ][1550] Running state [maasng.wait_for_http_code] at time 09:09:22.500846
2019-05-21 09:09:22,501 [salt.state       :1813][INFO    ][1550] Executing state module.run for [maasng.wait_for_http_code]
2019-05-21 09:09:22,501 [salt.utils.decorators:613 ][WARNING ][1550] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 09:09:22,602 [salt.state       :300 ][INFO    ][1550] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-21 09:09:22,603 [salt.state       :1951][INFO    ][1550] Completed state [maasng.wait_for_http_code] at time 09:09:22.603196 duration_in_ms=102.349
2019-05-21 09:09:22,604 [salt.state       :1780][INFO    ][1550] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:09:22.604627
2019-05-21 09:09:22,605 [salt.state       :1813][INFO    ][1550] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-21 09:09:22,605 [salt.state       :300 ][INFO    ][1550] /var/lib/maas/.setup_admin exists
2019-05-21 09:09:22,606 [salt.state       :1951][INFO    ][1550] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 09:09:22.606262 duration_in_ms=1.635
2019-05-21 09:09:22,607 [salt.state       :1780][INFO    ][1550] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:22.607431
2019-05-21 09:09:22,607 [salt.state       :1813][INFO    ][1550] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 09:09:22,608 [salt.loaded.int.module.cmdmod:395 ][INFO    ][1550] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 09:09:24,039 [salt.state       :300 ][INFO    ][1550] {'pid': 1603, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 09:09:24,039 [salt.state       :1951][INFO    ][1550] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:24.039897 duration_in_ms=1432.467
2019-05-21 09:09:24,048 [salt.state       :1780][INFO    ][1550] Running state [maas_region_boot_source_resources_mirror] at time 09:09:24.048136
2019-05-21 09:09:24,048 [salt.state       :1813][INFO    ][1550] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-21 09:09:24,152 [salt.state       :300 ][INFO    ][1550] {'changes': {}}
2019-05-21 09:09:24,152 [salt.state       :1951][INFO    ][1550] Completed state [maas_region_boot_source_resources_mirror] at time 09:09:24.152576 duration_in_ms=104.441
2019-05-21 09:09:24,153 [salt.state       :1780][INFO    ][1550] Running state [maasng.boot_resources_import] at time 09:09:24.153721
2019-05-21 09:09:24,154 [salt.state       :1813][INFO    ][1550] Executing state module.run for [maasng.boot_resources_import]
2019-05-21 09:09:24,154 [salt.utils.decorators:613 ][WARNING ][1550] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 09:09:24,290 [salt.loaded.ext.module.maasng:1600][INFO    ][1550] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-21 09:09:29,336 [salt.loaded.ext.module.maasng:1600][INFO    ][1550] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-21 09:09:33,163 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521090933151607
2019-05-21 09:09:33,187 [salt.minion      :1432][INFO    ][1672] Starting a new job with PID 1672
2019-05-21 09:09:33,210 [salt.minion      :1711][INFO    ][1672] Returning information for job: 20190521090933151607
2019-05-21 09:09:34,397 [salt.loaded.ext.module.maasng:1600][INFO    ][1550] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-21 09:09:39,510 [salt.state       :300 ][INFO    ][1550] {'ret': True}
2019-05-21 09:09:39,511 [salt.state       :1951][INFO    ][1550] Completed state [maasng.boot_resources_import] at time 09:09:39.511310 duration_in_ms=15357.589
2019-05-21 09:09:39,512 [salt.state       :1780][INFO    ][1550] Running state [maas_region_boot_sources_selection_xenial] at time 09:09:39.512579
2019-05-21 09:09:39,513 [salt.state       :1813][INFO    ][1550] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-21 09:09:39,720 [salt.state       :300 ][INFO    ][1550] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-21 09:09:39,720 [salt.state       :1951][INFO    ][1550] Completed state [maas_region_boot_sources_selection_xenial] at time 09:09:39.720460 duration_in_ms=207.88
2019-05-21 09:09:39,721 [salt.state       :1780][INFO    ][1550] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 09:09:39.721818
2019-05-21 09:09:39,722 [salt.state       :1813][INFO    ][1550] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-21 09:09:39,722 [salt.utils.decorators:613 ][WARNING ][1550] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 09:09:39,723 [salt.loaded.ext.module.maasng:1771][INFO    ][1550] boot-sources sync initiated for ALL Rack's
2019-05-21 09:09:40,750 [salt.state       :300 ][INFO    ][1550] {'ret': True}
2019-05-21 09:09:40,750 [salt.state       :1951][INFO    ][1550] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 09:09:40.750653 duration_in_ms=1028.833
2019-05-21 09:09:40,753 [salt.state       :1780][INFO    ][1550] Running state [maas.process_maas_config] at time 09:09:40.753561
2019-05-21 09:09:40,754 [salt.state       :1813][INFO    ][1550] Executing state module.run for [maas.process_maas_config]
2019-05-21 09:09:40,754 [salt.utils.decorators:613 ][WARNING ][1550] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 09:09:40,755 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=enable_http_proxy value=True
2019-05-21 09:09:40,817 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=upstream_dns value=8.8.8.8
2019-05-21 09:09:40,893 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=commissioning_distro_series value=xenial
2019-05-21 09:09:40,959 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=default_osystem value=ubuntu
2019-05-21 09:09:43,941 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=active_discovery_interval value=600
2019-05-21 09:09:43,999 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=dnssec_validation value=no
2019-05-21 09:09:44,059 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=maas_name value=mas01
2019-05-21 09:09:44,113 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=network_discovery value=enabled
2019-05-21 09:09:44,227 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=enable_third_party_drivers value=True
2019-05-21 09:09:44,281 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=default_storage_layout value=lvm
2019-05-21 09:09:44,347 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=ntp_external_only value=True
2019-05-21 09:09:44,397 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-21 09:09:44,451 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=default_distro_series value=xenial
2019-05-21 09:09:44,505 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-21 09:09:44,642 [salt.state       :300 ][INFO    ][1550] {'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-21 09:09:44,643 [salt.state       :1951][INFO    ][1550] Completed state [maas.process_maas_config] at time 09:09:44.643303 duration_in_ms=3889.741
2019-05-21 09:09:44,644 [salt.state       :1780][INFO    ][1550] Running state [pxe_admin] at time 09:09:44.644264
2019-05-21 09:09:44,644 [salt.state       :1813][INFO    ][1550] Executing state maasng.fabric_present for [pxe_admin]
2019-05-21 09:09:44,733 [salt.loaded.ext.module.maasng:945 ][INFO    ][1550] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-21 09:09:44,809 [salt.loaded.ext.module.maasng:1008][WARNING ][1550] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-21 09:09:44,810 [salt.loaded.ext.module.maasng:1011][WARNING ][1550] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-21 09:09:44,882 [salt.state       :300 ][INFO    ][1550] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-21 09:09:44,882 [salt.state       :1951][INFO    ][1550] Completed state [pxe_admin] at time 09:09:44.882888 duration_in_ms=238.624
2019-05-21 09:09:44,883 [salt.state       :1780][INFO    ][1550] Running state [vlan 0] at time 09:09:44.883360
2019-05-21 09:09:44,883 [salt.state       :1813][INFO    ][1550] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-21 09:09:44,953 [salt.loaded.ext.module.maasng:945 ][INFO    ][1550] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-21 09:09:45,090 [salt.loaded.ext.module.maasng:945 ][INFO    ][1550] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'name': u'untagged', u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-21 09:09:45,377 [salt.loaded.ext.module.maasng:945 ][INFO    ][1550] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-21 09:09:45,479 [salt.state       :300 ][INFO    ][1550] {'new': 'Vlan untagged was updated'}
2019-05-21 09:09:45,479 [salt.state       :1951][INFO    ][1550] Completed state [vlan 0] at time 09:09:45.479733 duration_in_ms=596.372
2019-05-21 09:09:45,481 [salt.state       :1780][INFO    ][1550] Running state [192.168.11.0/24] at time 09:09:45.481206
2019-05-21 09:09:45,481 [salt.state       :1813][INFO    ][1550] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-21 09:09:45,672 [salt.loaded.ext.module.maasng:945 ][INFO    ][1550] [{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'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-21 09:09:45,673 [salt.loaded.ext.module.maasng:1235][WARNING ][1550] Ignoring parameter vlan:0
2019-05-21 09:09:45,750 [salt.state       :300 ][INFO    ][1550] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-21 09:09:45,751 [salt.state       :1951][INFO    ][1550] Completed state [192.168.11.0/24] at time 09:09:45.751051 duration_in_ms=269.845
2019-05-21 09:09:45,752 [salt.state       :1780][INFO    ][1550] Running state [maas_create_iprange_1] at time 09:09:45.752304
2019-05-21 09:09:45,752 [salt.state       :1813][INFO    ][1550] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-21 09:09:45,798 [salt.state       :300 ][INFO    ][1550] Iprange maas_create_iprange_1 already exist.
2019-05-21 09:09:45,798 [salt.state       :1951][INFO    ][1550] Completed state [maas_create_iprange_1] at time 09:09:45.798550 duration_in_ms=46.245
2019-05-21 09:09:45,799 [salt.state       :1780][INFO    ][1550] Running state [vlan 0] at time 09:09:45.799068
2019-05-21 09:09:45,799 [salt.state       :1813][INFO    ][1550] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-21 09:09:45,864 [salt.loaded.ext.module.maasng:945 ][INFO    ][1550] [{u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'class_type': None, u'name': u'fabric-0', u'id': 0}, {u'vlans': [{u'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'class_type': None, u'name': u'fabric-1', u'id': 1}, {u'vlans': [{u'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'class_type': u'', u'name': u'pxe_admin', u'id': 2}]
2019-05-21 09:09:45,977 [salt.loaded.ext.module.maasng:945 ][INFO    ][1550] [{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'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-21 09:09:46,215 [salt.loaded.ext.module.maasng:945 ][INFO    ][1550] [{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'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0'}, {u'id': 1, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1'}, {u'id': 2, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'mrpbgk', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin'}]
2019-05-21 09:09:46,318 [salt.state       :300 ][INFO    ][1550] {'new': 'Vlan untagged was updated'}
2019-05-21 09:09:46,318 [salt.state       :1951][INFO    ][1550] Completed state [vlan 0] at time 09:09:46.318766 duration_in_ms=519.697
2019-05-21 09:09:46,319 [salt.state       :1780][INFO    ][1550] Running state [opnfv] at time 09:09:46.319794
2019-05-21 09:09:46,320 [salt.state       :1813][INFO    ][1550] Executing state maasng.sshkey_present for [opnfv]
2019-05-21 09:09:46,370 [salt.loaded.ext.module.maasng:1903][INFO    ][1550] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-05-21 09:09:46,371 [salt.state       :300 ][INFO    ][1550] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-21 09:09:46,371 [salt.state       :1951][INFO    ][1550] Completed state [opnfv] at time 09:09:46.371842 duration_in_ms=52.048
2019-05-21 09:09:46,372 [salt.state       :1780][INFO    ][1550] Running state [maas.process_tags] at time 09:09:46.372751
2019-05-21 09:09:46,373 [salt.state       :1813][INFO    ][1550] Executing state module.run for [maas.process_tags]
2019-05-21 09:09:46,374 [salt.utils.decorators:613 ][WARNING ][1550] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 09:09:46,425 [salt.loaded.ext.module.maas:92  ][INFO    ][1550] tags comment=Enable 1G pagesizes on aarch64 definition=//capability[@id="asimd"] name=aarch64_hugepages_1g kernel_opts=default_hugepagesz=1G hugepagesz=1G
2019-05-21 09:09:46,478 [salt.state       :300 ][INFO    ][1550] {'ret': {'updated': ['aarch64_hugepages_1g'], 'errors': {}, 'success': []}}
2019-05-21 09:09:46,479 [salt.state       :1951][INFO    ][1550] Completed state [maas.process_tags] at time 09:09:46.479250 duration_in_ms=106.499
2019-05-21 09:09:46,483 [salt.minion      :1711][INFO    ][1550] Returning information for job: 20190521090918121964
2019-05-21 09:09:47,016 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521090947004087
2019-05-21 09:09:47,036 [salt.minion      :1432][INFO    ][2031] Starting a new job with PID 2031
2019-05-21 09:09:50,756 [salt.state       :915 ][INFO    ][2031] Loading fresh modules for state activity
2019-05-21 09:09:50,850 [salt.state       :1780][INFO    ][2031] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:50.850896
2019-05-21 09:09:50,851 [salt.state       :1813][INFO    ][2031] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 09:09:50,853 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2031] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 09:09:52,246 [salt.state       :300 ][INFO    ][2031] {'pid': 2054, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 09:09:52,246 [salt.state       :1951][INFO    ][2031] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:09:52.246811 duration_in_ms=1395.915
2019-05-21 09:09:52,248 [salt.state       :1780][INFO    ][2031] Running state [maas.process_machines] at time 09:09:52.248008
2019-05-21 09:09:52,248 [salt.state       :1813][INFO    ][2031] Executing state module.run for [maas.process_machines]
2019-05-21 09:09:52,248 [salt.utils.decorators:613 ][WARNING ][2031] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 09:09:52,978 [salt.loaded.ext.module.maas:412 ][WARNING ][2031] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 09:09:52,979 [salt.loaded.ext.module.maas:92  ][INFO    ][2031] machine hostname=cmp002 power_type=ipmi mac_addresses=['00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=dpaq7b architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 09:09:54,320 [salt.loaded.ext.module.maas:412 ][WARNING ][2031] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 09:09:54,320 [salt.loaded.ext.module.maas:92  ][INFO    ][2031] machine hostname=cmp001 power_type=ipmi mac_addresses=['00:25:b5:a0:00:5a'] power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus system_id=cf8sgr architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 09:09:55,631 [salt.loaded.ext.module.maas:412 ][WARNING ][2031] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 09:09:55,632 [salt.loaded.ext.module.maas:92  ][INFO    ][2031] machine hostname=kvm01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=mfydxg architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 09:09:56,932 [salt.loaded.ext.module.maas:412 ][WARNING ][2031] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 09:09:56,933 [salt.loaded.ext.module.maas:92  ][INFO    ][2031] machine hostname=kvm03 power_type=ipmi mac_addresses=['00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=6hkq78 architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 09:09:58,224 [salt.loaded.ext.module.maas:412 ][WARNING ][2031] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-21 09:09:58,225 [salt.loaded.ext.module.maas:92  ][INFO    ][2031] machine hostname=kvm02 power_type=ipmi mac_addresses=['00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=dwe637 architecture=amd64/generic power_parameters_power_user=admin
2019-05-21 09:09:59,512 [salt.state       :300 ][INFO    ][2031] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-21 09:09:59,513 [salt.state       :1951][INFO    ][2031] Completed state [maas.process_machines] at time 09:09:59.513019 duration_in_ms=7265.008
2019-05-21 09:09:59,516 [salt.minion      :1711][INFO    ][2031] Returning information for job: 20190521090947004087
2019-05-21 09:10:32,467 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521091032453723
2019-05-21 09:10:32,490 [salt.minion      :1432][INFO    ][2329] Starting a new job with PID 2329
2019-05-21 09:10:36,082 [salt.state       :915 ][INFO    ][2329] Loading fresh modules for state activity
2019-05-21 09:10:36,132 [salt.state       :1780][INFO    ][2329] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:10:36.132791
2019-05-21 09:10:36,133 [salt.state       :1813][INFO    ][2329] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 09:10:36,134 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2329] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 09:10:37,612 [salt.state       :300 ][INFO    ][2329] {'pid': 2337, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 09:10:37,612 [salt.state       :1951][INFO    ][2329] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:10:37.612453 duration_in_ms=1479.662
2019-05-21 09:10:37,613 [salt.state       :1780][INFO    ][2329] Running state [maas.wait_for_machine_status] at time 09:10:37.613938
2019-05-21 09:10:37,614 [salt.state       :1813][INFO    ][2329] Executing state module.run for [maas.wait_for_machine_status]
2019-05-21 09:10:37,614 [salt.utils.decorators:613 ][WARNING ][2329] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 09:10:39,641 [salt.loaded.ext.module.maas:993 ][INFO    ][2329] Machine mfydxg mark broken
2019-05-21 09:10:40,297 [salt.loaded.ext.module.maas:996 ][INFO    ][2329] Machine mfydxg mark fixed
2019-05-21 09:10:41,532 [salt.loaded.ext.module.maas:684 ][INFO    ][2329] deploymachines hwe_kernel=hwe-16.04 system_id=mfydxg distro_series=xenial
2019-05-21 09:10:45,636 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1491.98289299s left)
2019-05-21 09:10:47,486 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091047473863
2019-05-21 09:10:47,510 [salt.minion      :1432][INFO    ][2402] Starting a new job with PID 2402
2019-05-21 09:10:47,534 [salt.minion      :1711][INFO    ][2402] Returning information for job: 20190521091047473863
2019-05-21 09:11:17,725 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091117679248
2019-05-21 09:11:17,744 [salt.minion      :1432][INFO    ][2431] Starting a new job with PID 2431
2019-05-21 09:11:17,768 [salt.minion      :1711][INFO    ][2431] Returning information for job: 20190521091117679248
2019-05-21 09:11:18,860 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1458.75878s left)
2019-05-21 09:11:47,817 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091147804550
2019-05-21 09:11:47,840 [salt.minion      :1432][INFO    ][2501] Starting a new job with PID 2501
2019-05-21 09:11:47,867 [salt.minion      :1711][INFO    ][2501] Returning information for job: 20190521091147804550
2019-05-21 09:11:52,361 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.25757408s left)
2019-05-21 09:12:17,868 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091217855705
2019-05-21 09:12:17,891 [salt.minion      :1432][INFO    ][2523] Starting a new job with PID 2523
2019-05-21 09:12:17,916 [salt.minion      :1711][INFO    ][2523] Returning information for job: 20190521091217855705
2019-05-21 09:12:24,966 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.65222192s left)
2019-05-21 09:12:47,922 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091247909599
2019-05-21 09:12:47,945 [salt.minion      :1432][INFO    ][2622] Starting a new job with PID 2622
2019-05-21 09:12:47,973 [salt.minion      :1711][INFO    ][2622] Returning information for job: 20190521091247909599
2019-05-21 09:12:58,610 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1359.00876307s left)
2019-05-21 09:13:17,977 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091317965137
2019-05-21 09:13:18,000 [salt.minion      :1432][INFO    ][2648] Starting a new job with PID 2648
2019-05-21 09:13:18,026 [salt.minion      :1711][INFO    ][2648] Returning information for job: 20190521091317965137
2019-05-21 09:13:31,730 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1325.88822103s left)
2019-05-21 09:13:48,035 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091348021987
2019-05-21 09:13:48,057 [salt.minion      :1432][INFO    ][2847] Starting a new job with PID 2847
2019-05-21 09:13:48,083 [salt.minion      :1711][INFO    ][2847] Returning information for job: 20190521091348021987
2019-05-21 09:14:05,327 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1292.29115605s left)
2019-05-21 09:14:18,095 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091418083327
2019-05-21 09:14:18,118 [salt.minion      :1432][INFO    ][2872] Starting a new job with PID 2872
2019-05-21 09:14:18,142 [salt.minion      :1711][INFO    ][2872] Returning information for job: 20190521091418083327
2019-05-21 09:14:38,953 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.6657629s left)
2019-05-21 09:14:48,159 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091448147308
2019-05-21 09:14:48,182 [salt.minion      :1432][INFO    ][2953] Starting a new job with PID 2953
2019-05-21 09:14:48,209 [salt.minion      :1711][INFO    ][2953] Returning information for job: 20190521091448147308
2019-05-21 09:15:12,566 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1225.05261397s left)
2019-05-21 09:15:18,232 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091518220246
2019-05-21 09:15:18,248 [salt.minion      :1432][INFO    ][2977] Starting a new job with PID 2977
2019-05-21 09:15:18,274 [salt.minion      :1711][INFO    ][2977] Returning information for job: 20190521091518220246
2019-05-21 09:15:46,177 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1191.44194698s left)
2019-05-21 09:15:48,299 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091548286085
2019-05-21 09:15:48,321 [salt.minion      :1432][INFO    ][3158] Starting a new job with PID 3158
2019-05-21 09:15:48,347 [salt.minion      :1711][INFO    ][3158] Returning information for job: 20190521091548286085
2019-05-21 09:16:18,374 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091618362452
2019-05-21 09:16:18,399 [salt.minion      :1432][INFO    ][3183] Starting a new job with PID 3183
2019-05-21 09:16:18,425 [salt.minion      :1711][INFO    ][3183] Returning information for job: 20190521091618362452
2019-05-21 09:16:19,854 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1157.764817s left)
2019-05-21 09:16:48,460 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091648447682
2019-05-21 09:16:48,483 [salt.minion      :1432][INFO    ][3335] Starting a new job with PID 3335
2019-05-21 09:16:48,508 [salt.minion      :1711][INFO    ][3335] Returning information for job: 20190521091648447682
2019-05-21 09:16:53,420 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1124.19807887s left)
2019-05-21 09:17:18,549 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091718536689
2019-05-21 09:17:18,571 [salt.minion      :1432][INFO    ][3414] Starting a new job with PID 3414
2019-05-21 09:17:18,597 [salt.minion      :1711][INFO    ][3414] Returning information for job: 20190521091718536689
2019-05-21 09:17:26,315 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1091.30395389s left)
2019-05-21 09:17:48,640 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091748627807
2019-05-21 09:17:48,664 [salt.minion      :1432][INFO    ][3499] Starting a new job with PID 3499
2019-05-21 09:17:48,691 [salt.minion      :1711][INFO    ][3499] Returning information for job: 20190521091748627807
2019-05-21 09:17:59,619 [salt.loaded.ext.module.maas:1023][INFO    ][2329] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1057.99990892s left)
2019-05-21 09:18:18,745 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command saltutil.find_job with jid 20190521091818732122
2019-05-21 09:18:18,768 [salt.minion      :1432][INFO    ][3560] Starting a new job with PID 3560
2019-05-21 09:18:18,794 [salt.minion      :1711][INFO    ][3560] Returning information for job: 20190521091818732122
2019-05-21 09:18:32,741 [salt.state       :300 ][INFO    ][2329] {'ret': True}
2019-05-21 09:18:32,741 [salt.state       :1951][INFO    ][2329] Completed state [maas.wait_for_machine_status] at time 09:18:32.741443 duration_in_ms=475127.503
2019-05-21 09:18:32,744 [salt.minion      :1711][INFO    ][2329] Returning information for job: 20190521091032453723
2019-05-21 09:18:33,273 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521091833263188
2019-05-21 09:18:33,289 [salt.minion      :1432][INFO    ][3711] Starting a new job with PID 3711
2019-05-21 09:18:36,838 [salt.state       :915 ][INFO    ][3711] Loading fresh modules for state activity
2019-05-21 09:18:36,918 [salt.state       :1780][INFO    ][3711] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:36.918066
2019-05-21 09:18:36,918 [salt.state       :1813][INFO    ][3711] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 09:18:36,919 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3711] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 09:18:38,440 [salt.state       :300 ][INFO    ][3711] {'pid': 3725, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 09:18:38,441 [salt.state       :1951][INFO    ][3711] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:38.441290 duration_in_ms=1523.222
2019-05-21 09:18:38,444 [salt.state       :1780][INFO    ][3711] Running state [maas_machines_storage_cmp002_lvm] at time 09:18:38.444626
2019-05-21 09:18:38,445 [salt.state       :1813][INFO    ][3711] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-21 09:18:39,184 [salt.state       :300 ][INFO    ][3711] Machine cmp002 is not in Ready state.
2019-05-21 09:18:39,184 [salt.state       :1951][INFO    ][3711] Completed state [maas_machines_storage_cmp002_lvm] at time 09:18:39.184685 duration_in_ms=740.058
2019-05-21 09:18:39,185 [salt.state       :1780][INFO    ][3711] Running state [maas_machines_storage_cmp001_lvm] at time 09:18:39.185275
2019-05-21 09:18:39,185 [salt.state       :1813][INFO    ][3711] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-21 09:18:39,997 [salt.state       :300 ][INFO    ][3711] Machine cmp001 is not in Ready state.
2019-05-21 09:18:39,998 [salt.state       :1951][INFO    ][3711] Completed state [maas_machines_storage_cmp001_lvm] at time 09:18:39.998267 duration_in_ms=812.992
2019-05-21 09:18:40,002 [salt.minion      :1711][INFO    ][3711] Returning information for job: 20190521091833263188
2019-05-21 09:18:40,630 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521091840620652
2019-05-21 09:18:40,652 [salt.minion      :1432][INFO    ][3736] Starting a new job with PID 3736
2019-05-21 09:18:41,395 [salt.state       :915 ][INFO    ][3736] Loading fresh modules for state activity
2019-05-21 09:18:41,483 [salt.state       :1780][INFO    ][3736] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:41.483584
2019-05-21 09:18:41,484 [salt.state       :1813][INFO    ][3736] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 09:18:41,486 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3736] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 09:18:42,952 [salt.state       :300 ][INFO    ][3736] {'pid': 3743, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 09:18:42,953 [salt.state       :1951][INFO    ][3736] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:42.953056 duration_in_ms=1469.473
2019-05-21 09:18:42,954 [salt.state       :1780][INFO    ][3736] Running state [maas.deploy_machines] at time 09:18:42.954271
2019-05-21 09:18:42,954 [salt.state       :1813][INFO    ][3736] Executing state module.run for [maas.deploy_machines]
2019-05-21 09:18:42,955 [salt.utils.decorators:613 ][WARNING ][3736] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 09:18:43,693 [salt.state       :300 ][INFO    ][3736] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-21 09:18:43,693 [salt.state       :1951][INFO    ][3736] Completed state [maas.deploy_machines] at time 09:18:43.693893 duration_in_ms=739.62
2019-05-21 09:18:43,697 [salt.minion      :1711][INFO    ][3736] Returning information for job: 20190521091840620652
2019-05-21 09:18:44,338 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command state.apply with jid 20190521091844328768
2019-05-21 09:18:44,359 [salt.minion      :1432][INFO    ][3753] Starting a new job with PID 3753
2019-05-21 09:18:45,106 [salt.state       :915 ][INFO    ][3753] Loading fresh modules for state activity
2019-05-21 09:18:45,197 [salt.state       :1780][INFO    ][3753] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:45.197671
2019-05-21 09:18:45,198 [salt.state       :1813][INFO    ][3753] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-21 09:18:45,200 [salt.loaded.int.module.cmdmod:395 ][INFO    ][3753] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-21 09:18:46,784 [salt.state       :300 ][INFO    ][3753] {'pid': 3760, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-21 09:18:46,785 [salt.state       :1951][INFO    ][3753] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 09:18:46.785124 duration_in_ms=1587.452
2019-05-21 09:18:46,788 [salt.state       :1780][INFO    ][3753] Running state [maas.wait_for_machine_status] at time 09:18:46.788530
2019-05-21 09:18:46,789 [salt.state       :1813][INFO    ][3753] Executing state module.run for [maas.wait_for_machine_status]
2019-05-21 09:18:46,789 [salt.utils.decorators:613 ][WARNING ][3753] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-21 09:18:50,532 [salt.state       :300 ][INFO    ][3753] {'ret': True}
2019-05-21 09:18:50,533 [salt.state       :1951][INFO    ][3753] Completed state [maas.wait_for_machine_status] at time 09:18:50.533397 duration_in_ms=3744.865
2019-05-21 09:18:50,537 [salt.minion      :1711][INFO    ][3753] Returning information for job: 20190521091844328768
2019-05-21 09:48:05,148 [salt.utils.schedule:1377][INFO    ][27296] Running scheduled job: __mine_interval
2019-05-21 10:44:28,968 [salt.minion      :1308][INFO    ][27296] User sudo_ubuntu Executing command cp.push_dir with jid 20190521104428955443
2019-05-21 10:44:28,991 [salt.minion      :1432][INFO    ][10033] Starting a new job with PID 10033
