2019-05-15 02:12:59,033 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-15 02:13:49,084 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-15 02:14:39,128 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-15 02:15:29,166 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-15 02:16:19,215 [salt.minion      :870 ][ERROR   ][360] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-15 02:18:28,259 [salt.utils.decorators:613 ][WARNING ][2736] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 02:18:28,865 [salt.utils.decorators:613 ][WARNING ][2736] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 02:18:31,112 [salt.loaded.int.states.file:2298][WARNING ][2889] 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-15 02:18:36,762 [salt.state       :2022][WARNING ][2985] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-15 02:18:39,296 [salt.utils.decorators:613 ][WARNING ][2985] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 02:33:48,676 [salt.utils.decorators:613 ][WARNING ][2985] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:03:56,661 [salt.utils.decorators:613 ][WARNING ][2985] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:24:54,949 [salt.state       :302 ][ERROR   ][2985] Module function maasng.sync_and_wait_bs_to_all_racks threw an exception. Exception: HTTP Error 401: OK
2019-05-15 03:24:56,315 [salt.loaded.ext.module.maasng:1008][WARNING ][2985] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-15 03:24:56,315 [salt.loaded.ext.module.maasng:1011][WARNING ][2985] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-15 03:24:59,623 [salt.loaded.ext.module.maasng:1235][WARNING ][2985] Ignoring parameter vlan:0
2019-05-15 03:25:05,354 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32340] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-15 03:25:05,385 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32340] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-15 03:25:05,408 [salt.utils.parsers:1051][WARNING ][360] Minion received a SIGTERM. Exiting.
2019-05-15 03:25:06,370 [salt.cli.daemons :293 ][INFO    ][32389] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-05-15 03:25:06,463 [salt.cli.daemons :82  ][INFO    ][32389] Starting up the Salt Minion
2019-05-15 03:25:06,464 [salt.utils.event :1017][INFO    ][32389] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-05-15 03:25:07,323 [salt.minion      :976 ][INFO    ][32389] Creating minion process manager
2019-05-15 03:25:08,797 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][32389] Executing command ['date', '+%z'] in directory '/root'
2019-05-15 03:25:08,817 [salt.utils.schedule:568 ][INFO    ][32389] Updating job settings for scheduled job: __mine_interval
2019-05-15 03:25:08,818 [salt.minion      :1108][INFO    ][32389] Added mine.update to scheduler
2019-05-15 03:25:08,822 [salt.minion      :1975][INFO    ][32389] Minion is starting as user 'root'
2019-05-15 03:25:08,834 [salt.minion      :2336][INFO    ][32389] Minion is ready to receive requests!
2019-05-15 03:25:13,147 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515032513134214
2019-05-15 03:25:13,171 [salt.minion      :1432][INFO    ][32482] Starting a new job with PID 32482
2019-05-15 03:25:16,896 [salt.state       :915 ][INFO    ][32482] Loading fresh modules for state activity
2019-05-15 03:25:17,580 [salt.state       :1780][INFO    ][32482] Running state [maas-region-controller] at time 03:25:17.580395
2019-05-15 03:25:17,580 [salt.state       :1813][INFO    ][32482] Executing state pkg.installed for [maas-region-controller]
2019-05-15 03:25:17,581 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-15 03:25:17,689 [salt.state       :300 ][INFO    ][32482] All specified packages are already installed
2019-05-15 03:25:17,689 [salt.state       :1951][INFO    ][32482] Completed state [maas-region-controller] at time 03:25:17.689794 duration_in_ms=109.399
2019-05-15 03:25:17,690 [salt.state       :1780][INFO    ][32482] Running state [python-oauth] at time 03:25:17.690222
2019-05-15 03:25:17,690 [salt.state       :1813][INFO    ][32482] Executing state pkg.installed for [python-oauth]
2019-05-15 03:25:17,699 [salt.state       :300 ][INFO    ][32482] All specified packages are already installed
2019-05-15 03:25:17,699 [salt.state       :1951][INFO    ][32482] Completed state [python-oauth] at time 03:25:17.699928 duration_in_ms=9.705
2019-05-15 03:25:17,704 [salt.state       :1780][INFO    ][32482] Running state [/etc/maas/regiond.conf] at time 03:25:17.703944
2019-05-15 03:25:17,704 [salt.state       :1813][INFO    ][32482] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-15 03:25:17,774 [salt.state       :300 ][INFO    ][32482] No changes needed to be made
2019-05-15 03:25:17,775 [salt.state       :1951][INFO    ][32482] Completed state [/etc/maas/regiond.conf] at time 03:25:17.774992 duration_in_ms=71.048
2019-05-15 03:25:17,775 [salt.state       :1780][INFO    ][32482] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:25:17.775756
2019-05-15 03:25:17,776 [salt.state       :1813][INFO    ][32482] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-15 03:25:17,851 [salt.state       :300 ][INFO    ][32482] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-15 03:25:17,851 [salt.state       :1951][INFO    ][32482] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:25:17.851744 duration_in_ms=75.988
2019-05-15 03:25:17,852 [salt.state       :1780][INFO    ][32482] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:25:17.852339
2019-05-15 03:25:17,852 [salt.state       :1813][INFO    ][32482] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-15 03:25:17,865 [salt.state       :300 ][INFO    ][32482] No changes needed to be made
2019-05-15 03:25:17,865 [salt.state       :1951][INFO    ][32482] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:25:17.865444 duration_in_ms=13.105
2019-05-15 03:25:17,866 [salt.state       :1780][INFO    ][32482] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:25:17.866052
2019-05-15 03:25:17,866 [salt.state       :1813][INFO    ][32482] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-15 03:25:17,889 [salt.state       :300 ][INFO    ][32482] No changes needed to be made
2019-05-15 03:25:17,889 [salt.state       :1951][INFO    ][32482] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:25:17.889528 duration_in_ms=23.476
2019-05-15 03:25:17,890 [salt.state       :1780][INFO    ][32482] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:25:17.890142
2019-05-15 03:25:17,890 [salt.state       :1813][INFO    ][32482] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-15 03:25:17,924 [salt.state       :300 ][INFO    ][32482] No changes needed to be made
2019-05-15 03:25:17,924 [salt.state       :1951][INFO    ][32482] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:25:17.924835 duration_in_ms=34.692
2019-05-15 03:25:17,925 [salt.state       :1780][INFO    ][32482] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:25:17.925654
2019-05-15 03:25:17,926 [salt.state       :1813][INFO    ][32482] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-15 03:25:17,940 [salt.state       :300 ][INFO    ][32482] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-15 03:25:17,940 [salt.state       :1951][INFO    ][32482] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:25:17.940611 duration_in_ms=14.957
2019-05-15 03:25:17,943 [salt.state       :1780][INFO    ][32482] Running state [a2enmod headers] at time 03:25:17.943265
2019-05-15 03:25:17,943 [salt.state       :1813][INFO    ][32482] Executing state cmd.run for [a2enmod headers]
2019-05-15 03:25:17,944 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command 'a2enmod headers' in directory '/root'
2019-05-15 03:25:18,014 [salt.state       :300 ][INFO    ][32482] {'pid': 32502, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-15 03:25:18,015 [salt.state       :1951][INFO    ][32482] Completed state [a2enmod headers] at time 03:25:18.015018 duration_in_ms=71.751
2019-05-15 03:25:18,015 [salt.state       :1780][INFO    ][32482] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:25:18.015597
2019-05-15 03:25:18,016 [salt.state       :1813][INFO    ][32482] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-15 03:25:18,035 [salt.state       :300 ][INFO    ][32482] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-15 03:25:18,035 [salt.state       :1951][INFO    ][32482] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:25:18.035814 duration_in_ms=20.217
2019-05-15 03:25:18,036 [salt.state       :1780][INFO    ][32482] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:25:18.036684
2019-05-15 03:25:18,037 [salt.state       :1813][INFO    ][32482] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-15 03:25:18,121 [salt.state       :300 ][INFO    ][32482] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-15 03:25:18,121 [salt.state       :1951][INFO    ][32482] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:25:18.121865 duration_in_ms=85.181
2019-05-15 03:25:18,122 [salt.state       :1780][INFO    ][32482] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:25:18.122707
2019-05-15 03:25:18,123 [salt.state       :1813][INFO    ][32482] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-15 03:25:18,200 [salt.state       :300 ][INFO    ][32482] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-15 03:25:18,200 [salt.state       :1951][INFO    ][32482] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:25:18.200524 duration_in_ms=77.817
2019-05-15 03:25:18,201 [salt.state       :1780][INFO    ][32482] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:25:18.201178
2019-05-15 03:25:18,201 [salt.state       :1813][INFO    ][32482] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-15 03:25:18,265 [salt.state       :300 ][INFO    ][32482] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-15 03:25:18,266 [salt.state       :1951][INFO    ][32482] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:25:18.266189 duration_in_ms=65.01
2019-05-15 03:25:18,266 [salt.state       :1780][INFO    ][32482] Running state [/root/.pgpass] at time 03:25:18.266516
2019-05-15 03:25:18,266 [salt.state       :1813][INFO    ][32482] Executing state file.managed for [/root/.pgpass]
2019-05-15 03:25:18,313 [salt.state       :300 ][INFO    ][32482] File /root/.pgpass is in the correct state
2019-05-15 03:25:18,314 [salt.state       :1951][INFO    ][32482] Completed state [/root/.pgpass] at time 03:25:18.314119 duration_in_ms=47.602
2019-05-15 03:25:18,319 [salt.state       :1780][INFO    ][32482] Running state [maas-region syncdb --noinput] at time 03:25:18.319751
2019-05-15 03:25:18,320 [salt.state       :1813][INFO    ][32482] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-15 03:25:18,320 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-15 03:25:20,250 [salt.state       :300 ][INFO    ][32482] {'pid': 32515, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sessions, piston3, maasserver, contenttypes, sites, metadataserver, auth\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-15 03:25:20,251 [salt.state       :1951][INFO    ][32482] Completed state [maas-region syncdb --noinput] at time 03:25:20.251487 duration_in_ms=1931.723
2019-05-15 03:25:20,251 [salt.state       :2022][WARNING ][32482] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-15 03:25:20,254 [salt.state       :1780][INFO    ][32482] Running state [maas-regiond] at time 03:25:20.254657
2019-05-15 03:25:20,255 [salt.state       :1813][INFO    ][32482] Executing state service.running for [maas-regiond]
2019-05-15 03:25:20,256 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-15 03:25:20,294 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-15 03:25:20,312 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-15 03:25:20,329 [salt.state       :300 ][INFO    ][32482] The service maas-regiond is already running
2019-05-15 03:25:20,330 [salt.state       :1951][INFO    ][32482] Completed state [maas-regiond] at time 03:25:20.329982 duration_in_ms=75.325
2019-05-15 03:25:20,332 [salt.state       :1780][INFO    ][32482] Running state [bind9] at time 03:25:20.332396
2019-05-15 03:25:20,332 [salt.state       :1813][INFO    ][32482] Executing state service.running for [bind9]
2019-05-15 03:25:20,333 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-15 03:25:20,352 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-15 03:25:20,370 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-15 03:25:20,387 [salt.state       :300 ][INFO    ][32482] The service bind9 is already running
2019-05-15 03:25:20,388 [salt.state       :1951][INFO    ][32482] Completed state [bind9] at time 03:25:20.387933 duration_in_ms=55.537
2019-05-15 03:25:20,390 [salt.state       :1780][INFO    ][32482] Running state [apache2] at time 03:25:20.390308
2019-05-15 03:25:20,390 [salt.state       :1813][INFO    ][32482] Executing state service.running for [apache2]
2019-05-15 03:25:20,391 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-15 03:25:20,411 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-15 03:25:20,428 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-15 03:25:20,449 [salt.state       :300 ][INFO    ][32482] The service apache2 is already running
2019-05-15 03:25:20,450 [salt.state       :1951][INFO    ][32482] Completed state [apache2] at time 03:25:20.450219 duration_in_ms=59.911
2019-05-15 03:25:20,452 [salt.state       :1780][INFO    ][32482] Running state [maasng.wait_for_http_code] at time 03:25:20.452374
2019-05-15 03:25:20,452 [salt.state       :1813][INFO    ][32482] Executing state module.run for [maasng.wait_for_http_code]
2019-05-15 03:25:20,453 [salt.utils.decorators:613 ][WARNING ][32482] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:25:20,588 [salt.state       :300 ][INFO    ][32482] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-15 03:25:20,588 [salt.state       :1951][INFO    ][32482] Completed state [maasng.wait_for_http_code] at time 03:25:20.588706 duration_in_ms=136.331
2019-05-15 03:25:20,590 [salt.state       :1780][INFO    ][32482] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:25:20.590217
2019-05-15 03:25:20,590 [salt.state       :1813][INFO    ][32482] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-15 03:25:20,591 [salt.state       :300 ][INFO    ][32482] /var/lib/maas/.setup_admin exists
2019-05-15 03:25:20,591 [salt.state       :1951][INFO    ][32482] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:25:20.591857 duration_in_ms=1.64
2019-05-15 03:25:20,593 [salt.state       :1780][INFO    ][32482] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:25:20.593031
2019-05-15 03:25:20,593 [salt.state       :1813][INFO    ][32482] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:25:20,594 [salt.loaded.int.module.cmdmod:395 ][INFO    ][32482] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:25:22,167 [salt.state       :300 ][INFO    ][32482] {'pid': 32536, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:25:22,168 [salt.state       :1951][INFO    ][32482] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:25:22.168144 duration_in_ms=1575.113
2019-05-15 03:25:22,176 [salt.state       :1780][INFO    ][32482] Running state [maas_region_boot_source_resources_mirror] at time 03:25:22.176242
2019-05-15 03:25:22,176 [salt.state       :1813][INFO    ][32482] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-15 03:25:22,282 [salt.state       :300 ][INFO    ][32482] {'changes': {}}
2019-05-15 03:25:22,282 [salt.state       :1951][INFO    ][32482] Completed state [maas_region_boot_source_resources_mirror] at time 03:25:22.282901 duration_in_ms=106.659
2019-05-15 03:25:22,283 [salt.state       :1780][INFO    ][32482] Running state [maasng.boot_resources_import] at time 03:25:22.283894
2019-05-15 03:25:22,284 [salt.state       :1813][INFO    ][32482] Executing state module.run for [maasng.boot_resources_import]
2019-05-15 03:25:22,284 [salt.utils.decorators:613 ][WARNING ][32482] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:25:22,402 [salt.loaded.ext.module.maasng:1600][INFO    ][32482] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-15 03:25:27,460 [salt.loaded.ext.module.maasng:1600][INFO    ][32482] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-15 03:25:28,175 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515032528162442
2019-05-15 03:25:28,198 [salt.minion      :1432][INFO    ][32560] Starting a new job with PID 32560
2019-05-15 03:25:28,220 [salt.minion      :1711][INFO    ][32560] Returning information for job: 20190515032528162442
2019-05-15 03:25:32,521 [salt.loaded.ext.module.maasng:1600][INFO    ][32482] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-15 03:25:37,633 [salt.state       :300 ][INFO    ][32482] {'ret': True}
2019-05-15 03:25:37,634 [salt.state       :1951][INFO    ][32482] Completed state [maasng.boot_resources_import] at time 03:25:37.634324 duration_in_ms=15350.429
2019-05-15 03:25:37,635 [salt.state       :1780][INFO    ][32482] Running state [maas_region_boot_sources_selection_xenial] at time 03:25:37.635606
2019-05-15 03:25:37,636 [salt.state       :1813][INFO    ][32482] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-15 03:25:37,856 [salt.state       :300 ][INFO    ][32482] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-15 03:25:37,857 [salt.state       :1951][INFO    ][32482] Completed state [maas_region_boot_sources_selection_xenial] at time 03:25:37.857211 duration_in_ms=221.604
2019-05-15 03:25:37,858 [salt.state       :1780][INFO    ][32482] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 03:25:37.858521
2019-05-15 03:25:37,859 [salt.state       :1813][INFO    ][32482] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-15 03:25:37,859 [salt.utils.decorators:613 ][WARNING ][32482] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:25:37,860 [salt.loaded.ext.module.maasng:1771][INFO    ][32482] boot-sources sync initiated for ALL Rack's
2019-05-15 03:25:38,953 [salt.state       :300 ][INFO    ][32482] {'ret': True}
2019-05-15 03:25:38,953 [salt.state       :1951][INFO    ][32482] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 03:25:38.953458 duration_in_ms=1094.936
2019-05-15 03:25:38,955 [salt.state       :1780][INFO    ][32482] Running state [maas.process_maas_config] at time 03:25:38.955637
2019-05-15 03:25:38,956 [salt.state       :1813][INFO    ][32482] Executing state module.run for [maas.process_maas_config]
2019-05-15 03:25:38,956 [salt.utils.decorators:613 ][WARNING ][32482] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:25:38,957 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=enable_http_proxy value=True
2019-05-15 03:25:39,020 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=upstream_dns value=8.8.8.8
2019-05-15 03:25:41,845 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=commissioning_distro_series value=xenial
2019-05-15 03:25:41,931 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=default_osystem value=ubuntu
2019-05-15 03:25:42,001 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=active_discovery_interval value=600
2019-05-15 03:25:42,070 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=dnssec_validation value=no
2019-05-15 03:25:42,127 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=maas_name value=mas01
2019-05-15 03:25:42,172 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=network_discovery value=enabled
2019-05-15 03:25:42,319 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=enable_third_party_drivers value=True
2019-05-15 03:25:42,384 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=default_storage_layout value=lvm
2019-05-15 03:25:42,437 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=ntp_external_only value=True
2019-05-15 03:25:42,499 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-15 03:25:42,550 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=default_distro_series value=xenial
2019-05-15 03:25:42,604 [salt.loaded.ext.module.maas:92  ][INFO    ][32482] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-05-15 03:25:42,750 [salt.state       :300 ][INFO    ][32482] {'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-15 03:25:42,751 [salt.state       :1951][INFO    ][32482] Completed state [maas.process_maas_config] at time 03:25:42.751242 duration_in_ms=3795.604
2019-05-15 03:25:42,752 [salt.state       :1780][INFO    ][32482] Running state [pxe_admin] at time 03:25:42.752208
2019-05-15 03:25:42,752 [salt.state       :1813][INFO    ][32482] Executing state maasng.fabric_present for [pxe_admin]
2019-05-15 03:25:42,821 [salt.loaded.ext.module.maasng:945 ][INFO    ][32482] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'name': u'untagged', 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-15 03:25:42,899 [salt.loaded.ext.module.maasng:1008][WARNING ][32482] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-15 03:25:42,899 [salt.loaded.ext.module.maasng:1011][WARNING ][32482] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-15 03:25:42,960 [salt.state       :300 ][INFO    ][32482] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-15 03:25:42,961 [salt.state       :1951][INFO    ][32482] Completed state [pxe_admin] at time 03:25:42.961025 duration_in_ms=208.816
2019-05-15 03:25:42,961 [salt.state       :1780][INFO    ][32482] Running state [vlan 0] at time 03:25:42.961518
2019-05-15 03:25:42,962 [salt.state       :1813][INFO    ][32482] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-15 03:25:43,031 [salt.loaded.ext.module.maasng:945 ][INFO    ][32482] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', 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-15 03:25:43,154 [salt.loaded.ext.module.maasng:945 ][INFO    ][32482] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {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'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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {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'a4cctt', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-05-15 03:25:43,402 [salt.loaded.ext.module.maasng:945 ][INFO    ][32482] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {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'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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {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'a4cctt', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-05-15 03:25:43,491 [salt.state       :300 ][INFO    ][32482] {'new': 'Vlan untagged was updated'}
2019-05-15 03:25:43,491 [salt.state       :1951][INFO    ][32482] Completed state [vlan 0] at time 03:25:43.491726 duration_in_ms=530.208
2019-05-15 03:25:43,493 [salt.state       :1780][INFO    ][32482] Running state [192.168.11.0/24] at time 03:25:43.492969
2019-05-15 03:25:43,493 [salt.state       :1813][INFO    ][32482] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-15 03:25:43,647 [salt.loaded.ext.module.maasng:945 ][INFO    ][32482] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-15 03:25:43,647 [salt.loaded.ext.module.maasng:1235][WARNING ][32482] Ignoring parameter vlan:0
2019-05-15 03:25:43,702 [salt.state       :300 ][INFO    ][32482] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-15 03:25:43,702 [salt.state       :1951][INFO    ][32482] Completed state [192.168.11.0/24] at time 03:25:43.702750 duration_in_ms=209.782
2019-05-15 03:25:43,703 [salt.state       :1780][INFO    ][32482] Running state [maas_create_iprange_1] at time 03:25:43.703325
2019-05-15 03:25:43,703 [salt.state       :1813][INFO    ][32482] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-15 03:25:43,755 [salt.state       :300 ][INFO    ][32482] Iprange maas_create_iprange_1 already exist.
2019-05-15 03:25:43,756 [salt.state       :1951][INFO    ][32482] Completed state [maas_create_iprange_1] at time 03:25:43.756136 duration_in_ms=52.809
2019-05-15 03:25:43,756 [salt.state       :1780][INFO    ][32482] Running state [vlan 0] at time 03:25:43.756579
2019-05-15 03:25:43,757 [salt.state       :1813][INFO    ][32482] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-15 03:25:43,803 [salt.loaded.ext.module.maasng:945 ][INFO    ][32482] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'name': u'untagged', 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-15 03:25:43,911 [salt.loaded.ext.module.maasng:945 ][INFO    ][32482] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', 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-15 03:25:44,107 [salt.loaded.ext.module.maasng:945 ][INFO    ][32482] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'name': u'untagged', 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-15 03:25:44,167 [salt.state       :300 ][INFO    ][32482] {'new': 'Vlan untagged was updated'}
2019-05-15 03:25:44,167 [salt.state       :1951][INFO    ][32482] Completed state [vlan 0] at time 03:25:44.167787 duration_in_ms=411.207
2019-05-15 03:25:44,168 [salt.state       :1780][INFO    ][32482] Running state [opnfv] at time 03:25:44.168334
2019-05-15 03:25:44,168 [salt.state       :1813][INFO    ][32482] Executing state maasng.sshkey_present for [opnfv]
2019-05-15 03:25:44,203 [salt.loaded.ext.module.maasng:1903][INFO    ][32482] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-15 03:25:44,203 [salt.state       :300 ][INFO    ][32482] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-15 03:25:44,204 [salt.state       :1951][INFO    ][32482] Completed state [opnfv] at time 03:25:44.203992 duration_in_ms=35.658
2019-05-15 03:25:44,206 [salt.minion      :1711][INFO    ][32482] Returning information for job: 20190515032513134214
2019-05-15 03:25:44,722 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515032544709252
2019-05-15 03:25:44,742 [salt.minion      :1432][INFO    ][531] Starting a new job with PID 531
2019-05-15 03:25:48,381 [salt.state       :915 ][INFO    ][531] Loading fresh modules for state activity
2019-05-15 03:25:48,441 [salt.fileclient  :1219][INFO    ][531] Fetching file from saltenv 'base', ** done ** 'maas/machines/init.sls'
2019-05-15 03:25:48,486 [salt.state       :1780][INFO    ][531] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:25:48.486660
2019-05-15 03:25:48,487 [salt.state       :1813][INFO    ][531] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:25:48,489 [salt.loaded.int.module.cmdmod:395 ][INFO    ][531] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:25:49,939 [salt.state       :300 ][INFO    ][531] {'pid': 556, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:25:49,940 [salt.state       :1951][INFO    ][531] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:25:49.940440 duration_in_ms=1453.778
2019-05-15 03:25:49,943 [salt.state       :1780][INFO    ][531] Running state [maas.process_machines] at time 03:25:49.943845
2019-05-15 03:25:49,944 [salt.state       :1813][INFO    ][531] Executing state module.run for [maas.process_machines]
2019-05-15 03:25:49,945 [salt.utils.decorators:613 ][WARNING ][531] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:25:50,013 [salt.loaded.ext.module.maas:412 ][WARNING ][531] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:25:50,014 [salt.loaded.ext.module.maas:92  ][INFO    ][531] 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-15 03:25:51,620 [salt.loaded.ext.module.maas:412 ][WARNING ][531] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:25:51,621 [salt.loaded.ext.module.maas:92  ][INFO    ][531] 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-15 03:25:53,058 [salt.loaded.ext.module.maas:412 ][WARNING ][531] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:25:53,059 [salt.loaded.ext.module.maas:92  ][INFO    ][531] 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-15 03:25:54,532 [salt.loaded.ext.module.maas:412 ][WARNING ][531] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:25:54,533 [salt.loaded.ext.module.maas:92  ][INFO    ][531] 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-15 03:25:56,011 [salt.loaded.ext.module.maas:412 ][WARNING ][531] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:25:56,012 [salt.loaded.ext.module.maas:92  ][INFO    ][531] 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-15 03:25:57,389 [salt.state       :300 ][INFO    ][531] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-15 03:25:57,389 [salt.state       :1951][INFO    ][531] Completed state [maas.process_machines] at time 03:25:57.389774 duration_in_ms=7445.928
2019-05-15 03:25:57,394 [salt.minion      :1711][INFO    ][531] Returning information for job: 20190515032544709252
2019-05-15 03:26:28,432 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515032628419057
2019-05-15 03:26:28,455 [salt.minion      :1432][INFO    ][859] Starting a new job with PID 859
2019-05-15 03:26:32,231 [salt.state       :915 ][INFO    ][859] Loading fresh modules for state activity
2019-05-15 03:26:32,284 [salt.fileclient  :1219][INFO    ][859] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-15 03:26:32,325 [salt.state       :1780][INFO    ][859] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:26:32.324967
2019-05-15 03:26:32,325 [salt.state       :1813][INFO    ][859] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:26:32,327 [salt.loaded.int.module.cmdmod:395 ][INFO    ][859] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:26:33,775 [salt.state       :300 ][INFO    ][859] {'pid': 866, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:26:33,776 [salt.state       :1951][INFO    ][859] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:26:33.776698 duration_in_ms=1451.731
2019-05-15 03:26:33,780 [salt.state       :1780][INFO    ][859] Running state [maas.wait_for_machine_status] at time 03:26:33.780012
2019-05-15 03:26:33,780 [salt.state       :1813][INFO    ][859] Executing state module.run for [maas.wait_for_machine_status]
2019-05-15 03:26:33,781 [salt.utils.decorators:613 ][WARNING ][859] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:26:34,685 [salt.loaded.ext.module.maas:1023][INFO    ][859] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.10554504s left)
2019-05-15 03:26:43,514 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515032643501627
2019-05-15 03:26:43,538 [salt.minion      :1432][INFO    ][919] Starting a new job with PID 919
2019-05-15 03:26:43,560 [salt.minion      :1711][INFO    ][919] Returning information for job: 20190515032643501627
2019-05-15 03:27:05,605 [salt.loaded.ext.module.maas:1023][INFO    ][859] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1468.1861639s left)
2019-05-15 03:27:13,563 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515032713551258
2019-05-15 03:27:13,588 [salt.minion      :1432][INFO    ][939] Starting a new job with PID 939
2019-05-15 03:27:13,611 [salt.minion      :1711][INFO    ][939] Returning information for job: 20190515032713551258
2019-05-15 03:27:36,647 [salt.loaded.ext.module.maas:1023][INFO    ][859] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1437.14399385s left)
2019-05-15 03:27:43,612 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515032743600828
2019-05-15 03:27:43,636 [salt.minion      :1432][INFO    ][1108] Starting a new job with PID 1108
2019-05-15 03:27:43,658 [salt.minion      :1711][INFO    ][1108] Returning information for job: 20190515032743600828
2019-05-15 03:28:07,957 [salt.loaded.ext.module.maas:1023][INFO    ][859] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1405.83338189s left)
2019-05-15 03:28:13,654 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515032813641886
2019-05-15 03:28:13,677 [salt.minion      :1432][INFO    ][1222] Starting a new job with PID 1222
2019-05-15 03:28:13,700 [salt.minion      :1711][INFO    ][1222] Returning information for job: 20190515032813641886
2019-05-15 03:28:39,456 [salt.loaded.ext.module.maas:1023][INFO    ][859] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1374.33461499s left)
2019-05-15 03:28:43,710 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515032843697319
2019-05-15 03:28:43,733 [salt.minion      :1432][INFO    ][1978] Starting a new job with PID 1978
2019-05-15 03:28:43,756 [salt.minion      :1711][INFO    ][1978] Returning information for job: 20190515032843697319
2019-05-15 03:29:11,114 [salt.loaded.ext.module.maas:1023][INFO    ][859] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1342.67652798s left)
2019-05-15 03:29:13,762 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515032913746268
2019-05-15 03:29:13,786 [salt.minion      :1432][INFO    ][2008] Starting a new job with PID 2008
2019-05-15 03:29:13,808 [salt.minion      :1711][INFO    ][2008] Returning information for job: 20190515032913746268
2019-05-15 03:29:43,826 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515032943811769
2019-05-15 03:29:43,850 [salt.minion      :1432][INFO    ][2274] Starting a new job with PID 2274
2019-05-15 03:29:43,872 [salt.minion      :1711][INFO    ][2274] Returning information for job: 20190515032943811769
2019-05-15 03:29:44,717 [salt.state       :300 ][INFO    ][859] {'ret': True}
2019-05-15 03:29:44,717 [salt.state       :1951][INFO    ][859] Completed state [maas.wait_for_machine_status] at time 03:29:44.717499 duration_in_ms=190937.486
2019-05-15 03:29:44,721 [salt.minion      :1711][INFO    ][859] Returning information for job: 20190515032628419057
2019-05-15 03:29:45,382 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515032945369280
2019-05-15 03:29:45,406 [salt.minion      :1432][INFO    ][2282] Starting a new job with PID 2282
2019-05-15 03:29:49,159 [salt.state       :915 ][INFO    ][2282] Loading fresh modules for state activity
2019-05-15 03:29:49,211 [salt.fileclient  :1219][INFO    ][2282] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-15 03:29:49,296 [salt.state       :1780][INFO    ][2282] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:49.296244
2019-05-15 03:29:49,296 [salt.state       :1813][INFO    ][2282] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:29:49,298 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2282] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:29:50,748 [salt.state       :300 ][INFO    ][2282] {'pid': 2290, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:29:50,748 [salt.state       :1951][INFO    ][2282] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:50.748543 duration_in_ms=1452.299
2019-05-15 03:29:50,750 [salt.state       :1780][INFO    ][2282] Running state [maas_machines_storage_cmp002_lvm] at time 03:29:50.749969
2019-05-15 03:29:50,750 [salt.state       :1813][INFO    ][2282] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-15 03:29:52,225 [salt.loaded.ext.module.maasng:610 ][INFO    ][2282] snwk4f
2019-05-15 03:29:52,226 [salt.loaded.ext.module.maasng:626 ][INFO    ][2282] sda
2019-05-15 03:29:52,854 [salt.loaded.ext.module.maasng:361 ][INFO    ][2282] snwk4f
2019-05-15 03:29:52,987 [salt.loaded.ext.module.maasng:367 ][INFO    ][2282] [{u'size': 2397998940160, u'name': u'sda', u'tags': [u'rotary'], u'used_size': 2397998940160, u'id': 1, u'partitions': [{u'uuid': u'd4ac0fdf-d194-475b-a8aa-4738354aa4dd', u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/1/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'snwk4f', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'b9e2226b-1ee5-46f5-8826-afbf2096bc0c', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 1}], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'snwk4f', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/1/'}, {u'size': 2397988454400, u'name': u'vgroot-lvroot', u'tags': [], u'used_size': 2397988454400, u'id': 12, u'partitions': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'ee624f1b-9f80-4648-adc4-1e99c6a137a1', u'fstype': u'ext4'}, u'uuid': u'605e4088-2965-4f47-9e19-e091150baf20', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'snwk4f', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'type': u'virtual', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/12/'}]
2019-05-15 03:29:52,988 [salt.loaded.ext.module.maasng:632 ][INFO    ][2282] vgroot
2019-05-15 03:29:52,988 [salt.loaded.ext.module.maasng:635 ][INFO    ][2282] lvroot
2019-05-15 03:29:52,988 [salt.loaded.ext.module.maasng:639 ][INFO    ][2282] 107374182400
2019-05-15 03:29:53,701 [salt.loaded.ext.module.maasng:645 ][INFO    ][2282] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, u'disable_ipv4': False, u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'min_hwe_kernel': u'ga-16.04', u'status_action': u'modules-final', u'tag_names': [], u'swap_size': None, u'commissioning_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'zone': {u'resource_uri': u'/MAAS/api/2.0/zones/default/', u'id': 1, u'name': u'default', u'description': u''}, u'resource_uri': u'/MAAS/api/2.0/machines/snwk4f/', u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'commissioning_status': 2, u'testing_status': 2, u'system_id': u'snwk4f', 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'model': None, u'uuid': u'5657532f-f25c-490f-8aa3-6a26442811bf', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'filesystem': {u'uuid': u'435602a7-f7a2-475b-8801-800df9ad0127', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'snwk4f', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/16/'}], u'blockdevice_set': [{u'size': 2397998940160, u'block_size': 4096, u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'snwk4f', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/1/', u'used_size': 2397998940160, u'id': 1, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'363861d5-30f3-4e5f-b677-2e841e9d85eb', u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/1/partition/10', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'snwk4f', u'filesystem': {u'uuid': u'e1d0ce88-5242-4f9a-8752-f063ae6de2f0', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 10, u'size': 2397992648704}]}, {u'size': 107374182400, u'block_size': 4096, u'uuid': u'5657532f-f25c-490f-8aa3-6a26442811bf', u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'filesystem': {u'uuid': u'435602a7-f7a2-475b-8801-800df9ad0127', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'snwk4f', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/16/', u'used_size': 107374182400, u'id': 16, u'serial': None, u'partitions': []}], u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'363861d5-30f3-4e5f-b677-2e841e9d85eb', u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/1/partition/10', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'snwk4f', u'filesystem': {u'uuid': u'e1d0ce88-5242-4f9a-8752-f063ae6de2f0', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 10, u'size': 2397992648704}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'snwk4f', u'partition_table_type': u'GPT', u'available_size': 0, 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'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/1/'}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'snwk4f', u'id': 10}], u'special_filesystems': [], u'current_commissioning_result_id': 2, u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'uuid': None, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'uuid': u'363861d5-30f3-4e5f-b677-2e841e9d85eb', u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/1/partition/10', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'snwk4f', u'filesystem': {u'uuid': u'e1d0ce88-5242-4f9a-8752-f063ae6de2f0', u'mount_point': None, u'mount_options': None, u'fstype': u'lvm-pv', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 1, u'type': u'partition', u'id': 10, u'size': 2397992648704}], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'snwk4f', u'partition_table_type': u'GPT', u'available_size': 0, 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'id': 1, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/blockdevices/1/'}, 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 38, u'mode': u'dhcp'}], u'tags': [], u'enabled': True, u'vlan': {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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'children': [], u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'snwk4f', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/interfaces/4/'}, {u'name': u'enp9s0', u'links': [{u'id': 39, u'mode': u'link_up'}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'children': [], u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6d', u'system_id': u'snwk4f', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/interfaces/9/'}, {u'name': u'enp8s0', u'links': [{u'id': 41, u'mode': u'link_up'}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'children': [], u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6c', u'system_id': u'snwk4f', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/interfaces/11/'}, {u'name': u'enp7s0', u'links': [{u'id': 42, u'mode': u'link_up'}], u'tags': [], u'enabled': True, u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'children': [], u'parents': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:6b', u'system_id': u'snwk4f', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/interfaces/20/'}], u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'node_type': 0, u'ip_addresses': [u'192.168.11.42'], u'architecture': u'amd64/generic', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42', u'id': 38, u'mode': u'dhcp'}], u'tags': [], u'enabled': True, u'vlan': {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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'children': [], u'parents': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'name': u'untagged', u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'mtu': 1500, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.42'}], u'mac_address': u'00:25:b5:a0:00:6a', u'system_id': u'snwk4f', u'effective_mtu': 1500, u'params': u'', u'type': u'physical', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/snwk4f/interfaces/4/'}, u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-05-15 03:29:53,703 [salt.state       :300 ][INFO    ][2282] {'new': {'storage_layout': 'lvm'}}
2019-05-15 03:29:53,704 [salt.state       :1951][INFO    ][2282] Completed state [maas_machines_storage_cmp002_lvm] at time 03:29:53.703989 duration_in_ms=2954.018
2019-05-15 03:29:53,704 [salt.state       :1780][INFO    ][2282] Running state [maas_machines_storage_cmp001_lvm] at time 03:29:53.704555
2019-05-15 03:29:53,705 [salt.state       :1813][INFO    ][2282] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-15 03:29:54,950 [salt.loaded.ext.module.maasng:610 ][INFO    ][2282] pmbx4m
2019-05-15 03:29:54,950 [salt.loaded.ext.module.maasng:626 ][INFO    ][2282] sda
2019-05-15 03:29:55,579 [salt.loaded.ext.module.maasng:361 ][INFO    ][2282] pmbx4m
2019-05-15 03:29:55,705 [salt.loaded.ext.module.maasng:367 ][INFO    ][2282] [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'available_size': 0, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/5/', u'type': u'physical', u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'pmbx4m', 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'size': 2397998940160, u'used_size': 2397998940160, u'id': 5, u'partitions': [{u'uuid': u'ce022f06-b8eb-4aba-b375-9654fe38ec92', u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/5/partition/9', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pmbx4m', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'4286b4d0-9578-4c35-a659-b81566a52a7f', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 5, u'type': u'partition', u'id': 9, u'size': 2397992648704}]}, {u'model': None, u'block_size': 4096, u'available_size': 0, u'uuid': u'b178f9b0-4c9f-4df9-9dcb-a55832a737fb', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/15/', u'type': u'virtual', u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'pmbx4m', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'bcef3a00-0d64-432f-9a95-5bb12564523d', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'size': 2397988454400, u'used_size': 2397988454400, u'id': 15, u'partitions': []}]
2019-05-15 03:29:55,706 [salt.loaded.ext.module.maasng:632 ][INFO    ][2282] vgroot
2019-05-15 03:29:55,706 [salt.loaded.ext.module.maasng:635 ][INFO    ][2282] lvroot
2019-05-15 03:29:55,706 [salt.loaded.ext.module.maasng:639 ][INFO    ][2282] 107374182400
2019-05-15 03:29:56,317 [salt.loaded.ext.module.maasng:645 ][INFO    ][2282] {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'memory_test_status': -1, u'ip_addresses': [u'192.168.11.38'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'hwe_kernel': u'', u'boot_interface': {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 51, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'params': u'', u'system_id': u'pmbx4m', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/interfaces/5/'}, u'node_type': 0, u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'modules-final', u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'pmbx4m', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'physicalblockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'82557aef-d202-4a8f-81bd-579dd7eed43a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pmbx4m', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'2785b105-0312-40b4-9d54-4a2ec7138a6e', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/5/partition/11', u'type': u'partition', u'id': 11, u'device_id': 5}], u'uuid': None, u'id': 5, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'pmbx4m', 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'size': 2397998940160, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/5/'}], u'blockdevice_set': [{u'block_size': 4096, u'uuid': None, u'tags': [u'rotary'], u'type': u'physical', u'id': 5, u'filesystem': None, u'partitions': [{u'size': 2397992648704, u'uuid': u'82557aef-d202-4a8f-81bd-579dd7eed43a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pmbx4m', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'2785b105-0312-40b4-9d54-4a2ec7138a6e', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/5/partition/11', u'type': u'partition', u'id': 11, u'device_id': 5}], u'name': u'sda', u'system_id': u'pmbx4m', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'used_size': 2397998940160, u'used_for': u'GPT partitioned with 1 partition', u'serial': u'618e72837274f1901cc7889705aa1b02', u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/5/'}, {u'block_size': 4096, u'uuid': u'6a864db2-1c89-4c27-ba31-833e26558c9f', u'tags': [], u'type': u'virtual', u'id': 17, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'db52d191-bde9-4d08-a9e9-275be8c91e39', u'label': u'root'}, u'partitions': [], u'name': u'vgroot-lvroot', u'system_id': u'pmbx4m', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'size': 107374182400, u'used_size': 107374182400, u'used_for': u'ext4 formatted filesystem mounted at /', u'serial': None, u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/17/'}], u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'on', u'owner_data': {}, u'memory_test_status_name': u'Unknown', u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'pmbx4m', u'id': 11}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'block_size': 4096, u'available_size': 0, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'partitions': [{u'size': 2397992648704, u'uuid': u'82557aef-d202-4a8f-81bd-579dd7eed43a', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'pmbx4m', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'2785b105-0312-40b4-9d54-4a2ec7138a6e', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/5/partition/11', u'type': u'partition', u'id': 11, u'device_id': 5}], u'uuid': None, u'id': 5, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'pmbx4m', 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'size': 2397998940160, u'used_size': 2397998940160, u'model': u'UCSB-MRAID12G', u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/5/'}, u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38', u'id': 51, u'mode': u'dhcp'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.38'}], u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'params': u'', u'system_id': u'pmbx4m', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/interfaces/5/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'name': u'enp8s0', u'links': [{u'id': 52, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'params': u'', u'system_id': u'pmbx4m', u'type': u'physical', u'id': 19, u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/interfaces/19/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'name': u'enp9s0', u'links': [{u'id': 53, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'params': u'', u'system_id': u'pmbx4m', u'type': u'physical', u'id': 21, u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/interfaces/21/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'name': u'enp7s0', u'links': [{u'id': 54, u'mode': u'link_up'}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'params': u'', u'system_id': u'pmbx4m', u'type': u'physical', u'id': 23, u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/interfaces/23/'}], u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'disable_ipv4': False, u'virtualblockdevice_set': [{u'block_size': 4096, u'available_size': 0, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'partitions': [], u'uuid': u'6a864db2-1c89-4c27-ba31-833e26558c9f', u'id': 17, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'pmbx4m', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'db52d191-bde9-4d08-a9e9-275be8c91e39', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'size': 107374182400, u'used_size': 107374182400, u'model': None, u'resource_uri': u'/MAAS/api/2.0/nodes/pmbx4m/blockdevices/17/'}], u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', u'commissioning_status_name': u'Passed', u'cpu_test_status_name': u'Unknown', u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/pmbx4m/'}
2019-05-15 03:29:56,320 [salt.state       :300 ][INFO    ][2282] {'new': {'storage_layout': 'lvm'}}
2019-05-15 03:29:56,320 [salt.state       :1951][INFO    ][2282] Completed state [maas_machines_storage_cmp001_lvm] at time 03:29:56.320521 duration_in_ms=2615.965
2019-05-15 03:29:56,324 [salt.minion      :1711][INFO    ][2282] Returning information for job: 20190515032945369280
2019-05-15 03:29:56,938 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515032956929808
2019-05-15 03:29:56,953 [salt.minion      :1432][INFO    ][2347] Starting a new job with PID 2347
2019-05-15 03:29:57,628 [salt.state       :915 ][INFO    ][2347] Loading fresh modules for state activity
2019-05-15 03:29:57,680 [salt.fileclient  :1219][INFO    ][2347] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-15 03:29:57,720 [salt.state       :1780][INFO    ][2347] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:57.720902
2019-05-15 03:29:57,721 [salt.state       :1813][INFO    ][2347] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:29:57,723 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2347] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:29:59,315 [salt.state       :300 ][INFO    ][2347] {'pid': 2359, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:29:59,316 [salt.state       :1951][INFO    ][2347] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:29:59.316179 duration_in_ms=1595.276
2019-05-15 03:29:59,318 [salt.state       :1780][INFO    ][2347] Running state [maas.deploy_machines] at time 03:29:59.318866
2019-05-15 03:29:59,319 [salt.state       :1813][INFO    ][2347] Executing state module.run for [maas.deploy_machines]
2019-05-15 03:29:59,320 [salt.utils.decorators:613 ][WARNING ][2347] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:30:00,055 [salt.loaded.ext.module.maas:684 ][INFO    ][2347] deploymachines hwe_kernel=ga-16.04 system_id=snwk4f distro_series=xenial
2019-05-15 03:30:02,179 [salt.loaded.ext.module.maas:684 ][INFO    ][2347] deploymachines hwe_kernel=ga-16.04 system_id=pmbx4m distro_series=xenial
2019-05-15 03:30:04,358 [salt.loaded.ext.module.maas:684 ][INFO    ][2347] deploymachines hwe_kernel=ga-16.04 system_id=a3ydws distro_series=xenial
2019-05-15 03:30:07,066 [salt.loaded.ext.module.maas:684 ][INFO    ][2347] deploymachines hwe_kernel=ga-16.04 system_id=k6syp7 distro_series=xenial
2019-05-15 03:30:09,683 [salt.loaded.ext.module.maas:684 ][INFO    ][2347] deploymachines hwe_kernel=ga-16.04 system_id=mqgsn8 distro_series=xenial
2019-05-15 03:30:12,012 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033012000673
2019-05-15 03:30:12,035 [salt.minion      :1432][INFO    ][2621] Starting a new job with PID 2621
2019-05-15 03:30:12,059 [salt.minion      :1711][INFO    ][2621] Returning information for job: 20190515033012000673
2019-05-15 03:30:12,235 [salt.state       :300 ][INFO    ][2347] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-15 03:30:12,236 [salt.state       :1951][INFO    ][2347] Completed state [maas.deploy_machines] at time 03:30:12.236285 duration_in_ms=12917.417
2019-05-15 03:30:12,240 [salt.minion      :1711][INFO    ][2347] Returning information for job: 20190515032956929808
2019-05-15 03:30:12,881 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515033012868172
2019-05-15 03:30:12,904 [salt.minion      :1432][INFO    ][2635] Starting a new job with PID 2635
2019-05-15 03:30:16,612 [salt.state       :915 ][INFO    ][2635] Loading fresh modules for state activity
2019-05-15 03:30:16,665 [salt.fileclient  :1219][INFO    ][2635] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-15 03:30:16,708 [salt.state       :1780][INFO    ][2635] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:30:16.708359
2019-05-15 03:30:16,708 [salt.state       :1813][INFO    ][2635] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:30:16,710 [salt.loaded.int.module.cmdmod:395 ][INFO    ][2635] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:30:18,164 [salt.state       :300 ][INFO    ][2635] {'pid': 2648, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:30:18,165 [salt.state       :1951][INFO    ][2635] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:30:18.165171 duration_in_ms=1456.812
2019-05-15 03:30:18,168 [salt.state       :1780][INFO    ][2635] Running state [maas.wait_for_machine_status] at time 03:30:18.168462
2019-05-15 03:30:18,169 [salt.state       :1813][INFO    ][2635] Executing state module.run for [maas.wait_for_machine_status]
2019-05-15 03:30:18,169 [salt.utils.decorators:613 ][WARNING ][2635] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:30:21,790 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.38879108s left)
2019-05-15 03:30:28,010 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033027996605
2019-05-15 03:30:28,033 [salt.minion      :1432][INFO    ][2661] Starting a new job with PID 2661
2019-05-15 03:30:28,057 [salt.minion      :1711][INFO    ][2661] Returning information for job: 20190515033027996605
2019-05-15 03:30:55,187 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2212.99250913s left)
2019-05-15 03:30:58,066 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033058052546
2019-05-15 03:30:58,090 [salt.minion      :1432][INFO    ][2711] Starting a new job with PID 2711
2019-05-15 03:30:58,113 [salt.minion      :1711][INFO    ][2711] Returning information for job: 20190515033058052546
2019-05-15 03:31:28,156 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033128143764
2019-05-15 03:31:28,178 [salt.minion      :1432][INFO    ][2731] Starting a new job with PID 2731
2019-05-15 03:31:28,199 [salt.minion      :1711][INFO    ][2731] Returning information for job: 20190515033128143764
2019-05-15 03:31:28,682 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.49692416s left)
2019-05-15 03:31:58,203 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033158190543
2019-05-15 03:31:58,221 [salt.minion      :1432][INFO    ][2870] Starting a new job with PID 2870
2019-05-15 03:31:58,233 [salt.minion      :1711][INFO    ][2870] Returning information for job: 20190515033158190543
2019-05-15 03:32:01,564 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.61531115s left)
2019-05-15 03:32:28,229 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033228216727
2019-05-15 03:32:28,253 [salt.minion      :1432][INFO    ][3044] Starting a new job with PID 3044
2019-05-15 03:32:28,275 [salt.minion      :1711][INFO    ][3044] Returning information for job: 20190515033228216727
2019-05-15 03:32:34,719 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.45991111s left)
2019-05-15 03:32:58,282 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033258270346
2019-05-15 03:32:58,307 [salt.minion      :1432][INFO    ][3792] Starting a new job with PID 3792
2019-05-15 03:32:58,329 [salt.minion      :1711][INFO    ][3792] Returning information for job: 20190515033258270346
2019-05-15 03:33:07,906 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2080.27257705s left)
2019-05-15 03:33:28,329 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033328317003
2019-05-15 03:33:28,353 [salt.minion      :1432][INFO    ][3818] Starting a new job with PID 3818
2019-05-15 03:33:28,377 [salt.minion      :1711][INFO    ][3818] Returning information for job: 20190515033328317003
2019-05-15 03:33:40,933 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2047.24621201s left)
2019-05-15 03:33:58,393 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033358380570
2019-05-15 03:33:58,417 [salt.minion      :1432][INFO    ][4128] Starting a new job with PID 4128
2019-05-15 03:33:58,440 [salt.minion      :1711][INFO    ][4128] Returning information for job: 20190515033358380570
2019-05-15 03:34:14,262 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.917243s left)
2019-05-15 03:34:28,460 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033428445471
2019-05-15 03:34:28,484 [salt.minion      :1432][INFO    ][4157] Starting a new job with PID 4157
2019-05-15 03:34:28,507 [salt.minion      :1711][INFO    ][4157] Returning information for job: 20190515033428445471
2019-05-15 03:34:47,712 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1980.46740603s left)
2019-05-15 03:34:58,541 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033458528565
2019-05-15 03:34:58,566 [salt.minion      :1432][INFO    ][4403] Starting a new job with PID 4403
2019-05-15 03:34:58,588 [salt.minion      :1711][INFO    ][4403] Returning information for job: 20190515033458528565
2019-05-15 03:35:20,580 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1947.59878302s left)
2019-05-15 03:35:28,603 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033528590195
2019-05-15 03:35:28,627 [salt.minion      :1432][INFO    ][4424] Starting a new job with PID 4424
2019-05-15 03:35:28,650 [salt.minion      :1711][INFO    ][4424] Returning information for job: 20190515033528590195
2019-05-15 03:35:54,227 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.9524672s left)
2019-05-15 03:35:58,683 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033558670432
2019-05-15 03:35:58,707 [salt.minion      :1432][INFO    ][4747] Starting a new job with PID 4747
2019-05-15 03:35:58,729 [salt.minion      :1711][INFO    ][4747] Returning information for job: 20190515033558670432
2019-05-15 03:36:27,501 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1880.67821002s left)
2019-05-15 03:36:28,767 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033628754157
2019-05-15 03:36:28,783 [salt.minion      :1432][INFO    ][4770] Starting a new job with PID 4770
2019-05-15 03:36:28,804 [salt.minion      :1711][INFO    ][4770] Returning information for job: 20190515033628754157
2019-05-15 03:36:58,847 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033658834228
2019-05-15 03:36:58,864 [salt.minion      :1432][INFO    ][5111] Starting a new job with PID 5111
2019-05-15 03:36:58,878 [salt.minion      :1711][INFO    ][5111] Returning information for job: 20190515033658834228
2019-05-15 03:37:00,845 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1847.33373618s left)
2019-05-15 03:37:28,920 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033728908660
2019-05-15 03:37:28,944 [salt.minion      :1432][INFO    ][5136] Starting a new job with PID 5136
2019-05-15 03:37:28,966 [salt.minion      :1711][INFO    ][5136] Returning information for job: 20190515033728908660
2019-05-15 03:37:34,089 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1814.09022117s left)
2019-05-15 03:37:59,018 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033759006222
2019-05-15 03:37:59,041 [salt.minion      :1432][INFO    ][5402] Starting a new job with PID 5402
2019-05-15 03:37:59,063 [salt.minion      :1711][INFO    ][5402] Returning information for job: 20190515033759006222
2019-05-15 03:38:07,675 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1780.50435805s left)
2019-05-15 03:38:29,128 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033829116059
2019-05-15 03:38:29,151 [salt.minion      :1432][INFO    ][5471] Starting a new job with PID 5471
2019-05-15 03:38:29,175 [salt.minion      :1711][INFO    ][5471] Returning information for job: 20190515033829116059
2019-05-15 03:38:40,597 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1747.58222413s left)
2019-05-15 03:38:59,167 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033859154142
2019-05-15 03:38:59,190 [salt.minion      :1432][INFO    ][5668] Starting a new job with PID 5668
2019-05-15 03:38:59,213 [salt.minion      :1711][INFO    ][5668] Returning information for job: 20190515033859154142
2019-05-15 03:39:14,096 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1714.08293605s left)
2019-05-15 03:39:29,244 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033929231592
2019-05-15 03:39:29,267 [salt.minion      :1432][INFO    ][5751] Starting a new job with PID 5751
2019-05-15 03:39:29,290 [salt.minion      :1711][INFO    ][5751] Returning information for job: 20190515033929231592
2019-05-15 03:39:47,898 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1680.280586s left)
2019-05-15 03:39:59,371 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515033959358759
2019-05-15 03:39:59,395 [salt.minion      :1432][INFO    ][6179] Starting a new job with PID 6179
2019-05-15 03:39:59,417 [salt.minion      :1711][INFO    ][6179] Returning information for job: 20190515033959358759
2019-05-15 03:40:21,060 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1647.11883116s left)
2019-05-15 03:40:29,504 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034029491727
2019-05-15 03:40:29,528 [salt.minion      :1432][INFO    ][6200] Starting a new job with PID 6200
2019-05-15 03:40:29,551 [salt.minion      :1711][INFO    ][6200] Returning information for job: 20190515034029491727
2019-05-15 03:40:54,311 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1613.86765409s left)
2019-05-15 03:40:59,655 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034059643118
2019-05-15 03:40:59,680 [salt.minion      :1432][INFO    ][6256] Starting a new job with PID 6256
2019-05-15 03:40:59,704 [salt.minion      :1711][INFO    ][6256] Returning information for job: 20190515034059643118
2019-05-15 03:41:27,702 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1580.4776082s left)
2019-05-15 03:41:29,809 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034129796215
2019-05-15 03:41:29,832 [salt.minion      :1432][INFO    ][6276] Starting a new job with PID 6276
2019-05-15 03:41:29,854 [salt.minion      :1711][INFO    ][6276] Returning information for job: 20190515034129796215
2019-05-15 03:41:59,966 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034159952906
2019-05-15 03:41:59,989 [salt.minion      :1432][INFO    ][6330] Starting a new job with PID 6330
2019-05-15 03:42:00,011 [salt.minion      :1711][INFO    ][6330] Returning information for job: 20190515034159952906
2019-05-15 03:42:01,181 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1546.9975791s left)
2019-05-15 03:42:30,134 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034230121576
2019-05-15 03:42:30,158 [salt.minion      :1432][INFO    ][6350] Starting a new job with PID 6350
2019-05-15 03:42:30,181 [salt.minion      :1711][INFO    ][6350] Returning information for job: 20190515034230121576
2019-05-15 03:42:34,697 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1513.48228717s left)
2019-05-15 03:43:00,318 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034300305254
2019-05-15 03:43:00,341 [salt.minion      :1432][INFO    ][6408] Starting a new job with PID 6408
2019-05-15 03:43:00,363 [salt.minion      :1711][INFO    ][6408] Returning information for job: 20190515034300305254
2019-05-15 03:43:08,199 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1479.9799602s left)
2019-05-15 03:43:30,515 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034330503630
2019-05-15 03:43:30,538 [salt.minion      :1432][INFO    ][6433] Starting a new job with PID 6433
2019-05-15 03:43:30,560 [salt.minion      :1711][INFO    ][6433] Returning information for job: 20190515034330503630
2019-05-15 03:43:41,522 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1446.65738416s left)
2019-05-15 03:44:00,708 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034400696590
2019-05-15 03:44:00,731 [salt.minion      :1432][INFO    ][6623] Starting a new job with PID 6623
2019-05-15 03:44:00,755 [salt.minion      :1711][INFO    ][6623] Returning information for job: 20190515034400696590
2019-05-15 03:44:14,951 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1413.22789407s left)
2019-05-15 03:44:30,920 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034430907634
2019-05-15 03:44:30,945 [salt.minion      :1432][INFO    ][6645] Starting a new job with PID 6645
2019-05-15 03:44:30,968 [salt.minion      :1711][INFO    ][6645] Returning information for job: 20190515034430907634
2019-05-15 03:44:48,512 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1379.66680312s left)
2019-05-15 03:45:01,146 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034501134363
2019-05-15 03:45:01,166 [salt.minion      :1432][INFO    ][6702] Starting a new job with PID 6702
2019-05-15 03:45:01,186 [salt.minion      :1711][INFO    ][6702] Returning information for job: 20190515034501134363
2019-05-15 03:45:21,837 [salt.loaded.ext.module.maas:1023][INFO    ][2635] Waiting status:Deployed for machines:['kvm01']
sleep for:30s Timeout:2250s (1346.3415761s left)
2019-05-15 03:45:31,372 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034531359621
2019-05-15 03:45:31,395 [salt.minion      :1432][INFO    ][6723] Starting a new job with PID 6723
2019-05-15 03:45:31,420 [salt.minion      :1711][INFO    ][6723] Returning information for job: 20190515034531359621
2019-05-15 03:45:53,904 [salt.loaded.ext.module.maas:993 ][INFO    ][2635] Machine a3ydws mark broken
2019-05-15 03:45:54,668 [salt.loaded.ext.module.maas:996 ][INFO    ][2635] Machine a3ydws mark fixed
2019-05-15 03:45:55,678 [salt.loaded.ext.module.maas:684 ][INFO    ][2635] deploymachines hwe_kernel=ga-16.04 system_id=a3ydws distro_series=xenial
2019-05-15 03:45:58,680 [salt.loaded.ext.module.maas:160 ][ERROR   ][2635] 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-15 03:45:58,682 [salt.state       :302 ][ERROR   ][2635] 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-15 03:45:58,683 [salt.state       :1951][INFO    ][2635] Completed state [maas.wait_for_machine_status] at time 03:45:58.682928 duration_in_ms=940514.461
2019-05-15 03:45:58,693 [salt.minion      :1711][INFO    ][2635] Returning information for job: 20190515033012868172
2019-05-15 03:46:09,489 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command pillar.get with jid 20190515034609478455
2019-05-15 03:46:09,511 [salt.minion      :1432][INFO    ][6861] Starting a new job with PID 6861
2019-05-15 03:46:09,519 [salt.minion      :1711][INFO    ][6861] Returning information for job: 20190515034609478455
2019-05-15 03:46:10,032 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command service.status with jid 20190515034610019857
2019-05-15 03:46:10,054 [salt.minion      :1432][INFO    ][6866] Starting a new job with PID 6866
2019-05-15 03:46:10,446 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6866] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-15 03:46:10,478 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][6866] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-15 03:46:10,493 [salt.minion      :1711][INFO    ][6866] Returning information for job: 20190515034610019857
2019-05-15 03:46:11,026 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515034611013114
2019-05-15 03:46:11,048 [salt.minion      :1432][INFO    ][6877] Starting a new job with PID 6877
2019-05-15 03:46:14,752 [salt.state       :915 ][INFO    ][6877] Loading fresh modules for state activity
2019-05-15 03:46:15,079 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command 'salt-minion --version' in directory '/root'
2019-05-15 03:46:15,453 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command 'salt-minion --version' in directory '/root'
2019-05-15 03:46:16,290 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command 'salt-minion --version' in directory '/root'
2019-05-15 03:46:16,627 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command 'salt-minion --version' in directory '/root'
2019-05-15 03:46:17,987 [salt.state       :1780][INFO    ][6877] Running state [salt-minion] at time 03:46:17.987916
2019-05-15 03:46:17,988 [salt.state       :1813][INFO    ][6877] Executing state pkg.installed for [salt-minion]
2019-05-15 03:46:17,988 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-15 03:46:18,080 [salt.state       :300 ][INFO    ][6877] All specified packages are already installed
2019-05-15 03:46:18,081 [salt.state       :1951][INFO    ][6877] Completed state [salt-minion] at time 03:46:18.081209 duration_in_ms=93.294
2019-05-15 03:46:18,081 [salt.state       :1780][INFO    ][6877] Running state [salt_minion_dependency_packages] at time 03:46:18.081540
2019-05-15 03:46:18,081 [salt.state       :1813][INFO    ][6877] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-15 03:46:18,088 [salt.state       :300 ][INFO    ][6877] All specified packages are already installed
2019-05-15 03:46:18,088 [salt.state       :1951][INFO    ][6877] Completed state [salt_minion_dependency_packages] at time 03:46:18.088642 duration_in_ms=7.102
2019-05-15 03:46:18,091 [salt.state       :1780][INFO    ][6877] Running state [/etc/salt/minion.d/minion.conf] at time 03:46:18.091692
2019-05-15 03:46:18,091 [salt.state       :1813][INFO    ][6877] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-15 03:46:18,279 [salt.state       :300 ][INFO    ][6877] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-15 03:46:18,279 [salt.state       :1951][INFO    ][6877] Completed state [/etc/salt/minion.d/minion.conf] at time 03:46:18.279940 duration_in_ms=188.248
2019-05-15 03:46:18,280 [salt.state       :1780][INFO    ][6877] Running state [python-netaddr] at time 03:46:18.280118
2019-05-15 03:46:18,280 [salt.state       :1813][INFO    ][6877] Executing state pkg.installed for [python-netaddr]
2019-05-15 03:46:18,284 [salt.state       :300 ][INFO    ][6877] All specified packages are already installed
2019-05-15 03:46:18,284 [salt.state       :1951][INFO    ][6877] Completed state [python-netaddr] at time 03:46:18.284845 duration_in_ms=4.727
2019-05-15 03:46:18,286 [salt.state       :1780][INFO    ][6877] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:46:18.286869
2019-05-15 03:46:18,287 [salt.state       :1813][INFO    ][6877] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-15 03:46:18,296 [salt.state       :300 ][INFO    ][6877] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-15 03:46:18,296 [salt.state       :1951][INFO    ][6877] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:46:18.296306 duration_in_ms=9.437
2019-05-15 03:46:18,296 [salt.state       :1780][INFO    ][6877] Running state [salt-minion] at time 03:46:18.296951
2019-05-15 03:46:18,297 [salt.state       :1813][INFO    ][6877] Executing state service.running for [salt-minion]
2019-05-15 03:46:18,297 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-15 03:46:18,332 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-15 03:46:18,348 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-15 03:46:18,364 [salt.state       :300 ][INFO    ][6877] The service salt-minion is already running
2019-05-15 03:46:18,364 [salt.state       :1951][INFO    ][6877] Completed state [salt-minion] at time 03:46:18.364647 duration_in_ms=67.695
2019-05-15 03:46:18,366 [salt.state       :1780][INFO    ][6877] Running state [/etc/salt/grains.d] at time 03:46:18.366110
2019-05-15 03:46:18,366 [salt.state       :1813][INFO    ][6877] Executing state file.directory for [/etc/salt/grains.d]
2019-05-15 03:46:18,367 [salt.state       :300 ][INFO    ][6877] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-15 03:46:18,367 [salt.state       :1951][INFO    ][6877] Completed state [/etc/salt/grains.d] at time 03:46:18.367577 duration_in_ms=1.466
2019-05-15 03:46:18,368 [salt.state       :1780][INFO    ][6877] Running state [/etc/salt/grains] at time 03:46:18.368217
2019-05-15 03:46:18,368 [salt.state       :1813][INFO    ][6877] Executing state file.managed for [/etc/salt/grains]
2019-05-15 03:46:18,369 [salt.state       :300 ][INFO    ][6877] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-15 03:46:18,369 [salt.state       :1951][INFO    ][6877] Completed state [/etc/salt/grains] at time 03:46:18.369245 duration_in_ms=1.028
2019-05-15 03:46:18,369 [salt.state       :1780][INFO    ][6877] Running state [/etc/salt/grains.d/placeholder] at time 03:46:18.369704
2019-05-15 03:46:18,370 [salt.state       :1813][INFO    ][6877] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-15 03:46:18,370 [salt.state       :300 ][INFO    ][6877] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-15 03:46:18,370 [salt.state       :1951][INFO    ][6877] Completed state [/etc/salt/grains.d/placeholder] at time 03:46:18.370700 duration_in_ms=0.997
2019-05-15 03:46:18,371 [salt.state       :1780][INFO    ][6877] Running state [/etc/salt/grains.d/sphinx] at time 03:46:18.371143
2019-05-15 03:46:18,371 [salt.state       :1813][INFO    ][6877] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-15 03:46:18,381 [salt.state       :300 ][INFO    ][6877] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-15 03:46:18,381 [salt.state       :1951][INFO    ][6877] Completed state [/etc/salt/grains.d/sphinx] at time 03:46:18.381891 duration_in_ms=10.748
2019-05-15 03:46:18,384 [salt.state       :1780][INFO    ][6877] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:46:18.384069
2019-05-15 03:46:18,384 [salt.state       :1813][INFO    ][6877] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-15 03:46:18,384 [salt.state       :300 ][INFO    ][6877] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-15 03:46:18,384 [salt.state       :1951][INFO    ][6877] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:46:18.384934 duration_in_ms=0.865
2019-05-15 03:46:18,385 [salt.state       :1780][INFO    ][6877] Running state [/etc/salt/grains.d/dns_records] at time 03:46:18.385400
2019-05-15 03:46:18,385 [salt.state       :1813][INFO    ][6877] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-15 03:46:18,393 [salt.state       :300 ][INFO    ][6877] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-15 03:46:18,393 [salt.state       :1951][INFO    ][6877] Completed state [/etc/salt/grains.d/dns_records] at time 03:46:18.393798 duration_in_ms=8.398
2019-05-15 03:46:18,394 [salt.state       :1780][INFO    ][6877] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:46:18.394716
2019-05-15 03:46:18,395 [salt.state       :1813][INFO    ][6877] 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-15 03:46:18,395 [salt.state       :300 ][INFO    ][6877] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-15 03:46:18,395 [salt.state       :1951][INFO    ][6877] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:46:18.395584 duration_in_ms=0.868
2019-05-15 03:46:18,396 [salt.state       :1780][INFO    ][6877] Running state [/etc/salt/grains.d/salt] at time 03:46:18.396056
2019-05-15 03:46:18,396 [salt.state       :1813][INFO    ][6877] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-15 03:46:18,407 [salt.state       :300 ][INFO    ][6877] File /etc/salt/grains.d/salt is in the correct state
2019-05-15 03:46:18,407 [salt.state       :1951][INFO    ][6877] Completed state [/etc/salt/grains.d/salt] at time 03:46:18.407221 duration_in_ms=11.165
2019-05-15 03:46:18,408 [salt.state       :1780][INFO    ][6877] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:46:18.408104
2019-05-15 03:46:18,408 [salt.state       :1813][INFO    ][6877] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-15 03:46:18,408 [salt.state       :300 ][INFO    ][6877] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-15 03:46:18,409 [salt.state       :1951][INFO    ][6877] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:46:18.408966 duration_in_ms=0.862
2019-05-15 03:46:18,410 [salt.state       :1780][INFO    ][6877] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:46:18.410848
2019-05-15 03:46:18,411 [salt.state       :1813][INFO    ][6877] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-15 03:46:18,411 [salt.state       :300 ][INFO    ][6877] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-15 03:46:18,411 [salt.state       :1951][INFO    ][6877] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:46:18.411725 duration_in_ms=0.877
2019-05-15 03:46:18,412 [salt.state       :1780][INFO    ][6877] Running state [mine.update] at time 03:46:18.412393
2019-05-15 03:46:18,412 [salt.state       :1813][INFO    ][6877] Executing state module.wait for [mine.update]
2019-05-15 03:46:18,413 [salt.state       :300 ][INFO    ][6877] No changes made for mine.update
2019-05-15 03:46:18,413 [salt.state       :1951][INFO    ][6877] Completed state [mine.update] at time 03:46:18.413203 duration_in_ms=0.81
2019-05-15 03:46:18,413 [salt.state       :1780][INFO    ][6877] Running state [ca-certificates] at time 03:46:18.413447
2019-05-15 03:46:18,413 [salt.state       :1813][INFO    ][6877] Executing state pkg.installed for [ca-certificates]
2019-05-15 03:46:18,421 [salt.state       :300 ][INFO    ][6877] All specified packages are already installed
2019-05-15 03:46:18,421 [salt.state       :1951][INFO    ][6877] Completed state [ca-certificates] at time 03:46:18.421409 duration_in_ms=7.962
2019-05-15 03:46:18,422 [salt.state       :1780][INFO    ][6877] Running state [update-ca-certificates] at time 03:46:18.422121
2019-05-15 03:46:18,422 [salt.state       :1813][INFO    ][6877] Executing state cmd.wait for [update-ca-certificates]
2019-05-15 03:46:18,422 [salt.state       :300 ][INFO    ][6877] No changes made for update-ca-certificates
2019-05-15 03:46:18,423 [salt.state       :1951][INFO    ][6877] Completed state [update-ca-certificates] at time 03:46:18.422950 duration_in_ms=0.829
2019-05-15 03:46:18,423 [salt.state       :1780][INFO    ][6877] Running state [iptables] at time 03:46:18.423195
2019-05-15 03:46:18,423 [salt.state       :1813][INFO    ][6877] Executing state pkg.installed for [iptables]
2019-05-15 03:46:18,430 [salt.state       :300 ][INFO    ][6877] All specified packages are already installed
2019-05-15 03:46:18,430 [salt.state       :1951][INFO    ][6877] Completed state [iptables] at time 03:46:18.430642 duration_in_ms=7.447
2019-05-15 03:46:18,430 [salt.state       :1780][INFO    ][6877] Running state [iptables-persistent] at time 03:46:18.430881
2019-05-15 03:46:18,431 [salt.state       :1813][INFO    ][6877] Executing state pkg.installed for [iptables-persistent]
2019-05-15 03:46:18,437 [salt.state       :300 ][INFO    ][6877] All specified packages are already installed
2019-05-15 03:46:18,438 [salt.state       :1951][INFO    ][6877] Completed state [iptables-persistent] at time 03:46:18.438094 duration_in_ms=7.213
2019-05-15 03:46:18,439 [salt.state       :1780][INFO    ][6877] Running state [iptables_modules_v4_load] at time 03:46:18.439087
2019-05-15 03:46:18,439 [salt.state       :1813][INFO    ][6877] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-15 03:46:18,439 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command 'lsmod' in directory '/root'
2019-05-15 03:46:18,463 [salt.state       :300 ][INFO    ][6877] Kernel modules iptable_filter, ip_tables are already present
2019-05-15 03:46:18,463 [salt.state       :1951][INFO    ][6877] Completed state [iptables_modules_v4_load] at time 03:46:18.463732 duration_in_ms=24.644
2019-05-15 03:46:18,464 [salt.state       :1780][INFO    ][6877] Running state [/etc/iptables/rules.v4] at time 03:46:18.464504
2019-05-15 03:46:18,464 [salt.state       :1813][INFO    ][6877] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-15 03:46:18,581 [salt.state       :300 ][INFO    ][6877] File /etc/iptables/rules.v4 is in the correct state
2019-05-15 03:46:18,581 [salt.state       :1951][INFO    ][6877] Completed state [/etc/iptables/rules.v4] at time 03:46:18.581819 duration_in_ms=117.315
2019-05-15 03:46:18,583 [salt.state       :1780][INFO    ][6877] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:46:18.583698
2019-05-15 03:46:18,584 [salt.state       :1813][INFO    ][6877] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-15 03:46:18,585 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-15 03:46:18,606 [salt.state       :300 ][INFO    ][6877] onlyif execution failed
2019-05-15 03:46:18,606 [salt.state       :1951][INFO    ][6877] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:46:18.606825 duration_in_ms=23.128
2019-05-15 03:46:18,608 [salt.state       :1780][INFO    ][6877] Running state [netfilter-persistent] at time 03:46:18.608648
2019-05-15 03:46:18,609 [salt.state       :1813][INFO    ][6877] Executing state service.running for [netfilter-persistent]
2019-05-15 03:46:18,610 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-15 03:46:18,631 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-15 03:46:18,650 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-15 03:46:18,668 [salt.state       :300 ][INFO    ][6877] The service netfilter-persistent is already running
2019-05-15 03:46:18,669 [salt.state       :1951][INFO    ][6877] Completed state [netfilter-persistent] at time 03:46:18.669388 duration_in_ms=60.74
2019-05-15 03:46:18,670 [salt.state       :1780][INFO    ][6877] Running state [iptables_extra.remove_stale_tables] at time 03:46:18.670795
2019-05-15 03:46:18,671 [salt.state       :1813][INFO    ][6877] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-15 03:46:18,671 [salt.state       :300 ][INFO    ][6877] No changes made for iptables_extra.remove_stale_tables
2019-05-15 03:46:18,672 [salt.state       :1951][INFO    ][6877] Completed state [iptables_extra.remove_stale_tables] at time 03:46:18.672219 duration_in_ms=1.424
2019-05-15 03:46:18,672 [salt.state       :1780][INFO    ][6877] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:46:18.672642
2019-05-15 03:46:18,673 [salt.state       :1813][INFO    ][6877] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-15 03:46:18,674 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6877] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-15 03:46:18,689 [salt.state       :300 ][INFO    ][6877] onlyif execution failed
2019-05-15 03:46:18,689 [salt.state       :1951][INFO    ][6877] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:46:18.689625 duration_in_ms=16.983
2019-05-15 03:46:18,691 [salt.state       :1780][INFO    ][6877] Running state [/etc/iptables/rules.v6] at time 03:46:18.691118
2019-05-15 03:46:18,691 [salt.state       :1813][INFO    ][6877] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-15 03:46:18,692 [salt.state       :300 ][INFO    ][6877] File /etc/iptables/rules.v6 is not present
2019-05-15 03:46:18,692 [salt.state       :1951][INFO    ][6877] Completed state [/etc/iptables/rules.v6] at time 03:46:18.692668 duration_in_ms=1.551
2019-05-15 03:46:18,693 [salt.state       :1780][INFO    ][6877] Running state [iptables_extra.flush_all] at time 03:46:18.693734
2019-05-15 03:46:18,694 [salt.state       :1813][INFO    ][6877] Executing state module.wait for [iptables_extra.flush_all]
2019-05-15 03:46:18,694 [salt.state       :300 ][INFO    ][6877] No changes made for iptables_extra.flush_all
2019-05-15 03:46:18,695 [salt.state       :1951][INFO    ][6877] Completed state [iptables_extra.flush_all] at time 03:46:18.694947 duration_in_ms=1.213
2019-05-15 03:46:18,699 [salt.minion      :1711][INFO    ][6877] Returning information for job: 20190515034611013114
2019-05-15 03:46:19,314 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515034619301279
2019-05-15 03:46:19,338 [salt.minion      :1432][INFO    ][6953] Starting a new job with PID 6953
2019-05-15 03:46:20,081 [salt.state       :915 ][INFO    ][6953] Loading fresh modules for state activity
2019-05-15 03:46:20,690 [salt.state       :1780][INFO    ][6953] Running state [maas-rack-controller] at time 03:46:20.690825
2019-05-15 03:46:20,691 [salt.state       :1813][INFO    ][6953] Executing state pkg.installed for [maas-rack-controller]
2019-05-15 03:46:20,691 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6953] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-15 03:46:20,769 [salt.state       :300 ][INFO    ][6953] All specified packages are already installed
2019-05-15 03:46:20,769 [salt.state       :1951][INFO    ][6953] Completed state [maas-rack-controller] at time 03:46:20.769439 duration_in_ms=78.615
2019-05-15 03:46:20,769 [salt.state       :1780][INFO    ][6953] Running state [ipmitool] at time 03:46:20.769701
2019-05-15 03:46:20,769 [salt.state       :1813][INFO    ][6953] Executing state pkg.installed for [ipmitool]
2019-05-15 03:46:20,774 [salt.state       :300 ][INFO    ][6953] All specified packages are already installed
2019-05-15 03:46:20,774 [salt.state       :1951][INFO    ][6953] Completed state [ipmitool] at time 03:46:20.774607 duration_in_ms=4.906
2019-05-15 03:46:20,776 [salt.state       :1780][INFO    ][6953] Running state [/etc/maas/rackd.conf] at time 03:46:20.776889
2019-05-15 03:46:20,777 [salt.state       :1813][INFO    ][6953] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-15 03:46:20,777 [salt.state       :300 ][INFO    ][6953] No changes needed to be made
2019-05-15 03:46:20,778 [salt.state       :1951][INFO    ][6953] Completed state [/etc/maas/rackd.conf] at time 03:46:20.778028 duration_in_ms=1.139
2019-05-15 03:46:20,778 [salt.state       :1780][INFO    ][6953] Running state [/etc/maas/rackd.conf] at time 03:46:20.778197
2019-05-15 03:46:20,778 [salt.state       :1813][INFO    ][6953] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-15 03:46:20,778 [salt.loaded.int.states.file:2298][WARNING ][6953] 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-15 03:46:20,778 [salt.state       :300 ][INFO    ][6953] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-15 03:46:20,779 [salt.state       :1951][INFO    ][6953] Completed state [/etc/maas/rackd.conf] at time 03:46:20.779108 duration_in_ms=0.911
2019-05-15 03:46:20,779 [salt.state       :1780][INFO    ][6953] Running state [maas-rackd] at time 03:46:20.779826
2019-05-15 03:46:20,780 [salt.state       :1813][INFO    ][6953] Executing state service.running for [maas-rackd]
2019-05-15 03:46:20,780 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6953] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-15 03:46:20,812 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6953] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-15 03:46:20,830 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6953] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-15 03:46:20,846 [salt.state       :300 ][INFO    ][6953] The service maas-rackd is already running
2019-05-15 03:46:20,847 [salt.state       :1951][INFO    ][6953] Completed state [maas-rackd] at time 03:46:20.847021 duration_in_ms=67.194
2019-05-15 03:46:20,848 [salt.minion      :1711][INFO    ][6953] Returning information for job: 20190515034619301279
2019-05-15 03:46:21,469 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515034621456478
2019-05-15 03:46:21,492 [salt.minion      :1432][INFO    ][6976] Starting a new job with PID 6976
2019-05-15 03:46:22,244 [salt.state       :915 ][INFO    ][6976] Loading fresh modules for state activity
2019-05-15 03:46:22,924 [salt.state       :1780][INFO    ][6976] Running state [maas-region-controller] at time 03:46:22.923973
2019-05-15 03:46:22,924 [salt.state       :1813][INFO    ][6976] Executing state pkg.installed for [maas-region-controller]
2019-05-15 03:46:22,924 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-15 03:46:23,005 [salt.state       :300 ][INFO    ][6976] All specified packages are already installed
2019-05-15 03:46:23,005 [salt.state       :1951][INFO    ][6976] Completed state [maas-region-controller] at time 03:46:23.005473 duration_in_ms=81.5
2019-05-15 03:46:23,005 [salt.state       :1780][INFO    ][6976] Running state [python-oauth] at time 03:46:23.005743
2019-05-15 03:46:23,005 [salt.state       :1813][INFO    ][6976] Executing state pkg.installed for [python-oauth]
2019-05-15 03:46:23,010 [salt.state       :300 ][INFO    ][6976] All specified packages are already installed
2019-05-15 03:46:23,011 [salt.state       :1951][INFO    ][6976] Completed state [python-oauth] at time 03:46:23.011054 duration_in_ms=5.31
2019-05-15 03:46:23,013 [salt.state       :1780][INFO    ][6976] Running state [/etc/maas/regiond.conf] at time 03:46:23.013445
2019-05-15 03:46:23,013 [salt.state       :1813][INFO    ][6976] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-15 03:46:23,066 [salt.state       :300 ][INFO    ][6976] No changes needed to be made
2019-05-15 03:46:23,066 [salt.state       :1951][INFO    ][6976] Completed state [/etc/maas/regiond.conf] at time 03:46:23.066919 duration_in_ms=53.474
2019-05-15 03:46:23,067 [salt.state       :1780][INFO    ][6976] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:46:23.067386
2019-05-15 03:46:23,067 [salt.state       :1813][INFO    ][6976] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-15 03:46:23,131 [salt.state       :300 ][INFO    ][6976] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-15 03:46:23,132 [salt.state       :1951][INFO    ][6976] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:46:23.132234 duration_in_ms=64.848
2019-05-15 03:46:23,132 [salt.state       :1780][INFO    ][6976] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:46:23.132753
2019-05-15 03:46:23,133 [salt.state       :1813][INFO    ][6976] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-15 03:46:23,145 [salt.state       :300 ][INFO    ][6976] No changes needed to be made
2019-05-15 03:46:23,145 [salt.state       :1951][INFO    ][6976] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:46:23.145677 duration_in_ms=12.923
2019-05-15 03:46:23,146 [salt.state       :1780][INFO    ][6976] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:46:23.146165
2019-05-15 03:46:23,146 [salt.state       :1813][INFO    ][6976] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-15 03:46:23,169 [salt.state       :300 ][INFO    ][6976] No changes needed to be made
2019-05-15 03:46:23,169 [salt.state       :1951][INFO    ][6976] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:46:23.169497 duration_in_ms=23.331
2019-05-15 03:46:23,170 [salt.state       :1780][INFO    ][6976] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:46:23.170008
2019-05-15 03:46:23,170 [salt.state       :1813][INFO    ][6976] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-15 03:46:23,194 [salt.state       :300 ][INFO    ][6976] No changes needed to be made
2019-05-15 03:46:23,194 [salt.state       :1951][INFO    ][6976] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:46:23.194227 duration_in_ms=24.219
2019-05-15 03:46:23,194 [salt.state       :1780][INFO    ][6976] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:46:23.194695
2019-05-15 03:46:23,194 [salt.state       :1813][INFO    ][6976] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-15 03:46:23,206 [salt.state       :300 ][INFO    ][6976] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-15 03:46:23,206 [salt.state       :1951][INFO    ][6976] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:46:23.206601 duration_in_ms=11.906
2019-05-15 03:46:23,207 [salt.state       :1780][INFO    ][6976] Running state [a2enmod headers] at time 03:46:23.207790
2019-05-15 03:46:23,208 [salt.state       :1813][INFO    ][6976] Executing state cmd.run for [a2enmod headers]
2019-05-15 03:46:23,208 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command 'a2enmod headers' in directory '/root'
2019-05-15 03:46:23,279 [salt.state       :300 ][INFO    ][6976] {'pid': 6995, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-15 03:46:23,280 [salt.state       :1951][INFO    ][6976] Completed state [a2enmod headers] at time 03:46:23.280000 duration_in_ms=72.208
2019-05-15 03:46:23,280 [salt.state       :1780][INFO    ][6976] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:46:23.280573
2019-05-15 03:46:23,281 [salt.state       :1813][INFO    ][6976] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-15 03:46:23,299 [salt.state       :300 ][INFO    ][6976] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-15 03:46:23,300 [salt.state       :1951][INFO    ][6976] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:46:23.300160 duration_in_ms=19.586
2019-05-15 03:46:23,301 [salt.state       :1780][INFO    ][6976] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:46:23.301001
2019-05-15 03:46:23,301 [salt.state       :1813][INFO    ][6976] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-15 03:46:23,383 [salt.state       :300 ][INFO    ][6976] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-15 03:46:23,384 [salt.state       :1951][INFO    ][6976] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:46:23.384311 duration_in_ms=83.308
2019-05-15 03:46:23,385 [salt.state       :1780][INFO    ][6976] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:46:23.385043
2019-05-15 03:46:23,385 [salt.state       :1813][INFO    ][6976] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-15 03:46:23,449 [salt.state       :300 ][INFO    ][6976] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-15 03:46:23,449 [salt.state       :1951][INFO    ][6976] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:46:23.449786 duration_in_ms=64.743
2019-05-15 03:46:23,450 [salt.state       :1780][INFO    ][6976] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:46:23.450302
2019-05-15 03:46:23,450 [salt.state       :1813][INFO    ][6976] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-15 03:46:23,509 [salt.state       :300 ][INFO    ][6976] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-15 03:46:23,509 [salt.state       :1951][INFO    ][6976] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:46:23.509511 duration_in_ms=59.209
2019-05-15 03:46:23,509 [salt.state       :1780][INFO    ][6976] Running state [/root/.pgpass] at time 03:46:23.509809
2019-05-15 03:46:23,510 [salt.state       :1813][INFO    ][6976] Executing state file.managed for [/root/.pgpass]
2019-05-15 03:46:23,551 [salt.state       :300 ][INFO    ][6976] File /root/.pgpass is in the correct state
2019-05-15 03:46:23,551 [salt.state       :1951][INFO    ][6976] Completed state [/root/.pgpass] at time 03:46:23.551385 duration_in_ms=41.576
2019-05-15 03:46:23,556 [salt.state       :1780][INFO    ][6976] Running state [maas-region syncdb --noinput] at time 03:46:23.556069
2019-05-15 03:46:23,556 [salt.state       :1813][INFO    ][6976] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-15 03:46:23,557 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-15 03:46:25,491 [salt.state       :300 ][INFO    ][6976] {'pid': 7008, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: sites, contenttypes, metadataserver, maasserver, sessions, auth, piston3\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-05-15 03:46:25,491 [salt.state       :1951][INFO    ][6976] Completed state [maas-region syncdb --noinput] at time 03:46:25.491318 duration_in_ms=1935.249
2019-05-15 03:46:25,491 [salt.state       :2022][WARNING ][6976] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-15 03:46:25,492 [salt.state       :1780][INFO    ][6976] Running state [maas-regiond] at time 03:46:25.492508
2019-05-15 03:46:25,492 [salt.state       :1813][INFO    ][6976] Executing state service.running for [maas-regiond]
2019-05-15 03:46:25,493 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-15 03:46:25,527 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-15 03:46:25,542 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-15 03:46:25,557 [salt.state       :300 ][INFO    ][6976] The service maas-regiond is already running
2019-05-15 03:46:25,557 [salt.state       :1951][INFO    ][6976] Completed state [maas-regiond] at time 03:46:25.557947 duration_in_ms=65.439
2019-05-15 03:46:25,558 [salt.state       :1780][INFO    ][6976] Running state [bind9] at time 03:46:25.558927
2019-05-15 03:46:25,559 [salt.state       :1813][INFO    ][6976] Executing state service.running for [bind9]
2019-05-15 03:46:25,559 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-15 03:46:25,575 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-15 03:46:25,590 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-15 03:46:25,605 [salt.state       :300 ][INFO    ][6976] The service bind9 is already running
2019-05-15 03:46:25,605 [salt.state       :1951][INFO    ][6976] Completed state [bind9] at time 03:46:25.605394 duration_in_ms=46.467
2019-05-15 03:46:25,606 [salt.state       :1780][INFO    ][6976] Running state [apache2] at time 03:46:25.606371
2019-05-15 03:46:25,606 [salt.state       :1813][INFO    ][6976] Executing state service.running for [apache2]
2019-05-15 03:46:25,607 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-15 03:46:25,622 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-15 03:46:25,637 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-15 03:46:25,655 [salt.state       :300 ][INFO    ][6976] The service apache2 is already running
2019-05-15 03:46:25,656 [salt.state       :1951][INFO    ][6976] Completed state [apache2] at time 03:46:25.656179 duration_in_ms=49.808
2019-05-15 03:46:25,657 [salt.state       :1780][INFO    ][6976] Running state [maasng.wait_for_http_code] at time 03:46:25.657052
2019-05-15 03:46:25,657 [salt.state       :1813][INFO    ][6976] Executing state module.run for [maasng.wait_for_http_code]
2019-05-15 03:46:25,657 [salt.utils.decorators:613 ][WARNING ][6976] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:46:25,663 [salt.state       :300 ][INFO    ][6976] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-15 03:46:25,664 [salt.state       :1951][INFO    ][6976] Completed state [maasng.wait_for_http_code] at time 03:46:25.664030 duration_in_ms=6.976
2019-05-15 03:46:25,665 [salt.state       :1780][INFO    ][6976] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:46:25.665145
2019-05-15 03:46:25,665 [salt.state       :1813][INFO    ][6976] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-15 03:46:25,666 [salt.state       :300 ][INFO    ][6976] /var/lib/maas/.setup_admin exists
2019-05-15 03:46:25,666 [salt.state       :1951][INFO    ][6976] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:46:25.666537 duration_in_ms=1.392
2019-05-15 03:46:25,667 [salt.state       :1780][INFO    ][6976] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:46:25.667482
2019-05-15 03:46:25,667 [salt.state       :1813][INFO    ][6976] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:46:25,668 [salt.loaded.int.module.cmdmod:395 ][INFO    ][6976] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:46:27,114 [salt.state       :300 ][INFO    ][6976] {'pid': 7028, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:46:27,115 [salt.state       :1951][INFO    ][6976] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:46:27.115385 duration_in_ms=1447.904
2019-05-15 03:46:27,121 [salt.state       :1780][INFO    ][6976] Running state [maas_region_boot_source_resources_mirror] at time 03:46:27.121724
2019-05-15 03:46:27,122 [salt.state       :1813][INFO    ][6976] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-15 03:46:27,217 [salt.state       :300 ][INFO    ][6976] {'changes': {}}
2019-05-15 03:46:27,217 [salt.state       :1951][INFO    ][6976] Completed state [maas_region_boot_source_resources_mirror] at time 03:46:27.217448 duration_in_ms=95.722
2019-05-15 03:46:27,218 [salt.state       :1780][INFO    ][6976] Running state [maasng.boot_resources_import] at time 03:46:27.218446
2019-05-15 03:46:27,218 [salt.state       :1813][INFO    ][6976] Executing state module.run for [maasng.boot_resources_import]
2019-05-15 03:46:27,219 [salt.utils.decorators:613 ][WARNING ][6976] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:46:27,331 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-15 03:46:32,389 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-15 03:46:36,516 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034636503644
2019-05-15 03:46:36,540 [salt.minion      :1432][INFO    ][7068] Starting a new job with PID 7068
2019-05-15 03:46:36,564 [salt.minion      :1711][INFO    ][7068] Returning information for job: 20190515034636503644
2019-05-15 03:46:37,448 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-15 03:46:42,508 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:885.0/900s
2019-05-15 03:46:47,634 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:880.0/900s
2019-05-15 03:46:52,703 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:875.0/900s
2019-05-15 03:46:57,765 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:870.0/900s
2019-05-15 03:47:02,824 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:864.0/900s
2019-05-15 03:47:06,576 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034706563738
2019-05-15 03:47:06,601 [salt.minion      :1432][INFO    ][7133] Starting a new job with PID 7133
2019-05-15 03:47:06,623 [salt.minion      :1711][INFO    ][7133] Returning information for job: 20190515034706563738
2019-05-15 03:47:07,886 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:859.0/900s
2019-05-15 03:47:12,946 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:854.0/900s
2019-05-15 03:47:18,008 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:849.0/900s
2019-05-15 03:47:23,065 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:844.0/900s
2019-05-15 03:47:28,120 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:839.0/900s
2019-05-15 03:47:33,216 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:834.0/900s
2019-05-15 03:47:36,636 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034736623892
2019-05-15 03:47:36,661 [salt.minion      :1432][INFO    ][7191] Starting a new job with PID 7191
2019-05-15 03:47:36,685 [salt.minion      :1711][INFO    ][7191] Returning information for job: 20190515034736623892
2019-05-15 03:47:38,285 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:829.0/900s
2019-05-15 03:47:43,351 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:824.0/900s
2019-05-15 03:47:48,413 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:819.0/900s
2019-05-15 03:47:53,475 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:814.0/900s
2019-05-15 03:47:58,536 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:809.0/900s
2019-05-15 03:48:03,595 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:804.0/900s
2019-05-15 03:48:06,694 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034806682258
2019-05-15 03:48:06,716 [salt.minion      :1432][INFO    ][7257] Starting a new job with PID 7257
2019-05-15 03:48:06,740 [salt.minion      :1711][INFO    ][7257] Returning information for job: 20190515034806682258
2019-05-15 03:48:08,656 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:799.0/900s
2019-05-15 03:48:13,710 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:794.0/900s
2019-05-15 03:48:18,770 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:789.0/900s
2019-05-15 03:48:23,839 [salt.loaded.ext.module.maasng:1600][INFO    ][6976] Waiting boot-resources import done
sleep for:5s Left:783.0/900s
2019-05-15 03:48:29,163 [salt.state       :300 ][INFO    ][6976] {'ret': True}
2019-05-15 03:48:29,164 [salt.state       :1951][INFO    ][6976] Completed state [maasng.boot_resources_import] at time 03:48:29.164047 duration_in_ms=121945.601
2019-05-15 03:48:29,164 [salt.state       :1780][INFO    ][6976] Running state [maas_region_boot_sources_selection_xenial] at time 03:48:29.164683
2019-05-15 03:48:29,164 [salt.state       :1813][INFO    ][6976] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-15 03:48:30,015 [salt.state       :300 ][INFO    ][6976] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-15 03:48:30,015 [salt.state       :1951][INFO    ][6976] Completed state [maas_region_boot_sources_selection_xenial] at time 03:48:30.015565 duration_in_ms=850.88
2019-05-15 03:48:30,016 [salt.state       :1780][INFO    ][6976] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 03:48:30.016853
2019-05-15 03:48:30,017 [salt.state       :1813][INFO    ][6976] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-15 03:48:30,018 [salt.utils.decorators:613 ][WARNING ][6976] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:48:30,018 [salt.loaded.ext.module.maasng:1771][INFO    ][6976] boot-sources sync initiated for ALL Rack's
2019-05-15 03:48:31,231 [salt.state       :300 ][INFO    ][6976] {'ret': True}
2019-05-15 03:48:31,232 [salt.state       :1951][INFO    ][6976] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 03:48:31.232086 duration_in_ms=1215.232
2019-05-15 03:48:31,234 [salt.state       :1780][INFO    ][6976] Running state [maas.process_maas_config] at time 03:48:31.234162
2019-05-15 03:48:31,234 [salt.state       :1813][INFO    ][6976] Executing state module.run for [maas.process_maas_config]
2019-05-15 03:48:31,235 [salt.utils.decorators:613 ][WARNING ][6976] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:48:31,236 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=enable_http_proxy value=True
2019-05-15 03:48:31,343 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=upstream_dns value=8.8.8.8
2019-05-15 03:48:31,466 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=commissioning_distro_series value=xenial
2019-05-15 03:48:31,580 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=default_osystem value=ubuntu
2019-05-15 03:48:31,701 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=active_discovery_interval value=600
2019-05-15 03:48:31,797 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=dnssec_validation value=no
2019-05-15 03:48:31,920 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=maas_name value=mas01
2019-05-15 03:48:34,432 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=network_discovery value=enabled
2019-05-15 03:48:34,520 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=enable_third_party_drivers value=True
2019-05-15 03:48:34,568 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=default_storage_layout value=lvm
2019-05-15 03:48:34,635 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=ntp_external_only value=True
2019-05-15 03:48:34,701 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-15 03:48:34,754 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=default_distro_series value=xenial
2019-05-15 03:48:34,801 [salt.loaded.ext.module.maas:92  ][INFO    ][6976] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-05-15 03:48:34,892 [salt.state       :300 ][INFO    ][6976] {'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-15 03:48:34,892 [salt.state       :1951][INFO    ][6976] Completed state [maas.process_maas_config] at time 03:48:34.892569 duration_in_ms=3658.407
2019-05-15 03:48:34,893 [salt.state       :1780][INFO    ][6976] Running state [pxe_admin] at time 03:48:34.893509
2019-05-15 03:48:34,894 [salt.state       :1813][INFO    ][6976] Executing state maasng.fabric_present for [pxe_admin]
2019-05-15 03:48:34,957 [salt.loaded.ext.module.maasng:945 ][INFO    ][6976] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-15 03:48:35,035 [salt.loaded.ext.module.maasng:1008][WARNING ][6976] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-15 03:48:35,035 [salt.loaded.ext.module.maasng:1011][WARNING ][6976] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-15 03:48:35,082 [salt.state       :300 ][INFO    ][6976] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-15 03:48:35,083 [salt.state       :1951][INFO    ][6976] Completed state [pxe_admin] at time 03:48:35.083256 duration_in_ms=189.746
2019-05-15 03:48:35,083 [salt.state       :1780][INFO    ][6976] Running state [vlan 0] at time 03:48:35.083689
2019-05-15 03:48:35,084 [salt.state       :1813][INFO    ][6976] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-15 03:48:35,136 [salt.loaded.ext.module.maasng:945 ][INFO    ][6976] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'name': u'untagged', 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-15 03:48:35,262 [salt.loaded.ext.module.maasng:945 ][INFO    ][6976] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'name': u'untagged', 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-15 03:48:35,527 [salt.loaded.ext.module.maasng:945 ][INFO    ][6976] [{u'id': 0, u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'name': u'untagged', 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-15 03:48:35,624 [salt.state       :300 ][INFO    ][6976] {'new': 'Vlan untagged was updated'}
2019-05-15 03:48:35,625 [salt.state       :1951][INFO    ][6976] Completed state [vlan 0] at time 03:48:35.624944 duration_in_ms=541.254
2019-05-15 03:48:35,626 [salt.state       :1780][INFO    ][6976] Running state [192.168.11.0/24] at time 03:48:35.626451
2019-05-15 03:48:35,626 [salt.state       :1813][INFO    ][6976] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-15 03:48:35,838 [salt.loaded.ext.module.maasng:945 ][INFO    ][6976] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'name': u'fabric-0', u'class_type': None}, {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'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'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'name': u'fabric-1', u'class_type': None}, {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'a4cctt', 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'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-05-15 03:48:35,839 [salt.loaded.ext.module.maasng:1235][WARNING ][6976] Ignoring parameter vlan:0
2019-05-15 03:48:35,910 [salt.state       :300 ][INFO    ][6976] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-15 03:48:35,911 [salt.state       :1951][INFO    ][6976] Completed state [192.168.11.0/24] at time 03:48:35.911265 duration_in_ms=284.815
2019-05-15 03:48:35,912 [salt.state       :1780][INFO    ][6976] Running state [maas_create_iprange_1] at time 03:48:35.912210
2019-05-15 03:48:35,912 [salt.state       :1813][INFO    ][6976] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-15 03:48:35,957 [salt.state       :300 ][INFO    ][6976] Iprange maas_create_iprange_1 already exist.
2019-05-15 03:48:35,957 [salt.state       :1951][INFO    ][6976] Completed state [maas_create_iprange_1] at time 03:48:35.957877 duration_in_ms=45.666
2019-05-15 03:48:35,958 [salt.state       :1780][INFO    ][6976] Running state [vlan 0] at time 03:48:35.958259
2019-05-15 03:48:35,958 [salt.state       :1813][INFO    ][6976] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-15 03:48:36,011 [salt.loaded.ext.module.maasng:945 ][INFO    ][6976] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', 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-15 03:48:36,095 [salt.loaded.ext.module.maasng:945 ][INFO    ][6976] [{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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'mtu': 1500, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', 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-15 03:48:36,305 [salt.loaded.ext.module.maasng:945 ][INFO    ][6976] [{u'id': 0, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'id': 1, u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'id': 2, u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'a4cctt', u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-15 03:48:36,377 [salt.state       :300 ][INFO    ][6976] {'new': 'Vlan untagged was updated'}
2019-05-15 03:48:36,378 [salt.state       :1951][INFO    ][6976] Completed state [vlan 0] at time 03:48:36.377928 duration_in_ms=419.668
2019-05-15 03:48:36,378 [salt.state       :1780][INFO    ][6976] Running state [opnfv] at time 03:48:36.378370
2019-05-15 03:48:36,378 [salt.state       :1813][INFO    ][6976] Executing state maasng.sshkey_present for [opnfv]
2019-05-15 03:48:36,413 [salt.loaded.ext.module.maasng:1903][INFO    ][6976] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-05-15 03:48:36,413 [salt.state       :300 ][INFO    ][6976] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-15 03:48:36,413 [salt.state       :1951][INFO    ][6976] Completed state [opnfv] at time 03:48:36.413743 duration_in_ms=35.372
2019-05-15 03:48:36,415 [salt.minion      :1711][INFO    ][6976] Returning information for job: 20190515034621456478
2019-05-15 03:48:36,841 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515034836829220
2019-05-15 03:48:36,858 [salt.minion      :1432][INFO    ][7418] Starting a new job with PID 7418
2019-05-15 03:48:40,327 [salt.state       :915 ][INFO    ][7418] Loading fresh modules for state activity
2019-05-15 03:48:40,418 [salt.state       :1780][INFO    ][7418] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:48:40.418640
2019-05-15 03:48:40,419 [salt.state       :1813][INFO    ][7418] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:48:40,421 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7418] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:48:41,872 [salt.state       :300 ][INFO    ][7418] {'pid': 7476, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:48:41,873 [salt.state       :1951][INFO    ][7418] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:48:41.873473 duration_in_ms=1454.833
2019-05-15 03:48:41,875 [salt.state       :1780][INFO    ][7418] Running state [maas.process_machines] at time 03:48:41.875593
2019-05-15 03:48:41,876 [salt.state       :1813][INFO    ][7418] Executing state module.run for [maas.process_machines]
2019-05-15 03:48:41,876 [salt.utils.decorators:613 ][WARNING ][7418] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:48:42,298 [salt.loaded.ext.module.maas:412 ][WARNING ][7418] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:48:42,299 [salt.loaded.ext.module.maas:92  ][INFO    ][7418] 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=snwk4f architecture=amd64/generic power_parameters_power_user=admin
2019-05-15 03:48:43,253 [salt.loaded.ext.module.maas:412 ][WARNING ][7418] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:48:43,254 [salt.loaded.ext.module.maas:92  ][INFO    ][7418] 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=pmbx4m architecture=amd64/generic power_parameters_power_user=admin
2019-05-15 03:48:44,505 [salt.loaded.ext.module.maas:412 ][WARNING ][7418] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:48:44,506 [salt.loaded.ext.module.maas:92  ][INFO    ][7418] 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=a3ydws architecture=amd64/generic power_parameters_power_user=admin
2019-05-15 03:48:45,834 [salt.loaded.ext.module.maas:412 ][WARNING ][7418] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:48:45,835 [salt.loaded.ext.module.maas:92  ][INFO    ][7418] 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=k6syp7 architecture=amd64/generic power_parameters_power_user=admin
2019-05-15 03:48:47,020 [salt.loaded.ext.module.maas:412 ][WARNING ][7418] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-15 03:48:47,020 [salt.loaded.ext.module.maas:92  ][INFO    ][7418] 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=mqgsn8 architecture=amd64/generic power_parameters_power_user=admin
2019-05-15 03:48:48,266 [salt.state       :300 ][INFO    ][7418] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-15 03:48:48,267 [salt.state       :1951][INFO    ][7418] Completed state [maas.process_machines] at time 03:48:48.267525 duration_in_ms=6391.93
2019-05-15 03:48:48,271 [salt.minion      :1711][INFO    ][7418] Returning information for job: 20190515034836829220
2019-05-15 03:49:20,784 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515034920772480
2019-05-15 03:49:20,803 [salt.minion      :1432][INFO    ][7857] Starting a new job with PID 7857
2019-05-15 03:49:24,454 [salt.state       :915 ][INFO    ][7857] Loading fresh modules for state activity
2019-05-15 03:49:24,503 [salt.state       :1780][INFO    ][7857] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:49:24.503380
2019-05-15 03:49:24,503 [salt.state       :1813][INFO    ][7857] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:49:24,504 [salt.loaded.int.module.cmdmod:395 ][INFO    ][7857] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:49:25,881 [salt.state       :300 ][INFO    ][7857] {'pid': 7865, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:49:25,881 [salt.state       :1951][INFO    ][7857] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:49:25.881573 duration_in_ms=1378.193
2019-05-15 03:49:25,882 [salt.state       :1780][INFO    ][7857] Running state [maas.wait_for_machine_status] at time 03:49:25.882725
2019-05-15 03:49:25,882 [salt.state       :1813][INFO    ][7857] Executing state module.run for [maas.wait_for_machine_status]
2019-05-15 03:49:25,883 [salt.utils.decorators:613 ][WARNING ][7857] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:49:27,907 [salt.loaded.ext.module.maas:993 ][INFO    ][7857] Machine a3ydws mark broken
2019-05-15 03:49:28,549 [salt.loaded.ext.module.maas:996 ][INFO    ][7857] Machine a3ydws mark fixed
2019-05-15 03:49:29,669 [salt.loaded.ext.module.maas:684 ][INFO    ][7857] deploymachines hwe_kernel=ga-16.04 system_id=a3ydws distro_series=xenial
2019-05-15 03:49:33,651 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1492.23859787s left)
2019-05-15 03:49:35,903 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515034935850627
2019-05-15 03:49:35,926 [salt.minion      :1432][INFO    ][7948] Starting a new job with PID 7948
2019-05-15 03:49:35,952 [salt.minion      :1711][INFO    ][7948] Returning information for job: 20190515034935850627
2019-05-15 03:50:05,951 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035005938024
2019-05-15 03:50:05,973 [salt.minion      :1432][INFO    ][7997] Starting a new job with PID 7997
2019-05-15 03:50:05,995 [salt.minion      :1711][INFO    ][7997] Returning information for job: 20190515035005938024
2019-05-15 03:50:06,906 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1458.98351192s left)
2019-05-15 03:50:36,002 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035035989633
2019-05-15 03:50:36,026 [salt.minion      :1432][INFO    ][8022] Starting a new job with PID 8022
2019-05-15 03:50:36,050 [salt.minion      :1711][INFO    ][8022] Returning information for job: 20190515035035989633
2019-05-15 03:50:40,141 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1425.74863195s left)
2019-05-15 03:51:06,050 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035106037722
2019-05-15 03:51:06,074 [salt.minion      :1432][INFO    ][8071] Starting a new job with PID 8071
2019-05-15 03:51:06,101 [salt.minion      :1711][INFO    ][8071] Returning information for job: 20190515035106037722
2019-05-15 03:51:13,505 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1392.38437891s left)
2019-05-15 03:51:36,094 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035136081853
2019-05-15 03:51:36,118 [salt.minion      :1432][INFO    ][8160] Starting a new job with PID 8160
2019-05-15 03:51:36,142 [salt.minion      :1711][INFO    ][8160] Returning information for job: 20190515035136081853
2019-05-15 03:51:47,262 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1358.62769699s left)
2019-05-15 03:52:06,148 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035206135165
2019-05-15 03:52:06,171 [salt.minion      :1432][INFO    ][8290] Starting a new job with PID 8290
2019-05-15 03:52:06,196 [salt.minion      :1711][INFO    ][8290] Returning information for job: 20190515035206135165
2019-05-15 03:52:20,575 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1325.314852s left)
2019-05-15 03:52:36,209 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035236193024
2019-05-15 03:52:36,232 [salt.minion      :1432][INFO    ][8323] Starting a new job with PID 8323
2019-05-15 03:52:36,257 [salt.minion      :1711][INFO    ][8323] Returning information for job: 20190515035236193024
2019-05-15 03:52:54,109 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1291.7804389s left)
2019-05-15 03:53:06,274 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035306261902
2019-05-15 03:53:06,298 [salt.minion      :1432][INFO    ][8461] Starting a new job with PID 8461
2019-05-15 03:53:06,324 [salt.minion      :1711][INFO    ][8461] Returning information for job: 20190515035306261902
2019-05-15 03:53:27,560 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1258.3300209s left)
2019-05-15 03:53:36,339 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035336326542
2019-05-15 03:53:36,360 [salt.minion      :1432][INFO    ][8491] Starting a new job with PID 8491
2019-05-15 03:53:36,383 [salt.minion      :1711][INFO    ][8491] Returning information for job: 20190515035336326542
2019-05-15 03:54:00,768 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1225.12185884s left)
2019-05-15 03:54:06,406 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035406393234
2019-05-15 03:54:06,429 [salt.minion      :1432][INFO    ][8543] Starting a new job with PID 8543
2019-05-15 03:54:06,454 [salt.minion      :1711][INFO    ][8543] Returning information for job: 20190515035406393234
2019-05-15 03:54:34,731 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1191.15904784s left)
2019-05-15 03:54:36,481 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035436465844
2019-05-15 03:54:36,509 [salt.minion      :1432][INFO    ][8573] Starting a new job with PID 8573
2019-05-15 03:54:36,539 [salt.minion      :1711][INFO    ][8573] Returning information for job: 20190515035436465844
2019-05-15 03:55:06,568 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035506556176
2019-05-15 03:55:06,592 [salt.minion      :1432][INFO    ][8701] Starting a new job with PID 8701
2019-05-15 03:55:06,620 [salt.minion      :1711][INFO    ][8701] Returning information for job: 20190515035506556176
2019-05-15 03:55:08,326 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1157.56328297s left)
2019-05-15 03:55:36,658 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035536645185
2019-05-15 03:55:36,681 [salt.minion      :1432][INFO    ][8730] Starting a new job with PID 8730
2019-05-15 03:55:36,710 [salt.minion      :1711][INFO    ][8730] Returning information for job: 20190515035536645185
2019-05-15 03:55:41,475 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1124.41448402s left)
2019-05-15 03:56:06,752 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035606739753
2019-05-15 03:56:06,777 [salt.minion      :1432][INFO    ][8825] Starting a new job with PID 8825
2019-05-15 03:56:06,803 [salt.minion      :1711][INFO    ][8825] Returning information for job: 20190515035606739753
2019-05-15 03:56:14,836 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1091.05381989s left)
2019-05-15 03:56:36,850 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035636836644
2019-05-15 03:56:36,874 [salt.minion      :1432][INFO    ][8859] Starting a new job with PID 8859
2019-05-15 03:56:36,903 [salt.minion      :1711][INFO    ][8859] Returning information for job: 20190515035636836644
2019-05-15 03:56:48,318 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1057.57117581s left)
2019-05-15 03:57:06,958 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035706945604
2019-05-15 03:57:06,981 [salt.minion      :1432][INFO    ][8973] Starting a new job with PID 8973
2019-05-15 03:57:07,010 [salt.minion      :1711][INFO    ][8973] Returning information for job: 20190515035706945604
2019-05-15 03:57:21,793 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1024.09690881s left)
2019-05-15 03:57:37,074 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035737060649
2019-05-15 03:57:37,098 [salt.minion      :1432][INFO    ][9003] Starting a new job with PID 9003
2019-05-15 03:57:37,126 [salt.minion      :1711][INFO    ][9003] Returning information for job: 20190515035737060649
2019-05-15 03:57:55,208 [salt.loaded.ext.module.maas:1023][INFO    ][7857] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (990.681843996s left)
2019-05-15 03:58:07,193 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command saltutil.find_job with jid 20190515035807180297
2019-05-15 03:58:07,217 [salt.minion      :1432][INFO    ][9089] Starting a new job with PID 9089
2019-05-15 03:58:07,252 [salt.minion      :1711][INFO    ][9089] Returning information for job: 20190515035807180297
2019-05-15 03:58:28,925 [salt.state       :300 ][INFO    ][7857] {'ret': True}
2019-05-15 03:58:28,925 [salt.state       :1951][INFO    ][7857] Completed state [maas.wait_for_machine_status] at time 03:58:28.925578 duration_in_ms=543042.85
2019-05-15 03:58:28,929 [salt.minion      :1711][INFO    ][7857] Returning information for job: 20190515034920772480
2019-05-15 03:58:29,573 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515035829563701
2019-05-15 03:58:29,596 [salt.minion      :1432][INFO    ][9119] Starting a new job with PID 9119
2019-05-15 03:58:33,303 [salt.state       :915 ][INFO    ][9119] Loading fresh modules for state activity
2019-05-15 03:58:33,450 [salt.state       :1780][INFO    ][9119] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:58:33.450390
2019-05-15 03:58:33,450 [salt.state       :1813][INFO    ][9119] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:58:33,452 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9119] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:58:34,939 [salt.state       :300 ][INFO    ][9119] {'pid': 9147, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:58:34,940 [salt.state       :1951][INFO    ][9119] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:58:34.939932 duration_in_ms=1489.542
2019-05-15 03:58:34,941 [salt.state       :1780][INFO    ][9119] Running state [maas_machines_storage_cmp002_lvm] at time 03:58:34.941247
2019-05-15 03:58:34,941 [salt.state       :1813][INFO    ][9119] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-15 03:58:35,605 [salt.state       :300 ][INFO    ][9119] Machine cmp002 is not in Ready state.
2019-05-15 03:58:35,606 [salt.state       :1951][INFO    ][9119] Completed state [maas_machines_storage_cmp002_lvm] at time 03:58:35.606020 duration_in_ms=664.771
2019-05-15 03:58:35,606 [salt.state       :1780][INFO    ][9119] Running state [maas_machines_storage_cmp001_lvm] at time 03:58:35.606633
2019-05-15 03:58:35,607 [salt.state       :1813][INFO    ][9119] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-15 03:58:36,202 [salt.state       :300 ][INFO    ][9119] Machine cmp001 is not in Ready state.
2019-05-15 03:58:36,203 [salt.state       :1951][INFO    ][9119] Completed state [maas_machines_storage_cmp001_lvm] at time 03:58:36.203025 duration_in_ms=596.391
2019-05-15 03:58:36,207 [salt.minion      :1711][INFO    ][9119] Returning information for job: 20190515035829563701
2019-05-15 03:58:36,843 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515035836830098
2019-05-15 03:58:36,866 [salt.minion      :1432][INFO    ][9159] Starting a new job with PID 9159
2019-05-15 03:58:37,637 [salt.state       :915 ][INFO    ][9159] Loading fresh modules for state activity
2019-05-15 03:58:37,727 [salt.state       :1780][INFO    ][9159] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:58:37.727568
2019-05-15 03:58:37,728 [salt.state       :1813][INFO    ][9159] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:58:37,730 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9159] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:58:39,198 [salt.state       :300 ][INFO    ][9159] {'pid': 9166, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:58:39,199 [salt.state       :1951][INFO    ][9159] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:58:39.199153 duration_in_ms=1471.586
2019-05-15 03:58:39,200 [salt.state       :1780][INFO    ][9159] Running state [maas.deploy_machines] at time 03:58:39.200336
2019-05-15 03:58:39,200 [salt.state       :1813][INFO    ][9159] Executing state module.run for [maas.deploy_machines]
2019-05-15 03:58:39,201 [salt.utils.decorators:613 ][WARNING ][9159] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:58:39,642 [salt.state       :300 ][INFO    ][9159] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-15 03:58:39,642 [salt.state       :1951][INFO    ][9159] Completed state [maas.deploy_machines] at time 03:58:39.642459 duration_in_ms=442.122
2019-05-15 03:58:39,644 [salt.minion      :1711][INFO    ][9159] Returning information for job: 20190515035836830098
2019-05-15 03:58:40,234 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command state.apply with jid 20190515035840220519
2019-05-15 03:58:40,251 [salt.minion      :1432][INFO    ][9320] Starting a new job with PID 9320
2019-05-15 03:58:40,943 [salt.state       :915 ][INFO    ][9320] Loading fresh modules for state activity
2019-05-15 03:58:41,035 [salt.state       :1780][INFO    ][9320] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:58:41.035412
2019-05-15 03:58:41,035 [salt.state       :1813][INFO    ][9320] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-15 03:58:41,038 [salt.loaded.int.module.cmdmod:395 ][INFO    ][9320] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-15 03:58:42,421 [salt.state       :300 ][INFO    ][9320] {'pid': 9334, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-15 03:58:42,421 [salt.state       :1951][INFO    ][9320] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:58:42.421869 duration_in_ms=1386.457
2019-05-15 03:58:42,423 [salt.state       :1780][INFO    ][9320] Running state [maas.wait_for_machine_status] at time 03:58:42.423382
2019-05-15 03:58:42,423 [salt.state       :1813][INFO    ][9320] Executing state module.run for [maas.wait_for_machine_status]
2019-05-15 03:58:42,423 [salt.utils.decorators:613 ][WARNING ][9320] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-15 03:58:45,804 [salt.state       :300 ][INFO    ][9320] {'ret': True}
2019-05-15 03:58:45,805 [salt.state       :1951][INFO    ][9320] Completed state [maas.wait_for_machine_status] at time 03:58:45.804911 duration_in_ms=3381.527
2019-05-15 03:58:45,808 [salt.minion      :1711][INFO    ][9320] Returning information for job: 20190515035840220519
2019-05-15 04:25:09,835 [salt.utils.schedule:1377][INFO    ][32389] Running scheduled job: __mine_interval
2019-05-15 05:25:09,836 [salt.utils.schedule:1377][INFO    ][32389] Running scheduled job: __mine_interval
2019-05-15 05:39:57,201 [salt.minion      :1308][INFO    ][32389] User sudo_ubuntu Executing command cp.push_dir with jid 20190515053957188213
2019-05-15 05:39:57,223 [salt.minion      :1432][INFO    ][16466] Starting a new job with PID 16466
