2019-05-10 02:13:58,385 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-10 02:14:48,430 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-10 02:15:38,472 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-10 02:16:28,521 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-10 02:17:18,572 [salt.minion      :870 ][ERROR   ][363] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-05-10 02:19:29,123 [salt.utils.decorators:613 ][WARNING ][2699] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 02:19:29,539 [salt.utils.decorators:613 ][WARNING ][2699] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 02:19:31,649 [salt.loaded.int.states.file:2298][WARNING ][2835] 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-10 02:19:37,154 [salt.state       :2022][WARNING ][2948] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-10 02:19:39,791 [salt.utils.decorators:613 ][WARNING ][2948] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 02:34:44,997 [salt.utils.decorators:613 ][WARNING ][2948] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:04:12,706 [salt.utils.decorators:613 ][WARNING ][2948] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:19:13,323 [salt.utils.decorators:613 ][WARNING ][2948] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:19:16,920 [salt.loaded.ext.module.maasng:1008][WARNING ][2948] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-05-10 03:19:16,920 [salt.loaded.ext.module.maasng:1011][WARNING ][2948] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-05-10 03:19:17,639 [salt.loaded.ext.module.maasng:1235][WARNING ][2948] Ignoring parameter vlan:0
2019-05-10 03:19:20,836 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13719] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-10 03:19:20,867 [salt.loaded.int.module.cmdmod:395 ][INFO    ][13719] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-05-10 03:19:20,888 [salt.utils.parsers:1051][WARNING ][363] Minion received a SIGTERM. Exiting.
2019-05-10 03:19:21,876 [salt.cli.daemons :293 ][INFO    ][13778] Setting up the Salt Minion "mas01.mcp-ovs-ha.local"
2019-05-10 03:19:21,955 [salt.cli.daemons :82  ][INFO    ][13778] Starting up the Salt Minion
2019-05-10 03:19:21,955 [salt.utils.event :1017][INFO    ][13778] Starting pull socket on /var/run/salt/minion/minion_event_501f9ec045_pull.ipc
2019-05-10 03:19:22,823 [salt.minion      :976 ][INFO    ][13778] Creating minion process manager
2019-05-10 03:19:24,141 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][13778] Executing command ['date', '+%z'] in directory '/root'
2019-05-10 03:19:24,160 [salt.utils.schedule:568 ][INFO    ][13778] Updating job settings for scheduled job: __mine_interval
2019-05-10 03:19:24,162 [salt.minion      :1108][INFO    ][13778] Added mine.update to scheduler
2019-05-10 03:19:24,165 [salt.minion      :1975][INFO    ][13778] Minion is starting as user 'root'
2019-05-10 03:19:24,173 [salt.utils.decorators:613 ][WARNING ][13715] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:19:24,178 [salt.minion      :2336][INFO    ][13778] Minion is ready to receive requests!
2019-05-10 03:19:24,224 [salt.loaded.ext.module.maas:412 ][WARNING ][13715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:19:29,202 [salt.loaded.ext.module.maas:412 ][WARNING ][13715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:19:33,764 [salt.loaded.ext.module.maas:412 ][WARNING ][13715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:19:34,264 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510031934252411
2019-05-10 03:19:34,286 [salt.minion      :1432][INFO    ][14005] Starting a new job with PID 14005
2019-05-10 03:19:34,301 [salt.minion      :1711][INFO    ][14005] Returning information for job: 20190510031934252411
2019-05-10 03:19:36,653 [salt.loaded.ext.module.maas:412 ][WARNING ][13715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:19:42,258 [salt.loaded.ext.module.maas:412 ][WARNING ][13715] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:20:16,611 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command state.apply with jid 20190510032016598015
2019-05-10 03:20:16,630 [salt.minion      :1432][INFO    ][14294] Starting a new job with PID 14294
2019-05-10 03:20:21,202 [salt.state       :915 ][INFO    ][14294] Loading fresh modules for state activity
2019-05-10 03:20:21,251 [salt.fileclient  :1219][INFO    ][14294] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-05-10 03:20:21,289 [salt.state       :1780][INFO    ][14294] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:21.288944
2019-05-10 03:20:21,289 [salt.state       :1813][INFO    ][14294] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-10 03:20:21,291 [salt.loaded.int.module.cmdmod:395 ][INFO    ][14294] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-10 03:20:22,509 [salt.state       :300 ][INFO    ][14294] {'pid': 14304, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-10 03:20:22,510 [salt.state       :1951][INFO    ][14294] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:22.510305 duration_in_ms=1221.362
2019-05-10 03:20:22,511 [salt.state       :1780][INFO    ][14294] Running state [maas.wait_for_machine_status] at time 03:20:22.511710
2019-05-10 03:20:22,511 [salt.state       :1813][INFO    ][14294] Executing state module.run for [maas.wait_for_machine_status]
2019-05-10 03:20:22,512 [salt.utils.decorators:613 ][WARNING ][14294] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:20:31,715 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032031704854
2019-05-10 03:20:31,737 [salt.minion      :1432][INFO    ][14330] Starting a new job with PID 14330
2019-05-10 03:20:31,753 [salt.minion      :1711][INFO    ][14330] Returning information for job: 20190510032031704854
2019-05-10 03:21:01,772 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032101761657
2019-05-10 03:21:01,796 [salt.minion      :1432][INFO    ][14400] Starting a new job with PID 14400
2019-05-10 03:21:01,818 [salt.minion      :1711][INFO    ][14400] Returning information for job: 20190510032101761657
2019-05-10 03:21:31,831 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032131824235
2019-05-10 03:21:31,858 [salt.minion      :1432][INFO    ][14542] Starting a new job with PID 14542
2019-05-10 03:21:31,881 [salt.minion      :1711][INFO    ][14542] Returning information for job: 20190510032131824235
2019-05-10 03:22:01,897 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032201887667
2019-05-10 03:22:01,924 [salt.minion      :1432][INFO    ][14617] Starting a new job with PID 14617
2019-05-10 03:22:01,940 [salt.minion      :1711][INFO    ][14617] Returning information for job: 20190510032201887667
2019-05-10 03:22:31,966 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032231953042
2019-05-10 03:22:31,989 [salt.minion      :1432][INFO    ][14669] Starting a new job with PID 14669
2019-05-10 03:22:32,011 [salt.minion      :1711][INFO    ][14669] Returning information for job: 20190510032231953042
2019-05-10 03:23:02,070 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032302053247
2019-05-10 03:23:02,094 [salt.minion      :1432][INFO    ][14771] Starting a new job with PID 14771
2019-05-10 03:23:02,114 [salt.minion      :1711][INFO    ][14771] Returning information for job: 20190510032302053247
2019-05-10 03:23:32,153 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032332142414
2019-05-10 03:23:32,169 [salt.minion      :1432][INFO    ][14810] Starting a new job with PID 14810
2019-05-10 03:23:32,185 [salt.minion      :1711][INFO    ][14810] Returning information for job: 20190510032332142414
2019-05-10 03:24:02,228 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032402216610
2019-05-10 03:24:02,252 [salt.minion      :1432][INFO    ][14929] Starting a new job with PID 14929
2019-05-10 03:24:02,274 [salt.minion      :1711][INFO    ][14929] Returning information for job: 20190510032402216610
2019-05-10 03:24:32,327 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032432314995
2019-05-10 03:24:32,351 [salt.minion      :1432][INFO    ][14965] Starting a new job with PID 14965
2019-05-10 03:24:32,374 [salt.minion      :1711][INFO    ][14965] Returning information for job: 20190510032432314995
2019-05-10 03:25:02,404 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032502395116
2019-05-10 03:25:02,425 [salt.minion      :1432][INFO    ][15014] Starting a new job with PID 15014
2019-05-10 03:25:02,445 [salt.minion      :1711][INFO    ][15014] Returning information for job: 20190510032502395116
2019-05-10 03:25:32,488 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032532478050
2019-05-10 03:25:32,512 [salt.minion      :1432][INFO    ][15037] Starting a new job with PID 15037
2019-05-10 03:25:32,533 [salt.minion      :1711][INFO    ][15037] Returning information for job: 20190510032532478050
2019-05-10 03:26:02,579 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032602566904
2019-05-10 03:26:02,599 [salt.minion      :1432][INFO    ][15090] Starting a new job with PID 15090
2019-05-10 03:26:02,617 [salt.minion      :1711][INFO    ][15090] Returning information for job: 20190510032602566904
2019-05-10 03:26:07,337 [salt.state       :302 ][ERROR   ][14294] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-05-10 03:26:07,338 [salt.state       :1951][INFO    ][14294] Completed state [maas.wait_for_machine_status] at time 03:26:07.338361 duration_in_ms=344826.649
2019-05-10 03:26:07,342 [salt.minion      :1711][INFO    ][14294] Returning information for job: 20190510032016598015
2019-05-10 03:26:18,066 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command pillar.get with jid 20190510032618054005
2019-05-10 03:26:18,090 [salt.minion      :1432][INFO    ][15371] Starting a new job with PID 15371
2019-05-10 03:26:18,099 [salt.minion      :1711][INFO    ][15371] Returning information for job: 20190510032618054005
2019-05-10 03:26:18,598 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command service.status with jid 20190510032618585441
2019-05-10 03:26:18,618 [salt.minion      :1432][INFO    ][15379] Starting a new job with PID 15379
2019-05-10 03:26:18,951 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][15379] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-05-10 03:26:18,984 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][15379] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-05-10 03:26:19,000 [salt.minion      :1711][INFO    ][15379] Returning information for job: 20190510032618585441
2019-05-10 03:26:19,501 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command state.apply with jid 20190510032619489241
2019-05-10 03:26:19,523 [salt.minion      :1432][INFO    ][15391] Starting a new job with PID 15391
2019-05-10 03:26:23,399 [salt.state       :915 ][INFO    ][15391] Loading fresh modules for state activity
2019-05-10 03:26:23,816 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command 'salt-minion --version' in directory '/root'
2019-05-10 03:26:24,120 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command 'salt-minion --version' in directory '/root'
2019-05-10 03:26:24,971 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command 'salt-minion --version' in directory '/root'
2019-05-10 03:26:25,320 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command 'salt-minion --version' in directory '/root'
2019-05-10 03:26:26,668 [salt.state       :1780][INFO    ][15391] Running state [salt-minion] at time 03:26:26.668737
2019-05-10 03:26:26,669 [salt.state       :1813][INFO    ][15391] Executing state pkg.installed for [salt-minion]
2019-05-10 03:26:26,669 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-10 03:26:26,762 [salt.state       :300 ][INFO    ][15391] All specified packages are already installed
2019-05-10 03:26:26,762 [salt.state       :1951][INFO    ][15391] Completed state [salt-minion] at time 03:26:26.762609 duration_in_ms=93.871
2019-05-10 03:26:26,763 [salt.state       :1780][INFO    ][15391] Running state [salt_minion_dependency_packages] at time 03:26:26.763012
2019-05-10 03:26:26,763 [salt.state       :1813][INFO    ][15391] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-05-10 03:26:26,771 [salt.state       :300 ][INFO    ][15391] All specified packages are already installed
2019-05-10 03:26:26,772 [salt.state       :1951][INFO    ][15391] Completed state [salt_minion_dependency_packages] at time 03:26:26.772063 duration_in_ms=9.051
2019-05-10 03:26:26,775 [salt.state       :1780][INFO    ][15391] Running state [/etc/salt/minion.d/minion.conf] at time 03:26:26.775809
2019-05-10 03:26:26,776 [salt.state       :1813][INFO    ][15391] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-05-10 03:26:27,038 [salt.state       :300 ][INFO    ][15391] File /etc/salt/minion.d/minion.conf is in the correct state
2019-05-10 03:26:27,039 [salt.state       :1951][INFO    ][15391] Completed state [/etc/salt/minion.d/minion.conf] at time 03:26:27.038983 duration_in_ms=263.173
2019-05-10 03:26:27,039 [salt.state       :1780][INFO    ][15391] Running state [python-netaddr] at time 03:26:27.039405
2019-05-10 03:26:27,039 [salt.state       :1813][INFO    ][15391] Executing state pkg.installed for [python-netaddr]
2019-05-10 03:26:27,051 [salt.state       :300 ][INFO    ][15391] All specified packages are already installed
2019-05-10 03:26:27,051 [salt.state       :1951][INFO    ][15391] Completed state [python-netaddr] at time 03:26:27.051473 duration_in_ms=12.068
2019-05-10 03:26:27,056 [salt.state       :1780][INFO    ][15391] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:26:27.056131
2019-05-10 03:26:27,056 [salt.state       :1813][INFO    ][15391] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-05-10 03:26:27,069 [salt.state       :300 ][INFO    ][15391] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-05-10 03:26:27,070 [salt.state       :1951][INFO    ][15391] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:26:27.070244 duration_in_ms=14.113
2019-05-10 03:26:27,071 [salt.state       :1780][INFO    ][15391] Running state [salt-minion] at time 03:26:27.071698
2019-05-10 03:26:27,072 [salt.state       :1813][INFO    ][15391] Executing state service.running for [salt-minion]
2019-05-10 03:26:27,072 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-05-10 03:26:27,112 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-05-10 03:26:27,130 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-05-10 03:26:27,147 [salt.state       :300 ][INFO    ][15391] The service salt-minion is already running
2019-05-10 03:26:27,148 [salt.state       :1951][INFO    ][15391] Completed state [salt-minion] at time 03:26:27.148246 duration_in_ms=76.547
2019-05-10 03:26:27,150 [salt.state       :1780][INFO    ][15391] Running state [/etc/salt/grains.d] at time 03:26:27.150691
2019-05-10 03:26:27,151 [salt.state       :1813][INFO    ][15391] Executing state file.directory for [/etc/salt/grains.d]
2019-05-10 03:26:27,152 [salt.state       :300 ][INFO    ][15391] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-05-10 03:26:27,153 [salt.state       :1951][INFO    ][15391] Completed state [/etc/salt/grains.d] at time 03:26:27.152984 duration_in_ms=2.293
2019-05-10 03:26:27,154 [salt.state       :1780][INFO    ][15391] Running state [/etc/salt/grains] at time 03:26:27.154043
2019-05-10 03:26:27,154 [salt.state       :1813][INFO    ][15391] Executing state file.managed for [/etc/salt/grains]
2019-05-10 03:26:27,155 [salt.state       :300 ][INFO    ][15391] File /etc/salt/grains exists with proper permissions. No changes made.
2019-05-10 03:26:27,155 [salt.state       :1951][INFO    ][15391] Completed state [/etc/salt/grains] at time 03:26:27.155618 duration_in_ms=1.575
2019-05-10 03:26:27,156 [salt.state       :1780][INFO    ][15391] Running state [/etc/salt/grains.d/placeholder] at time 03:26:27.156295
2019-05-10 03:26:27,156 [salt.state       :1813][INFO    ][15391] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-05-10 03:26:27,157 [salt.state       :300 ][INFO    ][15391] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-05-10 03:26:27,157 [salt.state       :1951][INFO    ][15391] Completed state [/etc/salt/grains.d/placeholder] at time 03:26:27.157796 duration_in_ms=1.501
2019-05-10 03:26:27,158 [salt.state       :1780][INFO    ][15391] Running state [/etc/salt/grains.d/sphinx] at time 03:26:27.158473
2019-05-10 03:26:27,158 [salt.state       :1813][INFO    ][15391] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-05-10 03:26:27,169 [salt.state       :300 ][INFO    ][15391] File /etc/salt/grains.d/sphinx is in the correct state
2019-05-10 03:26:27,170 [salt.state       :1951][INFO    ][15391] Completed state [/etc/salt/grains.d/sphinx] at time 03:26:27.170202 duration_in_ms=11.729
2019-05-10 03:26:27,173 [salt.state       :1780][INFO    ][15391] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:26:27.173252
2019-05-10 03:26:27,173 [salt.state       :1813][INFO    ][15391] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-05-10 03:26:27,174 [salt.state       :300 ][INFO    ][15391] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-05-10 03:26:27,174 [salt.state       :1951][INFO    ][15391] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:26:27.174423 duration_in_ms=1.171
2019-05-10 03:26:27,175 [salt.state       :1780][INFO    ][15391] Running state [/etc/salt/grains.d/dns_records] at time 03:26:27.175099
2019-05-10 03:26:27,175 [salt.state       :1813][INFO    ][15391] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-05-10 03:26:27,187 [salt.state       :300 ][INFO    ][15391] File /etc/salt/grains.d/dns_records is in the correct state
2019-05-10 03:26:27,188 [salt.state       :1951][INFO    ][15391] Completed state [/etc/salt/grains.d/dns_records] at time 03:26:27.187992 duration_in_ms=12.893
2019-05-10 03:26:27,189 [salt.state       :1780][INFO    ][15391] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:26:27.189253
2019-05-10 03:26:27,189 [salt.state       :1813][INFO    ][15391] 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-10 03:26:27,190 [salt.state       :300 ][INFO    ][15391] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-05-10 03:26:27,190 [salt.state       :1951][INFO    ][15391] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:26:27.190408 duration_in_ms=1.155
2019-05-10 03:26:27,191 [salt.state       :1780][INFO    ][15391] Running state [/etc/salt/grains.d/salt] at time 03:26:27.191079
2019-05-10 03:26:27,191 [salt.state       :1813][INFO    ][15391] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-05-10 03:26:27,199 [salt.state       :300 ][INFO    ][15391] File /etc/salt/grains.d/salt is in the correct state
2019-05-10 03:26:27,200 [salt.state       :1951][INFO    ][15391] Completed state [/etc/salt/grains.d/salt] at time 03:26:27.200000 duration_in_ms=8.922
2019-05-10 03:26:27,201 [salt.state       :1780][INFO    ][15391] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:26:27.201167
2019-05-10 03:26:27,201 [salt.state       :1813][INFO    ][15391] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-05-10 03:26:27,202 [salt.state       :300 ][INFO    ][15391] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-05-10 03:26:27,202 [salt.state       :1951][INFO    ][15391] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:26:27.202285 duration_in_ms=1.118
2019-05-10 03:26:27,204 [salt.state       :1780][INFO    ][15391] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:26:27.204808
2019-05-10 03:26:27,205 [salt.state       :1813][INFO    ][15391] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-05-10 03:26:27,205 [salt.state       :300 ][INFO    ][15391] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-05-10 03:26:27,205 [salt.state       :1951][INFO    ][15391] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:26:27.205923 duration_in_ms=1.114
2019-05-10 03:26:27,206 [salt.state       :1780][INFO    ][15391] Running state [mine.update] at time 03:26:27.206816
2019-05-10 03:26:27,207 [salt.state       :1813][INFO    ][15391] Executing state module.wait for [mine.update]
2019-05-10 03:26:27,207 [salt.state       :300 ][INFO    ][15391] No changes made for mine.update
2019-05-10 03:26:27,207 [salt.state       :1951][INFO    ][15391] Completed state [mine.update] at time 03:26:27.207859 duration_in_ms=1.043
2019-05-10 03:26:27,208 [salt.state       :1780][INFO    ][15391] Running state [ca-certificates] at time 03:26:27.208176
2019-05-10 03:26:27,208 [salt.state       :1813][INFO    ][15391] Executing state pkg.installed for [ca-certificates]
2019-05-10 03:26:27,218 [salt.state       :300 ][INFO    ][15391] All specified packages are already installed
2019-05-10 03:26:27,218 [salt.state       :1951][INFO    ][15391] Completed state [ca-certificates] at time 03:26:27.218742 duration_in_ms=10.567
2019-05-10 03:26:27,219 [salt.state       :1780][INFO    ][15391] Running state [update-ca-certificates] at time 03:26:27.219636
2019-05-10 03:26:27,220 [salt.state       :1813][INFO    ][15391] Executing state cmd.wait for [update-ca-certificates]
2019-05-10 03:26:27,220 [salt.state       :300 ][INFO    ][15391] No changes made for update-ca-certificates
2019-05-10 03:26:27,220 [salt.state       :1951][INFO    ][15391] Completed state [update-ca-certificates] at time 03:26:27.220657 duration_in_ms=1.021
2019-05-10 03:26:27,221 [salt.state       :1780][INFO    ][15391] Running state [iptables] at time 03:26:27.220960
2019-05-10 03:26:27,221 [salt.state       :1813][INFO    ][15391] Executing state pkg.installed for [iptables]
2019-05-10 03:26:27,230 [salt.state       :300 ][INFO    ][15391] All specified packages are already installed
2019-05-10 03:26:27,230 [salt.state       :1951][INFO    ][15391] Completed state [iptables] at time 03:26:27.230345 duration_in_ms=9.385
2019-05-10 03:26:27,230 [salt.state       :1780][INFO    ][15391] Running state [iptables-persistent] at time 03:26:27.230669
2019-05-10 03:26:27,230 [salt.state       :1813][INFO    ][15391] Executing state pkg.installed for [iptables-persistent]
2019-05-10 03:26:27,239 [salt.state       :300 ][INFO    ][15391] All specified packages are already installed
2019-05-10 03:26:27,239 [salt.state       :1951][INFO    ][15391] Completed state [iptables-persistent] at time 03:26:27.239717 duration_in_ms=9.048
2019-05-10 03:26:27,240 [salt.state       :1780][INFO    ][15391] Running state [iptables_modules_v4_load] at time 03:26:27.240923
2019-05-10 03:26:27,241 [salt.state       :1813][INFO    ][15391] Executing state kmod.present for [iptables_modules_v4_load]
2019-05-10 03:26:27,241 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command 'lsmod' in directory '/root'
2019-05-10 03:26:27,267 [salt.state       :300 ][INFO    ][15391] Kernel modules iptable_filter, ip_tables are already present
2019-05-10 03:26:27,268 [salt.state       :1951][INFO    ][15391] Completed state [iptables_modules_v4_load] at time 03:26:27.268852 duration_in_ms=27.928
2019-05-10 03:26:27,269 [salt.state       :1780][INFO    ][15391] Running state [/etc/iptables/rules.v4] at time 03:26:27.269907
2019-05-10 03:26:27,270 [salt.state       :1813][INFO    ][15391] Executing state file.managed for [/etc/iptables/rules.v4]
2019-05-10 03:26:27,385 [salt.state       :300 ][INFO    ][15391] File /etc/iptables/rules.v4 is in the correct state
2019-05-10 03:26:27,386 [salt.state       :1951][INFO    ][15391] Completed state [/etc/iptables/rules.v4] at time 03:26:27.385970 duration_in_ms=116.064
2019-05-10 03:26:27,387 [salt.state       :1780][INFO    ][15391] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:26:27.387289
2019-05-10 03:26:27,387 [salt.state       :1813][INFO    ][15391] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-05-10 03:26:27,388 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-05-10 03:26:27,408 [salt.state       :300 ][INFO    ][15391] onlyif execution failed
2019-05-10 03:26:27,409 [salt.state       :1951][INFO    ][15391] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:26:27.408938 duration_in_ms=21.648
2019-05-10 03:26:27,410 [salt.state       :1780][INFO    ][15391] Running state [netfilter-persistent] at time 03:26:27.410293
2019-05-10 03:26:27,410 [salt.state       :1813][INFO    ][15391] Executing state service.running for [netfilter-persistent]
2019-05-10 03:26:27,411 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-05-10 03:26:27,432 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-05-10 03:26:27,450 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-05-10 03:26:27,468 [salt.state       :300 ][INFO    ][15391] The service netfilter-persistent is already running
2019-05-10 03:26:27,468 [salt.state       :1951][INFO    ][15391] Completed state [netfilter-persistent] at time 03:26:27.468511 duration_in_ms=58.218
2019-05-10 03:26:27,469 [salt.state       :1780][INFO    ][15391] Running state [iptables_extra.remove_stale_tables] at time 03:26:27.469892
2019-05-10 03:26:27,470 [salt.state       :1813][INFO    ][15391] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-05-10 03:26:27,471 [salt.state       :300 ][INFO    ][15391] No changes made for iptables_extra.remove_stale_tables
2019-05-10 03:26:27,471 [salt.state       :1951][INFO    ][15391] Completed state [iptables_extra.remove_stale_tables] at time 03:26:27.471316 duration_in_ms=1.424
2019-05-10 03:26:27,471 [salt.state       :1780][INFO    ][15391] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:26:27.471729
2019-05-10 03:26:27,472 [salt.state       :1813][INFO    ][15391] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-05-10 03:26:27,473 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15391] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-05-10 03:26:27,488 [salt.state       :300 ][INFO    ][15391] onlyif execution failed
2019-05-10 03:26:27,489 [salt.state       :1951][INFO    ][15391] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:26:27.489303 duration_in_ms=17.574
2019-05-10 03:26:27,490 [salt.state       :1780][INFO    ][15391] Running state [/etc/iptables/rules.v6] at time 03:26:27.490791
2019-05-10 03:26:27,491 [salt.state       :1813][INFO    ][15391] Executing state file.absent for [/etc/iptables/rules.v6]
2019-05-10 03:26:27,492 [salt.state       :300 ][INFO    ][15391] File /etc/iptables/rules.v6 is not present
2019-05-10 03:26:27,492 [salt.state       :1951][INFO    ][15391] Completed state [/etc/iptables/rules.v6] at time 03:26:27.492294 duration_in_ms=1.503
2019-05-10 03:26:27,493 [salt.state       :1780][INFO    ][15391] Running state [iptables_extra.flush_all] at time 03:26:27.493340
2019-05-10 03:26:27,493 [salt.state       :1813][INFO    ][15391] Executing state module.wait for [iptables_extra.flush_all]
2019-05-10 03:26:27,494 [salt.state       :300 ][INFO    ][15391] No changes made for iptables_extra.flush_all
2019-05-10 03:26:27,494 [salt.state       :1951][INFO    ][15391] Completed state [iptables_extra.flush_all] at time 03:26:27.494535 duration_in_ms=1.196
2019-05-10 03:26:27,499 [salt.minion      :1711][INFO    ][15391] Returning information for job: 20190510032619489241
2019-05-10 03:26:28,104 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command state.apply with jid 20190510032628091495
2019-05-10 03:26:28,127 [salt.minion      :1432][INFO    ][15478] Starting a new job with PID 15478
2019-05-10 03:26:28,918 [salt.state       :915 ][INFO    ][15478] Loading fresh modules for state activity
2019-05-10 03:26:29,535 [salt.state       :1780][INFO    ][15478] Running state [maas-rack-controller] at time 03:26:29.535815
2019-05-10 03:26:29,536 [salt.state       :1813][INFO    ][15478] Executing state pkg.installed for [maas-rack-controller]
2019-05-10 03:26:29,536 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15478] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-10 03:26:29,625 [salt.state       :300 ][INFO    ][15478] All specified packages are already installed
2019-05-10 03:26:29,625 [salt.state       :1951][INFO    ][15478] Completed state [maas-rack-controller] at time 03:26:29.625598 duration_in_ms=89.783
2019-05-10 03:26:29,626 [salt.state       :1780][INFO    ][15478] Running state [ipmitool] at time 03:26:29.626003
2019-05-10 03:26:29,626 [salt.state       :1813][INFO    ][15478] Executing state pkg.installed for [ipmitool]
2019-05-10 03:26:29,632 [salt.state       :300 ][INFO    ][15478] All specified packages are already installed
2019-05-10 03:26:29,632 [salt.state       :1951][INFO    ][15478] Completed state [ipmitool] at time 03:26:29.632386 duration_in_ms=6.383
2019-05-10 03:26:29,635 [salt.state       :1780][INFO    ][15478] Running state [/etc/maas/rackd.conf] at time 03:26:29.635164
2019-05-10 03:26:29,635 [salt.state       :1813][INFO    ][15478] Executing state file.line for [/etc/maas/rackd.conf]
2019-05-10 03:26:29,636 [salt.state       :300 ][INFO    ][15478] No changes needed to be made
2019-05-10 03:26:29,636 [salt.state       :1951][INFO    ][15478] Completed state [/etc/maas/rackd.conf] at time 03:26:29.636576 duration_in_ms=1.412
2019-05-10 03:26:29,636 [salt.state       :1780][INFO    ][15478] Running state [/etc/maas/rackd.conf] at time 03:26:29.636834
2019-05-10 03:26:29,637 [salt.state       :1813][INFO    ][15478] Executing state file.managed for [/etc/maas/rackd.conf]
2019-05-10 03:26:29,637 [salt.loaded.int.states.file:2298][WARNING ][15478] 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-10 03:26:29,637 [salt.state       :300 ][INFO    ][15478] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-05-10 03:26:29,638 [salt.state       :1951][INFO    ][15478] Completed state [/etc/maas/rackd.conf] at time 03:26:29.638069 duration_in_ms=1.235
2019-05-10 03:26:29,638 [salt.state       :1780][INFO    ][15478] Running state [maas-rackd] at time 03:26:29.638897
2019-05-10 03:26:29,639 [salt.state       :1813][INFO    ][15478] Executing state service.running for [maas-rackd]
2019-05-10 03:26:29,639 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15478] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-05-10 03:26:29,673 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15478] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-05-10 03:26:29,690 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15478] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-05-10 03:26:29,706 [salt.state       :300 ][INFO    ][15478] The service maas-rackd is already running
2019-05-10 03:26:29,706 [salt.state       :1951][INFO    ][15478] Completed state [maas-rackd] at time 03:26:29.706774 duration_in_ms=67.876
2019-05-10 03:26:29,708 [salt.minion      :1711][INFO    ][15478] Returning information for job: 20190510032628091495
2019-05-10 03:26:30,256 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command state.apply with jid 20190510032630243917
2019-05-10 03:26:30,279 [salt.minion      :1432][INFO    ][15501] Starting a new job with PID 15501
2019-05-10 03:26:31,036 [salt.state       :915 ][INFO    ][15501] Loading fresh modules for state activity
2019-05-10 03:26:31,711 [salt.state       :1780][INFO    ][15501] Running state [maas-region-controller] at time 03:26:31.711790
2019-05-10 03:26:31,712 [salt.state       :1813][INFO    ][15501] Executing state pkg.installed for [maas-region-controller]
2019-05-10 03:26:31,712 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-05-10 03:26:31,789 [salt.state       :300 ][INFO    ][15501] All specified packages are already installed
2019-05-10 03:26:31,789 [salt.state       :1951][INFO    ][15501] Completed state [maas-region-controller] at time 03:26:31.789569 duration_in_ms=77.78
2019-05-10 03:26:31,789 [salt.state       :1780][INFO    ][15501] Running state [python-oauth] at time 03:26:31.789818
2019-05-10 03:26:31,790 [salt.state       :1813][INFO    ][15501] Executing state pkg.installed for [python-oauth]
2019-05-10 03:26:31,794 [salt.state       :300 ][INFO    ][15501] All specified packages are already installed
2019-05-10 03:26:31,794 [salt.state       :1951][INFO    ][15501] Completed state [python-oauth] at time 03:26:31.794946 duration_in_ms=5.129
2019-05-10 03:26:31,797 [salt.state       :1780][INFO    ][15501] Running state [/etc/maas/regiond.conf] at time 03:26:31.797241
2019-05-10 03:26:31,797 [salt.state       :1813][INFO    ][15501] Executing state file.replace for [/etc/maas/regiond.conf]
2019-05-10 03:26:31,844 [salt.state       :300 ][INFO    ][15501] No changes needed to be made
2019-05-10 03:26:31,844 [salt.state       :1951][INFO    ][15501] Completed state [/etc/maas/regiond.conf] at time 03:26:31.844536 duration_in_ms=47.295
2019-05-10 03:26:31,845 [salt.state       :1780][INFO    ][15501] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:26:31.844968
2019-05-10 03:26:31,845 [salt.state       :1813][INFO    ][15501] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-05-10 03:26:31,999 [salt.state       :300 ][INFO    ][15501] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-05-10 03:26:32,000 [salt.state       :1951][INFO    ][15501] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:26:32.000135 duration_in_ms=155.166
2019-05-10 03:26:32,001 [salt.state       :1780][INFO    ][15501] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:26:32.000951
2019-05-10 03:26:32,001 [salt.state       :1813][INFO    ][15501] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-10 03:26:32,020 [salt.state       :300 ][INFO    ][15501] No changes needed to be made
2019-05-10 03:26:32,020 [salt.state       :1951][INFO    ][15501] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:26:32.020309 duration_in_ms=19.358
2019-05-10 03:26:32,021 [salt.state       :1780][INFO    ][15501] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:26:32.021074
2019-05-10 03:26:32,021 [salt.state       :1813][INFO    ][15501] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-05-10 03:26:32,043 [salt.state       :300 ][INFO    ][15501] No changes needed to be made
2019-05-10 03:26:32,044 [salt.state       :1951][INFO    ][15501] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:26:32.043972 duration_in_ms=22.898
2019-05-10 03:26:32,044 [salt.state       :1780][INFO    ][15501] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:26:32.044685
2019-05-10 03:26:32,045 [salt.state       :1813][INFO    ][15501] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-05-10 03:26:32,077 [salt.state       :300 ][INFO    ][15501] No changes needed to be made
2019-05-10 03:26:32,078 [salt.state       :1951][INFO    ][15501] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:26:32.077995 duration_in_ms=33.311
2019-05-10 03:26:32,078 [salt.state       :1780][INFO    ][15501] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:26:32.078595
2019-05-10 03:26:32,078 [salt.state       :1813][INFO    ][15501] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-05-10 03:26:32,091 [salt.state       :300 ][INFO    ][15501] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-05-10 03:26:32,091 [salt.state       :1951][INFO    ][15501] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:26:32.091684 duration_in_ms=13.09
2019-05-10 03:26:32,093 [salt.state       :1780][INFO    ][15501] Running state [a2enmod headers] at time 03:26:32.093133
2019-05-10 03:26:32,093 [salt.state       :1813][INFO    ][15501] Executing state cmd.run for [a2enmod headers]
2019-05-10 03:26:32,094 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command 'a2enmod headers' in directory '/root'
2019-05-10 03:26:32,165 [salt.state       :300 ][INFO    ][15501] {'pid': 15520, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-05-10 03:26:32,166 [salt.state       :1951][INFO    ][15501] Completed state [a2enmod headers] at time 03:26:32.166364 duration_in_ms=73.231
2019-05-10 03:26:32,166 [salt.state       :1780][INFO    ][15501] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:26:32.166921
2019-05-10 03:26:32,167 [salt.state       :1813][INFO    ][15501] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-05-10 03:26:32,185 [salt.state       :300 ][INFO    ][15501] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-05-10 03:26:32,185 [salt.state       :1951][INFO    ][15501] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:26:32.185719 duration_in_ms=18.798
2019-05-10 03:26:32,186 [salt.state       :1780][INFO    ][15501] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:26:32.186512
2019-05-10 03:26:32,186 [salt.state       :1813][INFO    ][15501] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-05-10 03:26:32,275 [salt.state       :300 ][INFO    ][15501] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-05-10 03:26:32,276 [salt.state       :1951][INFO    ][15501] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:26:32.276090 duration_in_ms=89.569
2019-05-10 03:26:32,276 [salt.state       :1780][INFO    ][15501] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:26:32.276912
2019-05-10 03:26:32,277 [salt.state       :1813][INFO    ][15501] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-05-10 03:26:32,335 [salt.state       :300 ][INFO    ][15501] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-05-10 03:26:32,335 [salt.state       :1951][INFO    ][15501] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:26:32.335253 duration_in_ms=58.342
2019-05-10 03:26:32,335 [salt.state       :1780][INFO    ][15501] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:26:32.335706
2019-05-10 03:26:32,335 [salt.state       :1813][INFO    ][15501] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-05-10 03:26:32,394 [salt.state       :300 ][INFO    ][15501] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-05-10 03:26:32,395 [salt.state       :1951][INFO    ][15501] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:26:32.394993 duration_in_ms=59.288
2019-05-10 03:26:32,395 [salt.state       :1780][INFO    ][15501] Running state [/root/.pgpass] at time 03:26:32.395254
2019-05-10 03:26:32,395 [salt.state       :1813][INFO    ][15501] Executing state file.managed for [/root/.pgpass]
2019-05-10 03:26:32,442 [salt.state       :300 ][INFO    ][15501] File /root/.pgpass is in the correct state
2019-05-10 03:26:32,443 [salt.state       :1951][INFO    ][15501] Completed state [/root/.pgpass] at time 03:26:32.442971 duration_in_ms=47.717
2019-05-10 03:26:32,447 [salt.state       :1780][INFO    ][15501] Running state [maas-region syncdb --noinput] at time 03:26:32.447550
2019-05-10 03:26:32,447 [salt.state       :1813][INFO    ][15501] Executing state cmd.run for [maas-region syncdb --noinput]
2019-05-10 03:26:32,448 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-05-10 03:26:34,432 [salt.state       :300 ][INFO    ][15501] {'pid': 15533, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: staticfiles, messages\n  Apply all migrations: contenttypes, maasserver, sites, sessions, auth, metadataserver, 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-10 03:26:34,433 [salt.state       :1951][INFO    ][15501] Completed state [maas-region syncdb --noinput] at time 03:26:34.433443 duration_in_ms=1985.891
2019-05-10 03:26:34,433 [salt.state       :2022][WARNING ][15501] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-05-10 03:26:34,436 [salt.state       :1780][INFO    ][15501] Running state [maas-regiond] at time 03:26:34.436689
2019-05-10 03:26:34,437 [salt.state       :1813][INFO    ][15501] Executing state service.running for [maas-regiond]
2019-05-10 03:26:34,438 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-05-10 03:26:34,470 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-05-10 03:26:34,485 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-05-10 03:26:34,499 [salt.state       :300 ][INFO    ][15501] The service maas-regiond is already running
2019-05-10 03:26:34,499 [salt.state       :1951][INFO    ][15501] Completed state [maas-regiond] at time 03:26:34.499514 duration_in_ms=62.825
2019-05-10 03:26:34,501 [salt.state       :1780][INFO    ][15501] Running state [bind9] at time 03:26:34.501698
2019-05-10 03:26:34,502 [salt.state       :1813][INFO    ][15501] Executing state service.running for [bind9]
2019-05-10 03:26:34,503 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-05-10 03:26:34,517 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-05-10 03:26:34,530 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-05-10 03:26:34,543 [salt.state       :300 ][INFO    ][15501] The service bind9 is already running
2019-05-10 03:26:34,544 [salt.state       :1951][INFO    ][15501] Completed state [bind9] at time 03:26:34.544250 duration_in_ms=42.553
2019-05-10 03:26:34,546 [salt.state       :1780][INFO    ][15501] Running state [apache2] at time 03:26:34.546111
2019-05-10 03:26:34,546 [salt.state       :1813][INFO    ][15501] Executing state service.running for [apache2]
2019-05-10 03:26:34,547 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-05-10 03:26:34,561 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-05-10 03:26:34,573 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-05-10 03:26:34,590 [salt.state       :300 ][INFO    ][15501] The service apache2 is already running
2019-05-10 03:26:34,590 [salt.state       :1951][INFO    ][15501] Completed state [apache2] at time 03:26:34.590922 duration_in_ms=44.811
2019-05-10 03:26:34,592 [salt.state       :1780][INFO    ][15501] Running state [maasng.wait_for_http_code] at time 03:26:34.592352
2019-05-10 03:26:34,592 [salt.state       :1813][INFO    ][15501] Executing state module.run for [maasng.wait_for_http_code]
2019-05-10 03:26:34,593 [salt.utils.decorators:613 ][WARNING ][15501] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:26:34,601 [salt.state       :300 ][INFO    ][15501] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-05-10 03:26:34,601 [salt.state       :1951][INFO    ][15501] Completed state [maasng.wait_for_http_code] at time 03:26:34.601441 duration_in_ms=9.087
2019-05-10 03:26:34,602 [salt.state       :1780][INFO    ][15501] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:26:34.602864
2019-05-10 03:26:34,603 [salt.state       :1813][INFO    ][15501] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-05-10 03:26:34,604 [salt.state       :300 ][INFO    ][15501] /var/lib/maas/.setup_admin exists
2019-05-10 03:26:34,604 [salt.state       :1951][INFO    ][15501] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:26:34.604493 duration_in_ms=1.613
2019-05-10 03:26:34,605 [salt.state       :1780][INFO    ][15501] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:26:34.605675
2019-05-10 03:26:34,606 [salt.state       :1813][INFO    ][15501] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-10 03:26:34,607 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15501] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-10 03:26:36,132 [salt.state       :300 ][INFO    ][15501] {'pid': 15572, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-10 03:26:36,133 [salt.state       :1951][INFO    ][15501] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:26:36.133624 duration_in_ms=1527.949
2019-05-10 03:26:36,142 [salt.state       :1780][INFO    ][15501] Running state [maas_region_boot_source_resources_mirror] at time 03:26:36.142162
2019-05-10 03:26:36,142 [salt.state       :1813][INFO    ][15501] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-05-10 03:26:36,244 [salt.state       :300 ][INFO    ][15501] {'changes': {}}
2019-05-10 03:26:36,245 [salt.state       :1951][INFO    ][15501] Completed state [maas_region_boot_source_resources_mirror] at time 03:26:36.245288 duration_in_ms=103.128
2019-05-10 03:26:36,245 [salt.state       :1780][INFO    ][15501] Running state [maasng.boot_resources_import] at time 03:26:36.245925
2019-05-10 03:26:36,246 [salt.state       :1813][INFO    ][15501] Executing state module.run for [maasng.boot_resources_import]
2019-05-10 03:26:36,246 [salt.utils.decorators:613 ][WARNING ][15501] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:26:36,347 [salt.loaded.ext.module.maasng:1600][INFO    ][15501] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-05-10 03:26:41,396 [salt.loaded.ext.module.maasng:1600][INFO    ][15501] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-05-10 03:26:45,307 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032645295684
2019-05-10 03:26:45,329 [salt.minion      :1432][INFO    ][16004] Starting a new job with PID 16004
2019-05-10 03:26:45,351 [salt.minion      :1711][INFO    ][16004] Returning information for job: 20190510032645295684
2019-05-10 03:26:46,540 [salt.loaded.ext.module.maasng:1600][INFO    ][15501] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-05-10 03:26:51,663 [salt.state       :300 ][INFO    ][15501] {'ret': True}
2019-05-10 03:26:51,664 [salt.state       :1951][INFO    ][15501] Completed state [maasng.boot_resources_import] at time 03:26:51.664132 duration_in_ms=15418.205
2019-05-10 03:26:51,665 [salt.state       :1780][INFO    ][15501] Running state [maas_region_boot_sources_selection_xenial] at time 03:26:51.665195
2019-05-10 03:26:51,665 [salt.state       :1813][INFO    ][15501] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-05-10 03:26:51,879 [salt.state       :300 ][INFO    ][15501] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-05-10 03:26:51,879 [salt.state       :1951][INFO    ][15501] Completed state [maas_region_boot_sources_selection_xenial] at time 03:26:51.879392 duration_in_ms=214.195
2019-05-10 03:26:51,880 [salt.state       :1780][INFO    ][15501] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 03:26:51.880796
2019-05-10 03:26:51,881 [salt.state       :1813][INFO    ][15501] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-05-10 03:26:51,881 [salt.utils.decorators:613 ][WARNING ][15501] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:26:51,882 [salt.loaded.ext.module.maasng:1771][INFO    ][15501] boot-sources sync initiated for ALL Rack's
2019-05-10 03:26:52,721 [salt.state       :300 ][INFO    ][15501] {'ret': True}
2019-05-10 03:26:52,721 [salt.state       :1951][INFO    ][15501] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 03:26:52.721772 duration_in_ms=840.975
2019-05-10 03:26:52,723 [salt.state       :1780][INFO    ][15501] Running state [maas.process_maas_config] at time 03:26:52.723807
2019-05-10 03:26:52,724 [salt.state       :1813][INFO    ][15501] Executing state module.run for [maas.process_maas_config]
2019-05-10 03:26:52,724 [salt.utils.decorators:613 ][WARNING ][15501] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:26:52,725 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=enable_http_proxy value=True
2019-05-10 03:26:52,778 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=upstream_dns value=8.8.8.8
2019-05-10 03:26:52,842 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=commissioning_distro_series value=xenial
2019-05-10 03:26:52,907 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=default_osystem value=ubuntu
2019-05-10 03:26:52,973 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=active_discovery_interval value=600
2019-05-10 03:26:53,027 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=dnssec_validation value=no
2019-05-10 03:26:56,401 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=maas_name value=mas01
2019-05-10 03:26:56,482 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=network_discovery value=enabled
2019-05-10 03:26:56,574 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=enable_third_party_drivers value=True
2019-05-10 03:26:56,614 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=default_storage_layout value=lvm
2019-05-10 03:26:56,657 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=ntp_external_only value=True
2019-05-10 03:26:56,698 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=disk_erase_with_secure_erase value=False
2019-05-10 03:26:56,757 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=default_distro_series value=xenial
2019-05-10 03:26:56,807 [salt.loaded.ext.module.maas:92  ][INFO    ][15501] maasconfig name=default_min_hwe_kernel value=hwe-16.04
2019-05-10 03:26:56,890 [salt.state       :300 ][INFO    ][15501] {'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-10 03:26:56,891 [salt.state       :1951][INFO    ][15501] Completed state [maas.process_maas_config] at time 03:26:56.890995 duration_in_ms=4167.188
2019-05-10 03:26:56,891 [salt.state       :1780][INFO    ][15501] Running state [pxe_admin] at time 03:26:56.891432
2019-05-10 03:26:56,891 [salt.state       :1813][INFO    ][15501] Executing state maasng.fabric_present for [pxe_admin]
2019-05-10 03:26:56,932 [salt.loaded.ext.module.maasng:945 ][INFO    ][15501] [{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'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'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'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'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'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-10 03:26:56,985 [salt.loaded.ext.module.maasng:1008][WARNING ][15501] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-05-10 03:26:56,986 [salt.loaded.ext.module.maasng:1011][WARNING ][15501] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-05-10 03:26:57,059 [salt.state       :300 ][INFO    ][15501] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-05-10 03:26:57,060 [salt.state       :1951][INFO    ][15501] Completed state [pxe_admin] at time 03:26:57.060011 duration_in_ms=168.577
2019-05-10 03:26:57,060 [salt.state       :1780][INFO    ][15501] Running state [vlan 0] at time 03:26:57.060470
2019-05-10 03:26:57,060 [salt.state       :1813][INFO    ][15501] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-10 03:26:57,125 [salt.loaded.ext.module.maasng:945 ][INFO    ][15501] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-05-10 03:26:57,226 [salt.loaded.ext.module.maasng:945 ][INFO    ][15501] [{u'id': 0, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}], u'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'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'fabric': u'fabric-1'}], u'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'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'name': u'pxe_admin', u'class_type': u''}]
2019-05-10 03:26:57,513 [salt.loaded.ext.module.maasng:945 ][INFO    ][15501] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-05-10 03:26:57,609 [salt.state       :300 ][INFO    ][15501] {'new': 'Vlan untagged was updated'}
2019-05-10 03:26:57,609 [salt.state       :1951][INFO    ][15501] Completed state [vlan 0] at time 03:26:57.609871 duration_in_ms=549.4
2019-05-10 03:26:57,611 [salt.state       :1780][INFO    ][15501] Running state [192.168.11.0/24] at time 03:26:57.611467
2019-05-10 03:26:57,612 [salt.state       :1813][INFO    ][15501] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-05-10 03:26:57,848 [salt.loaded.ext.module.maasng:945 ][INFO    ][15501] [{u'name': u'fabric-0', u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0}, {u'name': u'fabric-1', u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/', u'id': 5002, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': None, u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1}, {u'name': u'pxe_admin', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}], u'class_type': u'', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2}]
2019-05-10 03:26:57,849 [salt.loaded.ext.module.maasng:1235][WARNING ][15501] Ignoring parameter vlan:0
2019-05-10 03:26:57,927 [salt.state       :300 ][INFO    ][15501] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-05-10 03:26:57,928 [salt.state       :1951][INFO    ][15501] Completed state [192.168.11.0/24] at time 03:26:57.928237 duration_in_ms=316.769
2019-05-10 03:26:57,929 [salt.state       :1780][INFO    ][15501] Running state [maas_create_iprange_1] at time 03:26:57.929570
2019-05-10 03:26:57,930 [salt.state       :1813][INFO    ][15501] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-05-10 03:26:57,987 [salt.state       :300 ][INFO    ][15501] Iprange maas_create_iprange_1 already exist.
2019-05-10 03:26:57,987 [salt.state       :1951][INFO    ][15501] Completed state [maas_create_iprange_1] at time 03:26:57.987442 duration_in_ms=57.871
2019-05-10 03:26:57,987 [salt.state       :1780][INFO    ][15501] Running state [vlan 0] at time 03:26:57.987905
2019-05-10 03:26:57,988 [salt.state       :1813][INFO    ][15501] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-05-10 03:26:58,053 [salt.loaded.ext.module.maasng:945 ][INFO    ][15501] [{u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'6r6fem', 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'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-10 03:26:58,166 [salt.loaded.ext.module.maasng:945 ][INFO    ][15501] [{u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'6r6fem', 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'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-10 03:26:58,459 [salt.loaded.ext.module.maasng:945 ][INFO    ][15501] [{u'class_type': None, u'vlans': [{u'vid': 0, u'fabric': u'fabric-0', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'vid': 0, u'fabric': u'fabric-1', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'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'vid': 0, u'fabric': u'pxe_admin', u'name': u'untagged', u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': u'6r6fem', 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'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-05-10 03:26:58,574 [salt.state       :300 ][INFO    ][15501] {'new': 'Vlan untagged was updated'}
2019-05-10 03:26:58,574 [salt.state       :1951][INFO    ][15501] Completed state [vlan 0] at time 03:26:58.574433 duration_in_ms=586.526
2019-05-10 03:26:58,575 [salt.state       :1780][INFO    ][15501] Running state [opnfv] at time 03:26:58.575569
2019-05-10 03:26:58,576 [salt.state       :1813][INFO    ][15501] Executing state maasng.sshkey_present for [opnfv]
2019-05-10 03:26:58,632 [salt.loaded.ext.module.maasng:1903][INFO    ][15501] [{u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'keysource': u''}]
2019-05-10 03:26:58,633 [salt.state       :300 ][INFO    ][15501] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-05-10 03:26:58,633 [salt.state       :1951][INFO    ][15501] Completed state [opnfv] at time 03:26:58.633759 duration_in_ms=58.189
2019-05-10 03:26:58,638 [salt.minion      :1711][INFO    ][15501] Returning information for job: 20190510032630243917
2019-05-10 03:26:59,120 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command state.apply with jid 20190510032659109872
2019-05-10 03:26:59,142 [salt.minion      :1432][INFO    ][16406] Starting a new job with PID 16406
2019-05-10 03:27:02,709 [salt.state       :915 ][INFO    ][16406] Loading fresh modules for state activity
2019-05-10 03:27:02,797 [salt.state       :1780][INFO    ][16406] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:27:02.797471
2019-05-10 03:27:02,797 [salt.state       :1813][INFO    ][16406] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-10 03:27:02,800 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16406] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-10 03:27:04,157 [salt.state       :300 ][INFO    ][16406] {'pid': 16452, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-10 03:27:04,157 [salt.state       :1951][INFO    ][16406] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:27:04.157390 duration_in_ms=1359.92
2019-05-10 03:27:04,158 [salt.state       :1780][INFO    ][16406] Running state [maas.process_machines] at time 03:27:04.158514
2019-05-10 03:27:04,158 [salt.state       :1813][INFO    ][16406] Executing state module.run for [maas.process_machines]
2019-05-10 03:27:04,159 [salt.utils.decorators:613 ][WARNING ][16406] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:27:04,493 [salt.loaded.ext.module.maas:412 ][WARNING ][16406] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:27:04,494 [salt.loaded.ext.module.maas:92  ][INFO    ][16406] machine hostname=cmp002 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:6a'] power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus system_id=b74m8w architecture=amd64/generic power_parameters_power_user=admin
2019-05-10 03:27:05,539 [salt.loaded.ext.module.maas:412 ][WARNING ][16406] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:27:05,540 [salt.loaded.ext.module.maas:92  ][INFO    ][16406] machine hostname=cmp001 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:5a'] power_parameters_power_address=172.30.8.73 power_parameters_power_pass=octopus system_id=cxwqga architecture=amd64/generic power_parameters_power_user=admin
2019-05-10 03:27:06,587 [salt.loaded.ext.module.maas:412 ][WARNING ][16406] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:27:06,588 [salt.loaded.ext.module.maas:92  ][INFO    ][16406] machine hostname=kvm01 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=kwaark architecture=amd64/generic power_parameters_power_user=admin
2019-05-10 03:27:07,556 [salt.loaded.ext.module.maas:412 ][WARNING ][16406] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:27:07,557 [salt.loaded.ext.module.maas:92  ][INFO    ][16406] machine hostname=kvm03 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:4a'] power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus system_id=m8gmta architecture=amd64/generic power_parameters_power_user=admin
2019-05-10 03:27:08,568 [salt.loaded.ext.module.maas:412 ][WARNING ][16406] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:27:08,569 [salt.loaded.ext.module.maas:92  ][INFO    ][16406] machine hostname=kvm02 power_type=ipmi mac_addresses=[u'00:25:b5:a0:00:3a'] power_parameters_power_address=172.30.8.65 power_parameters_power_pass=octopus system_id=skrcta architecture=amd64/generic power_parameters_power_user=admin
2019-05-10 03:27:09,606 [salt.state       :300 ][INFO    ][16406] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-05-10 03:27:09,607 [salt.state       :1951][INFO    ][16406] Completed state [maas.process_machines] at time 03:27:09.607085 duration_in_ms=5448.569
2019-05-10 03:27:09,611 [salt.minion      :1711][INFO    ][16406] Returning information for job: 20190510032659109872
2019-05-10 03:27:40,586 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command state.apply with jid 20190510032740574057
2019-05-10 03:27:40,610 [salt.minion      :1432][INFO    ][16760] Starting a new job with PID 16760
2019-05-10 03:27:44,349 [salt.state       :915 ][INFO    ][16760] Loading fresh modules for state activity
2019-05-10 03:27:44,434 [salt.state       :1780][INFO    ][16760] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:27:44.434351
2019-05-10 03:27:44,434 [salt.state       :1813][INFO    ][16760] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-10 03:27:44,436 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16760] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-10 03:27:45,854 [salt.state       :300 ][INFO    ][16760] {'pid': 16779, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-10 03:27:45,855 [salt.state       :1951][INFO    ][16760] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:27:45.855556 duration_in_ms=1421.205
2019-05-10 03:27:45,858 [salt.state       :1780][INFO    ][16760] Running state [maas.wait_for_machine_status] at time 03:27:45.858655
2019-05-10 03:27:45,859 [salt.state       :1813][INFO    ][16760] Executing state module.run for [maas.wait_for_machine_status]
2019-05-10 03:27:45,859 [salt.utils.decorators:613 ][WARNING ][16760] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:27:48,114 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03']
sleep for:30s Timeout:1500s (1497.75470781s left)
2019-05-10 03:27:55,637 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032755622881
2019-05-10 03:27:55,663 [salt.minion      :1432][INFO    ][16890] Starting a new job with PID 16890
2019-05-10 03:27:55,686 [salt.minion      :1711][INFO    ][16890] Returning information for job: 20190510032755622881
2019-05-10 03:28:21,421 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1464.44750786s left)
2019-05-10 03:28:25,685 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032825672932
2019-05-10 03:28:25,711 [salt.minion      :1432][INFO    ][16937] Starting a new job with PID 16937
2019-05-10 03:28:25,733 [salt.minion      :1711][INFO    ][16937] Returning information for job: 20190510032825672932
2019-05-10 03:28:54,416 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1431.45242381s left)
2019-05-10 03:28:55,793 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032855780034
2019-05-10 03:28:55,818 [salt.minion      :1432][INFO    ][17031] Starting a new job with PID 17031
2019-05-10 03:28:55,839 [salt.minion      :1711][INFO    ][17031] Returning information for job: 20190510032855780034
2019-05-10 03:29:25,841 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032925828880
2019-05-10 03:29:25,866 [salt.minion      :1432][INFO    ][17050] Starting a new job with PID 17050
2019-05-10 03:29:25,888 [salt.minion      :1711][INFO    ][17050] Returning information for job: 20190510032925828880
2019-05-10 03:29:27,337 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1398.53220487s left)
2019-05-10 03:29:55,887 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510032955879413
2019-05-10 03:29:55,910 [salt.minion      :1432][INFO    ][17121] Starting a new job with PID 17121
2019-05-10 03:29:55,932 [salt.minion      :1711][INFO    ][17121] Returning information for job: 20190510032955879413
2019-05-10 03:29:58,972 [salt.loaded.ext.module.maas:981 ][INFO    ][16760] Machine kwaark deleted
2019-05-10 03:30:00,062 [salt.loaded.ext.module.maas:412 ][WARNING ][16760] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:30:00,062 [salt.loaded.ext.module.maas:92  ][INFO    ][16760] 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=b74m8w architecture=amd64/generic power_parameters_power_user=admin
2019-05-10 03:30:01,229 [salt.loaded.ext.module.maas:412 ][WARNING ][16760] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:30:01,230 [salt.loaded.ext.module.maas:92  ][INFO    ][16760] 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=cxwqga architecture=amd64/generic power_parameters_power_user=admin
2019-05-10 03:30:02,282 [salt.loaded.ext.module.maas:412 ][WARNING ][16760] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:30:02,282 [salt.loaded.ext.module.maas:92  ][INFO    ][16760] 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-10 03:30:03,684 [salt.loaded.ext.module.maas:412 ][WARNING ][16760] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:30:03,685 [salt.loaded.ext.module.maas:92  ][INFO    ][16760] 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=m8gmta architecture=amd64/generic power_parameters_power_user=admin
2019-05-10 03:30:04,774 [salt.loaded.ext.module.maas:412 ][WARNING ][16760] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-05-10 03:30:04,775 [salt.loaded.ext.module.maas:92  ][INFO    ][16760] 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=skrcta architecture=amd64/generic power_parameters_power_user=admin
2019-05-10 03:30:07,329 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1358.53957701s left)
2019-05-10 03:30:25,943 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033025930616
2019-05-10 03:30:25,967 [salt.minion      :1432][INFO    ][17419] Starting a new job with PID 17419
2019-05-10 03:30:25,990 [salt.minion      :1711][INFO    ][17419] Returning information for job: 20190510033025930616
2019-05-10 03:30:40,273 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1325.59588695s left)
2019-05-10 03:30:56,002 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033055987819
2019-05-10 03:30:56,027 [salt.minion      :1432][INFO    ][17475] Starting a new job with PID 17475
2019-05-10 03:30:56,051 [salt.minion      :1711][INFO    ][17475] Returning information for job: 20190510033055987819
2019-05-10 03:31:13,460 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1292.40908384s left)
2019-05-10 03:31:26,065 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033126053192
2019-05-10 03:31:26,090 [salt.minion      :1432][INFO    ][17501] Starting a new job with PID 17501
2019-05-10 03:31:26,112 [salt.minion      :1711][INFO    ][17501] Returning information for job: 20190510033126053192
2019-05-10 03:31:46,637 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1259.2314539s left)
2019-05-10 03:31:56,129 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033156116865
2019-05-10 03:31:56,154 [salt.minion      :1432][INFO    ][17581] Starting a new job with PID 17581
2019-05-10 03:31:56,177 [salt.minion      :1711][INFO    ][17581] Returning information for job: 20190510033156116865
2019-05-10 03:32:19,422 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1226.44655085s left)
2019-05-10 03:32:26,199 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033226186971
2019-05-10 03:32:26,224 [salt.minion      :1432][INFO    ][17617] Starting a new job with PID 17617
2019-05-10 03:32:26,247 [salt.minion      :1711][INFO    ][17617] Returning information for job: 20190510033226186971
2019-05-10 03:32:52,593 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1193.27561092s left)
2019-05-10 03:32:56,283 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033256271138
2019-05-10 03:32:56,308 [salt.minion      :1432][INFO    ][17810] Starting a new job with PID 17810
2019-05-10 03:32:56,329 [salt.minion      :1711][INFO    ][17810] Returning information for job: 20190510033256271138
2019-05-10 03:33:25,862 [salt.loaded.ext.module.maas:1023][INFO    ][16760] Waiting status:Ready|Deployed for machines:['kvm01']
sleep for:30s Timeout:1500s (1160.00664997s left)
2019-05-10 03:33:26,363 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033326350655
2019-05-10 03:33:26,388 [salt.minion      :1432][INFO    ][17831] Starting a new job with PID 17831
2019-05-10 03:33:26,411 [salt.minion      :1711][INFO    ][17831] Returning information for job: 20190510033326350655
2019-05-10 03:33:56,451 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033356438375
2019-05-10 03:33:56,475 [salt.minion      :1432][INFO    ][17902] Starting a new job with PID 17902
2019-05-10 03:33:56,497 [salt.minion      :1711][INFO    ][17902] Returning information for job: 20190510033356438375
2019-05-10 03:33:59,367 [salt.state       :300 ][INFO    ][16760] {'ret': True}
2019-05-10 03:33:59,368 [salt.state       :1951][INFO    ][16760] Completed state [maas.wait_for_machine_status] at time 03:33:59.367940 duration_in_ms=373509.284
2019-05-10 03:33:59,371 [salt.minion      :1711][INFO    ][16760] Returning information for job: 20190510032740574057
2019-05-10 03:34:00,020 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command state.apply with jid 20190510033400007341
2019-05-10 03:34:00,043 [salt.minion      :1432][INFO    ][17913] Starting a new job with PID 17913
2019-05-10 03:34:03,779 [salt.state       :915 ][INFO    ][17913] Loading fresh modules for state activity
2019-05-10 03:34:03,834 [salt.fileclient  :1219][INFO    ][17913] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-05-10 03:34:03,916 [salt.state       :1780][INFO    ][17913] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:34:03.916458
2019-05-10 03:34:03,916 [salt.state       :1813][INFO    ][17913] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-10 03:34:03,918 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17913] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-10 03:34:05,276 [salt.state       :300 ][INFO    ][17913] {'pid': 17936, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-10 03:34:05,277 [salt.state       :1951][INFO    ][17913] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:34:05.277379 duration_in_ms=1360.921
2019-05-10 03:34:05,278 [salt.state       :1780][INFO    ][17913] Running state [maas_machines_storage_cmp002_lvm] at time 03:34:05.278849
2019-05-10 03:34:05,279 [salt.state       :1813][INFO    ][17913] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-05-10 03:34:06,547 [salt.loaded.ext.module.maasng:610 ][INFO    ][17913] b74m8w
2019-05-10 03:34:06,547 [salt.loaded.ext.module.maasng:626 ][INFO    ][17913] sda
2019-05-10 03:34:07,112 [salt.loaded.ext.module.maasng:361 ][INFO    ][17913] b74m8w
2019-05-10 03:34:07,242 [salt.loaded.ext.module.maasng:367 ][INFO    ][17913] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/2/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'b74m8w', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'used_size': 2397998940160, u'id': 2, u'partitions': [{u'uuid': u'9a56fcb1-fe0a-44b6-bddf-00786c5fe141', u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/2/partition/2', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'b74m8w', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'5551f737-4869-4a6e-8f73-cc337ac48ada', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 2, u'type': u'partition', u'id': 2, u'size': 2397992648704}]}, {u'size': 2397988454400, u'model': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/6/', u'type': u'virtual', u'tags': [], u'uuid': u'0c1b4046-3b5d-467b-9a1d-925bc2370467', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'b74m8w', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'a1086302-a6b9-4bf8-83c2-c52446386dfc', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 6, u'partitions': []}]
2019-05-10 03:34:07,242 [salt.loaded.ext.module.maasng:632 ][INFO    ][17913] vgroot
2019-05-10 03:34:07,243 [salt.loaded.ext.module.maasng:635 ][INFO    ][17913] lvroot
2019-05-10 03:34:07,243 [salt.loaded.ext.module.maasng:639 ][INFO    ][17913] 107374182400
2019-05-10 03:34:07,788 [salt.loaded.ext.module.maasng:645 ][INFO    ][17913] {u'hwe_kernel': u'', u'testing_status_name': u'Passed', u'memory_test_status': -1, 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'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40', u'mode': u'dhcp', u'id': 17}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40'}], u'parents': [], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'system_id': u'b74m8w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/interfaces/4/'}, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 2, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'b74m8w', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'serial': u'618e728372755980239b15112698bc66', u'size': 2397998940160, u'used_size': 2397998940160, u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/2/', u'partitions': [{u'uuid': u'34fb3cc7-3646-4be4-abea-21a1196aa3cd', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'b74m8w', u'device_id': 2, u'filesystem': {u'uuid': u'9d288462-14e7-4413-86cc-f3d40b6473df', 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'size': 2397992648704, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/2/partition/6'}]}, {u'model': None, u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 11, u'uuid': u'f3b4b9e4-b2bf-48c2-8b50-d1ed2b00a938', u'used_for': u'ext4 formatted filesystem mounted at /', u'path': u'/dev/disk/by-dname/lvroot', u'system_id': u'b74m8w', u'partition_table_type': None, u'filesystem': {u'uuid': u'334b138e-1885-493d-9d90-1ad92cce3a3f', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'serial': None, u'size': 107374182400, u'used_size': 107374182400, u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/11/', u'partitions': []}], u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'current_commissioning_result_id': 2, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'b74m8w', 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'Power state queried: off', u'ip_addresses': [u'192.168.11.40'], u'min_hwe_kernel': u'hwe-16.04', u'status': 4, u'storage_test_status': 2, u'storage_test_status_name': u'Passed', u'power_state': u'off', u'physicalblockdevice_set': [{u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 2, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/2/', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'b74m8w', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'34fb3cc7-3646-4be4-abea-21a1196aa3cd', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'b74m8w', u'device_id': 2, u'filesystem': {u'uuid': u'9d288462-14e7-4413-86cc-f3d40b6473df', 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'size': 2397992648704, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/2/partition/6'}]}], u'other_test_status_name': u'Unknown', u'owner_data': {}, u'volume_groups': [{u'__incomplete__': True, u'system_id': u'b74m8w', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'node_type_name': u'Machine', u'current_testing_result_id': 3, u'cpu_test_status': -1, u'bcaches': [], u'other_test_status': -1, u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'virtualblockdevice_set': [{u'block_size': 4096, u'name': u'vgroot-lvroot', u'tags': [], u'type': u'virtual', u'id': 11, u'uuid': u'f3b4b9e4-b2bf-48c2-8b50-d1ed2b00a938', u'used_for': u'ext4 formatted filesystem mounted at /', u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/11/', u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'system_id': u'b74m8w', u'partition_table_type': None, u'filesystem': {u'uuid': u'334b138e-1885-493d-9d90-1ad92cce3a3f', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'id_path': None, u'available_size': 0, u'model': None, u'size': 107374182400, u'used_size': 107374182400, u'serial': None, u'partitions': []}], u'commissioning_status': 2, u'architecture': u'amd64/generic', u'commissioning_status_name': u'Passed', 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'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'name': u'enp6s0', u'links': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40', u'mode': u'dhcp', u'id': 17}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 4, u'discovered': [{u'subnet': {u'dns_servers': [], u'managed': True, u'name': u'192.168.11.0/24', u'space': u'undefined', u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'fabric': u'pxe_admin'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.40'}], u'parents': [], u'mac_address': u'00:25:b5:a0:00:6a', u'params': u'', u'system_id': u'b74m8w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/interfaces/4/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 18}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 12, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:6c', u'params': u'', u'system_id': u'b74m8w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/interfaces/12/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 19}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 13, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:6b', u'params': u'', u'system_id': u'b74m8w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/interfaces/13/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'fabric': u'fabric-0'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 20}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'id': 14, u'discovered': None, u'parents': [], u'mac_address': u'00:25:b5:a0:00:6d', u'params': u'', u'system_id': u'b74m8w', u'type': u'physical', u'children': [], u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/interfaces/14/'}], u'address_ttl': None, u'resource_uri': u'/MAAS/api/2.0/machines/b74m8w/', u'distro_series': u'', u'boot_disk': {u'block_size': 4096, u'name': u'sda', u'tags': [u'rotary'], u'type': u'physical', u'id': 2, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/2/', u'path': u'/dev/disk/by-dname/sda', u'system_id': u'b74m8w', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'available_size': 0, u'model': u'UCSB-MRAID12G', u'size': 2397998940160, u'used_size': 2397998940160, u'serial': u'618e728372755980239b15112698bc66', u'partitions': [{u'uuid': u'34fb3cc7-3646-4be4-abea-21a1196aa3cd', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'b74m8w', u'device_id': 2, u'filesystem': {u'uuid': u'9d288462-14e7-4413-86cc-f3d40b6473df', 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'size': 2397992648704, u'type': u'partition', u'id': 6, u'resource_uri': u'/MAAS/api/2.0/nodes/b74m8w/blockdevices/2/partition/6'}]}}
2019-05-10 03:34:07,790 [salt.state       :300 ][INFO    ][17913] {'new': {'storage_layout': 'lvm'}}
2019-05-10 03:34:07,791 [salt.state       :1951][INFO    ][17913] Completed state [maas_machines_storage_cmp002_lvm] at time 03:34:07.791195 duration_in_ms=2512.343
2019-05-10 03:34:07,791 [salt.state       :1780][INFO    ][17913] Running state [maas_machines_storage_cmp001_lvm] at time 03:34:07.791809
2019-05-10 03:34:07,792 [salt.state       :1813][INFO    ][17913] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-05-10 03:34:09,211 [salt.loaded.ext.module.maasng:610 ][INFO    ][17913] cxwqga
2019-05-10 03:34:09,212 [salt.loaded.ext.module.maasng:626 ][INFO    ][17913] sda
2019-05-10 03:34:09,893 [salt.loaded.ext.module.maasng:361 ][INFO    ][17913] cxwqga
2019-05-10 03:34:10,020 [salt.loaded.ext.module.maasng:367 ][INFO    ][17913] [{u'size': 2397998940160, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/4/', u'used_size': 2397998940160, u'id': 4, u'tags': [u'rotary'], u'filesystem': None, u'partitions': [{u'size': 2397992648704, u'uuid': u'be70d29f-adf8-4ba0-905f-147cbeff15f4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cxwqga', u'filesystem': {u'uuid': u'4c24ae41-d5f0-462c-8238-6bacfe58c833', 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': 4, u'type': u'partition', u'id': 4, u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/4/partition/4'}], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cxwqga', 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'block_size': 4096, u'type': u'physical', u'serial': u'618e72837274f1901cc7889705aa1b02', u'uuid': None}, {u'size': 2397988454400, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/8/', u'used_size': 2397988454400, u'id': 8, u'tags': [], u'filesystem': {u'uuid': u'0d13e400-16f6-480e-b9d2-2cdb9c772093', u'mount_point': u'/', u'mount_options': None, u'fstype': u'ext4', u'label': u'root'}, u'partitions': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cxwqga', 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'block_size': 4096, u'type': u'virtual', u'serial': None, u'uuid': u'd4d37533-fd16-4453-a1d0-f0e103e737ea'}]
2019-05-10 03:34:10,021 [salt.loaded.ext.module.maasng:632 ][INFO    ][17913] vgroot
2019-05-10 03:34:10,022 [salt.loaded.ext.module.maasng:635 ][INFO    ][17913] lvroot
2019-05-10 03:34:10,022 [salt.loaded.ext.module.maasng:639 ][INFO    ][17913] 107374182400
2019-05-10 03:34:10,777 [salt.loaded.ext.module.maasng:645 ][INFO    ][17913] {u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'testing_status_name': u'Passed', u'boot_interface': {u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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': 24, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cxwqga', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/interfaces/5/'}, u'disable_ipv4': False, u'cpu_count': 16, u'power_type': u'ipmi', u'hwe_kernel': u'', u'memory_test_status_name': u'Unknown', u'node_type': 0, u'tag_names': [], u'swap_size': None, u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'status_action': u'', u'zone': {u'id': 1, u'description': u'', u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'current_commissioning_result_id': 4, u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'commissioning_status': 2, u'testing_status': 2, u'system_id': u'cxwqga', u'power_state': u'off', u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u'Power state queried: off', u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/12/', u'type': u'virtual', u'tags': [], u'uuid': u'a3be969e-d80e-42ab-9435-d64df3727e69', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cxwqga', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'e5c50765-7bb0-4642-ad23-9692d7e7ae10', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'partitions': []}], u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/4/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cxwqga', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'uuid': u'f83262a2-ad41-4a09-9fd0-18f752550c14', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/4/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cxwqga', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'8cfd0f15-7eda-42d2-96c8-ced7a08ffe4d', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'size': 2397992648704}]}, {u'size': 107374182400, u'model': None, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/12/', u'type': u'virtual', u'tags': [], u'uuid': u'a3be969e-d80e-42ab-9435-d64df3727e69', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'cxwqga', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'e5c50765-7bb0-4642-ad23-9692d7e7ae10', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'partitions': []}], u'status': 4, u'bcaches': [], u'storage_test_status_name': u'Passed', u'raids': [], u'owner_data': {}, u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'cxwqga', u'id': 7}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/4/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cxwqga', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'uuid': u'f83262a2-ad41-4a09-9fd0-18f752550c14', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/4/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cxwqga', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'8cfd0f15-7eda-42d2-96c8-ced7a08ffe4d', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'size': 2397992648704}]}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'architecture': u'amd64/generic', u'storage_test_status': 2, u'other_test_status': -1, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/4/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'cxwqga', u'partition_table_type': u'GPT', u'filesystem': None, u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 4, u'partitions': [{u'uuid': u'f83262a2-ad41-4a09-9fd0-18f752550c14', u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/blockdevices/4/partition/7', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'cxwqga', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'8cfd0f15-7eda-42d2-96c8-ced7a08ffe4d', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'device_id': 4, u'type': u'partition', u'id': 7, u'size': 2397992648704}]}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'ip_addresses': [u'192.168.11.38'], u'min_hwe_kernel': u'hwe-16.04', u'commissioning_status_name': u'Passed', u'interface_set': [{u'vlan': {u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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': 24, u'mode': u'dhcp'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5a', 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'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'primary_rack': u'6r6fem', u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/', u'id': 5003, u'secondary_rack': None, u'name': u'untagged'}, u'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'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cxwqga', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/interfaces/5/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'name': u'enp9s0', u'links': [{u'id': 26, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5d', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cxwqga', u'type': u'physical', u'id': 15, u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/interfaces/15/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'name': u'enp7s0', u'links': [{u'id': 28, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5b', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cxwqga', u'type': u'physical', u'id': 16, u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/interfaces/16/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/', u'id': 5001, u'secondary_rack': None, u'name': u'untagged'}, u'name': u'enp8s0', u'links': [{u'id': 30, u'mode': u'link_up'}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:5c', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'effective_mtu': 1500, u'params': u'', u'system_id': u'cxwqga', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/cxwqga/interfaces/18/'}], u'address_ttl': None, u'memory_test_status': -1, u'distro_series': u'', u'resource_uri': u'/MAAS/api/2.0/machines/cxwqga/'}
2019-05-10 03:34:10,779 [salt.state       :300 ][INFO    ][17913] {'new': {'storage_layout': 'lvm'}}
2019-05-10 03:34:10,780 [salt.state       :1951][INFO    ][17913] Completed state [maas_machines_storage_cmp001_lvm] at time 03:34:10.780359 duration_in_ms=2988.548
2019-05-10 03:34:10,785 [salt.minion      :1711][INFO    ][17913] Returning information for job: 20190510033400007341
2019-05-10 03:34:11,425 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command state.apply with jid 20190510033411412687
2019-05-10 03:34:11,449 [salt.minion      :1432][INFO    ][17956] Starting a new job with PID 17956
2019-05-10 03:34:12,180 [salt.state       :915 ][INFO    ][17956] Loading fresh modules for state activity
2019-05-10 03:34:12,218 [salt.fileclient  :1219][INFO    ][17956] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-05-10 03:34:12,253 [salt.state       :1780][INFO    ][17956] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:34:12.253024
2019-05-10 03:34:12,253 [salt.state       :1813][INFO    ][17956] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-10 03:34:12,255 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17956] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-10 03:34:13,655 [salt.state       :300 ][INFO    ][17956] {'pid': 17963, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-10 03:34:13,656 [salt.state       :1951][INFO    ][17956] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:34:13.656067 duration_in_ms=1403.043
2019-05-10 03:34:13,657 [salt.state       :1780][INFO    ][17956] Running state [maas.deploy_machines] at time 03:34:13.657161
2019-05-10 03:34:13,657 [salt.state       :1813][INFO    ][17956] Executing state module.run for [maas.deploy_machines]
2019-05-10 03:34:13,658 [salt.utils.decorators:613 ][WARNING ][17956] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:34:14,366 [salt.loaded.ext.module.maas:684 ][INFO    ][17956] deploymachines hwe_kernel=hwe-16.04 system_id=b74m8w distro_series=xenial
2019-05-10 03:34:16,710 [salt.loaded.ext.module.maas:684 ][INFO    ][17956] deploymachines hwe_kernel=hwe-16.04 system_id=cxwqga distro_series=xenial
2019-05-10 03:34:19,393 [salt.loaded.ext.module.maas:684 ][INFO    ][17956] deploymachines hwe_kernel=hwe-16.04 system_id=mt3d3e distro_series=xenial
2019-05-10 03:34:22,082 [salt.loaded.ext.module.maas:684 ][INFO    ][17956] deploymachines hwe_kernel=hwe-16.04 system_id=m8gmta distro_series=xenial
2019-05-10 03:34:24,729 [salt.loaded.ext.module.maas:684 ][INFO    ][17956] deploymachines hwe_kernel=hwe-16.04 system_id=skrcta distro_series=xenial
2019-05-10 03:34:26,456 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033426443546
2019-05-10 03:34:26,478 [salt.minion      :1432][INFO    ][18224] Starting a new job with PID 18224
2019-05-10 03:34:26,500 [salt.minion      :1711][INFO    ][18224] Returning information for job: 20190510033426443546
2019-05-10 03:34:27,148 [salt.state       :300 ][INFO    ][17956] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-05-10 03:34:27,149 [salt.state       :1951][INFO    ][17956] Completed state [maas.deploy_machines] at time 03:34:27.149425 duration_in_ms=13492.262
2019-05-10 03:34:27,152 [salt.minion      :1711][INFO    ][17956] Returning information for job: 20190510033411412687
2019-05-10 03:34:27,794 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command state.apply with jid 20190510033427780998
2019-05-10 03:34:27,819 [salt.minion      :1432][INFO    ][18240] Starting a new job with PID 18240
2019-05-10 03:34:31,529 [salt.state       :915 ][INFO    ][18240] Loading fresh modules for state activity
2019-05-10 03:34:31,581 [salt.fileclient  :1219][INFO    ][18240] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-05-10 03:34:31,618 [salt.state       :1780][INFO    ][18240] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:34:31.617942
2019-05-10 03:34:31,618 [salt.state       :1813][INFO    ][18240] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-05-10 03:34:31,620 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18240] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-05-10 03:34:33,026 [salt.state       :300 ][INFO    ][18240] {'pid': 18255, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-05-10 03:34:33,026 [salt.state       :1951][INFO    ][18240] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:34:33.026454 duration_in_ms=1408.513
2019-05-10 03:34:33,028 [salt.state       :1780][INFO    ][18240] Running state [maas.wait_for_machine_status] at time 03:34:33.028018
2019-05-10 03:34:33,028 [salt.state       :1813][INFO    ][18240] Executing state module.run for [maas.wait_for_machine_status]
2019-05-10 03:34:33,028 [salt.utils.decorators:613 ][WARNING ][18240] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-05-10 03:34:36,081 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.95184803s left)
2019-05-10 03:34:42,811 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033442798962
2019-05-10 03:34:42,836 [salt.minion      :1432][INFO    ][18312] Starting a new job with PID 18312
2019-05-10 03:34:42,858 [salt.minion      :1711][INFO    ][18312] Returning information for job: 20190510033442798962
2019-05-10 03:35:09,914 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.11841917s left)
2019-05-10 03:35:12,861 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033512849081
2019-05-10 03:35:12,886 [salt.minion      :1432][INFO    ][18333] Starting a new job with PID 18333
2019-05-10 03:35:12,909 [salt.minion      :1711][INFO    ][18333] Returning information for job: 20190510033512849081
2019-05-10 03:35:42,954 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033542941757
2019-05-10 03:35:42,978 [salt.minion      :1432][INFO    ][18388] Starting a new job with PID 18388
2019-05-10 03:35:42,999 [salt.minion      :1711][INFO    ][18388] Returning information for job: 20190510033542941757
2019-05-10 03:35:43,531 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.50194097s left)
2019-05-10 03:36:13,001 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033612989000
2019-05-10 03:36:13,019 [salt.minion      :1432][INFO    ][18496] Starting a new job with PID 18496
2019-05-10 03:36:13,040 [salt.minion      :1711][INFO    ][18496] Returning information for job: 20190510033612989000
2019-05-10 03:36:16,621 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2146.41131616s left)
2019-05-10 03:36:43,046 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033643033851
2019-05-10 03:36:43,072 [salt.minion      :1432][INFO    ][19001] Starting a new job with PID 19001
2019-05-10 03:36:43,095 [salt.minion      :1711][INFO    ][19001] Returning information for job: 20190510033643033851
2019-05-10 03:36:49,599 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.43372703s left)
2019-05-10 03:37:13,107 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033713093694
2019-05-10 03:37:13,132 [salt.minion      :1432][INFO    ][19049] Starting a new job with PID 19049
2019-05-10 03:37:13,156 [salt.minion      :1711][INFO    ][19049] Returning information for job: 20190510033713093694
2019-05-10 03:37:23,045 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2079.98799109s left)
2019-05-10 03:37:43,168 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033743155148
2019-05-10 03:37:43,193 [salt.minion      :1432][INFO    ][19569] Starting a new job with PID 19569
2019-05-10 03:37:43,215 [salt.minion      :1711][INFO    ][19569] Returning information for job: 20190510033743155148
2019-05-10 03:37:56,429 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.60376906s left)
2019-05-10 03:38:13,229 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033813217038
2019-05-10 03:38:13,253 [salt.minion      :1432][INFO    ][19589] Starting a new job with PID 19589
2019-05-10 03:38:13,277 [salt.minion      :1711][INFO    ][19589] Returning information for job: 20190510033813217038
2019-05-10 03:38:29,937 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.09539199s left)
2019-05-10 03:38:43,299 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033843286818
2019-05-10 03:38:43,324 [salt.minion      :1432][INFO    ][19725] Starting a new job with PID 19725
2019-05-10 03:38:43,347 [salt.minion      :1711][INFO    ][19725] Returning information for job: 20190510033843286818
2019-05-10 03:39:03,634 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1979.39866614s left)
2019-05-10 03:39:13,370 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033913358314
2019-05-10 03:39:13,395 [salt.minion      :1432][INFO    ][19746] Starting a new job with PID 19746
2019-05-10 03:39:13,417 [salt.minion      :1711][INFO    ][19746] Returning information for job: 20190510033913358314
2019-05-10 03:39:36,178 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.85424113s left)
2019-05-10 03:39:43,445 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510033943433456
2019-05-10 03:39:43,471 [salt.minion      :1432][INFO    ][20302] Starting a new job with PID 20302
2019-05-10 03:39:43,493 [salt.minion      :1711][INFO    ][20302] Returning information for job: 20190510033943433456
2019-05-10 03:40:09,722 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.31055403s left)
2019-05-10 03:40:13,528 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510034013516189
2019-05-10 03:40:13,554 [salt.minion      :1432][INFO    ][20345] Starting a new job with PID 20345
2019-05-10 03:40:13,576 [salt.minion      :1711][INFO    ][20345] Returning information for job: 20190510034013516189
2019-05-10 03:40:42,169 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1880.8634541s left)
2019-05-10 03:40:43,612 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510034043599221
2019-05-10 03:40:43,639 [salt.minion      :1432][INFO    ][20734] Starting a new job with PID 20734
2019-05-10 03:40:43,662 [salt.minion      :1711][INFO    ][20734] Returning information for job: 20190510034043599221
2019-05-10 03:41:13,704 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510034113690714
2019-05-10 03:41:13,728 [salt.minion      :1432][INFO    ][20753] Starting a new job with PID 20753
2019-05-10 03:41:13,751 [salt.minion      :1711][INFO    ][20753] Returning information for job: 20190510034113690714
2019-05-10 03:41:15,319 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1847.71338201s left)
2019-05-10 03:41:43,803 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510034143791128
2019-05-10 03:41:43,826 [salt.minion      :1432][INFO    ][20809] Starting a new job with PID 20809
2019-05-10 03:41:43,846 [salt.minion      :1711][INFO    ][20809] Returning information for job: 20190510034143791128
2019-05-10 03:41:48,905 [salt.loaded.ext.module.maas:1023][INFO    ][18240] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1814.12723613s left)
2019-05-10 03:42:13,911 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command saltutil.find_job with jid 20190510034213898246
2019-05-10 03:42:13,939 [salt.minion      :1432][INFO    ][20945] Starting a new job with PID 20945
2019-05-10 03:42:13,960 [salt.minion      :1711][INFO    ][20945] Returning information for job: 20190510034213898246
2019-05-10 03:42:22,412 [salt.state       :300 ][INFO    ][18240] {'ret': True}
2019-05-10 03:42:22,412 [salt.state       :1951][INFO    ][18240] Completed state [maas.wait_for_machine_status] at time 03:42:22.412436 duration_in_ms=469384.416
2019-05-10 03:42:22,416 [salt.minion      :1711][INFO    ][18240] Returning information for job: 20190510033427780998
2019-05-10 04:19:25,181 [salt.utils.schedule:1377][INFO    ][13778] Running scheduled job: __mine_interval
2019-05-10 05:11:31,119 [salt.minion      :1308][INFO    ][13778] User sudo_ubuntu Executing command cp.push_dir with jid 20190510051131113286
2019-05-10 05:11:31,140 [salt.minion      :1432][INFO    ][27432] Starting a new job with PID 27432
