2019-06-04 02:08:01,907 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 02:08:51,959 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 02:09:42,008 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 02:10:32,053 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 02:11:22,098 [salt.minion      :870 ][ERROR   ][364] Error while bringing up minion for multi-master. Is master at 10.20.0.2 responding?
2019-06-04 02:13:31,349 [salt.utils.decorators:613 ][WARNING ][2834] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 02:13:31,950 [salt.utils.decorators:613 ][WARNING ][2834] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 02:13:34,003 [salt.loaded.int.states.file:2298][WARNING ][2983] 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-06-04 02:13:39,225 [salt.state       :2022][WARNING ][3082] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-04 02:13:41,869 [salt.utils.decorators:613 ][WARNING ][3082] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 02:28:54,400 [salt.utils.decorators:613 ][WARNING ][3082] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 02:57:36,222 [salt.utils.decorators:613 ][WARNING ][3082] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:12:39,866 [salt.utils.decorators:613 ][WARNING ][3082] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:12:43,884 [salt.loaded.ext.module.maasng:1008][WARNING ][3082] Detected cidr:192.168.11.0/24 in fabric:fabric-2
2019-06-04 03:12:43,884 [salt.loaded.ext.module.maasng:1011][WARNING ][3082] Guessing, that fabric with current name:fabric-2
 should be renamed to:pxe_admin
2019-06-04 03:12:44,579 [salt.loaded.ext.module.maasng:1235][WARNING ][3082] Ignoring parameter vlan:0
2019-06-04 03:12:51,336 [salt.utils.decorators:613 ][WARNING ][14101] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:12:51,404 [salt.loaded.ext.module.maas:412 ][WARNING ][14101] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:12:55,240 [salt.loaded.ext.module.maas:412 ][WARNING ][14101] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:12:59,789 [salt.loaded.ext.module.maas:412 ][WARNING ][14101] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:13:03,639 [salt.loaded.ext.module.maas:412 ][WARNING ][14101] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:13:08,035 [salt.loaded.ext.module.maas:412 ][WARNING ][14101] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:13:14,958 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15052] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-04 03:13:14,990 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15052] Executing command ['systemd-run', '--scope', 'systemctl', 'restart', 'salt-minion.service'] in directory '/root'
2019-06-04 03:13:15,014 [salt.utils.parsers:1051][WARNING ][364] Minion received a SIGTERM. Exiting.
2019-06-04 03:13:16,087 [salt.cli.daemons :293 ][INFO    ][15098] Setting up the Salt Minion "mas01.mcp-odl-ha.local"
2019-06-04 03:13:16,188 [salt.cli.daemons :82  ][INFO    ][15098] Starting up the Salt Minion
2019-06-04 03:13:16,188 [salt.utils.event :1017][INFO    ][15098] Starting pull socket on /var/run/salt/minion/minion_event_3e82045771_pull.ipc
2019-06-04 03:13:17,057 [salt.minion      :976 ][INFO    ][15098] Creating minion process manager
2019-06-04 03:13:18,448 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][15098] Executing command ['date', '+%z'] in directory '/root'
2019-06-04 03:13:18,466 [salt.utils.schedule:568 ][INFO    ][15098] Updating job settings for scheduled job: __mine_interval
2019-06-04 03:13:18,467 [salt.minion      :1108][INFO    ][15098] Added mine.update to scheduler
2019-06-04 03:13:18,471 [salt.minion      :1975][INFO    ][15098] Minion is starting as user 'root'
2019-06-04 03:13:18,480 [salt.minion      :2336][INFO    ][15098] Minion is ready to receive requests!
2019-06-04 03:13:43,360 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command state.apply with jid 20190604031343347039
2019-06-04 03:13:43,382 [salt.minion      :1432][INFO    ][15246] Starting a new job with PID 15246
2019-06-04 03:13:46,878 [salt.state       :915 ][INFO    ][15246] Loading fresh modules for state activity
2019-06-04 03:13:46,907 [salt.fileclient  :1219][INFO    ][15246] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_ready_or_deployed.sls'
2019-06-04 03:13:46,933 [salt.state       :1780][INFO    ][15246] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:13:46.933554
2019-06-04 03:13:46,933 [salt.state       :1813][INFO    ][15246] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 03:13:46,935 [salt.loaded.int.module.cmdmod:395 ][INFO    ][15246] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 03:13:48,239 [salt.state       :300 ][INFO    ][15246] {'pid': 15273, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 03:13:48,239 [salt.state       :1951][INFO    ][15246] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:13:48.239804 duration_in_ms=1306.25
2019-06-04 03:13:48,240 [salt.state       :1780][INFO    ][15246] Running state [maas.wait_for_machine_status] at time 03:13:48.240853
2019-06-04 03:13:48,241 [salt.state       :1813][INFO    ][15246] Executing state module.run for [maas.wait_for_machine_status]
2019-06-04 03:13:48,241 [salt.utils.decorators:613 ][WARNING ][15246] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:13:49,025 [salt.loaded.ext.module.maas:1023][INFO    ][15246] Waiting status:Ready|Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:1500s (1499.22019815s left)
2019-06-04 03:13:58,396 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031358383535
2019-06-04 03:13:58,417 [salt.minion      :1432][INFO    ][15482] Starting a new job with PID 15482
2019-06-04 03:13:58,436 [salt.minion      :1711][INFO    ][15482] Returning information for job: 20190604031358383535
2019-06-04 03:14:28,467 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031428454701
2019-06-04 03:14:28,490 [salt.minion      :1432][INFO    ][15538] Starting a new job with PID 15538
2019-06-04 03:14:28,513 [salt.minion      :1711][INFO    ][15538] Returning information for job: 20190604031428454701
2019-06-04 03:14:58,580 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031458567705
2019-06-04 03:14:58,602 [salt.minion      :1432][INFO    ][15758] Starting a new job with PID 15758
2019-06-04 03:14:58,625 [salt.minion      :1711][INFO    ][15758] Returning information for job: 20190604031458567705
2019-06-04 03:15:28,645 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031528635374
2019-06-04 03:15:28,660 [salt.minion      :1432][INFO    ][15858] Starting a new job with PID 15858
2019-06-04 03:15:28,671 [salt.minion      :1711][INFO    ][15858] Returning information for job: 20190604031528635374
2019-06-04 03:15:58,690 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031558676786
2019-06-04 03:15:58,711 [salt.minion      :1432][INFO    ][16048] Starting a new job with PID 16048
2019-06-04 03:15:58,733 [salt.minion      :1711][INFO    ][16048] Returning information for job: 20190604031558676786
2019-06-04 03:16:28,761 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031628749705
2019-06-04 03:16:28,783 [salt.minion      :1432][INFO    ][16094] Starting a new job with PID 16094
2019-06-04 03:16:28,809 [salt.minion      :1711][INFO    ][16094] Returning information for job: 20190604031628749705
2019-06-04 03:16:58,840 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031658828383
2019-06-04 03:16:58,864 [salt.minion      :1432][INFO    ][16311] Starting a new job with PID 16311
2019-06-04 03:16:58,887 [salt.minion      :1711][INFO    ][16311] Returning information for job: 20190604031658828383
2019-06-04 03:17:28,925 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031728913100
2019-06-04 03:17:28,944 [salt.minion      :1432][INFO    ][16379] Starting a new job with PID 16379
2019-06-04 03:17:28,963 [salt.minion      :1711][INFO    ][16379] Returning information for job: 20190604031728913100
2019-06-04 03:17:59,011 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031758995960
2019-06-04 03:17:59,031 [salt.minion      :1432][INFO    ][16430] Starting a new job with PID 16430
2019-06-04 03:17:59,052 [salt.minion      :1711][INFO    ][16430] Returning information for job: 20190604031758995960
2019-06-04 03:18:29,101 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031829088370
2019-06-04 03:18:29,122 [salt.minion      :1432][INFO    ][16465] Starting a new job with PID 16465
2019-06-04 03:18:29,144 [salt.minion      :1711][INFO    ][16465] Returning information for job: 20190604031829088370
2019-06-04 03:18:59,186 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031859177447
2019-06-04 03:18:59,204 [salt.minion      :1432][INFO    ][16515] Starting a new job with PID 16515
2019-06-04 03:18:59,220 [salt.minion      :1711][INFO    ][16515] Returning information for job: 20190604031859177447
2019-06-04 03:19:29,272 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604031929260010
2019-06-04 03:19:29,294 [salt.minion      :1432][INFO    ][16536] Starting a new job with PID 16536
2019-06-04 03:19:29,314 [salt.minion      :1711][INFO    ][16536] Returning information for job: 20190604031929260010
2019-06-04 03:19:55,821 [salt.state       :302 ][ERROR   ][15246] Module function maas.wait_for_machine_status threw an exception. Exception: HTTP Error 401: OK
2019-06-04 03:19:55,822 [salt.state       :1951][INFO    ][15246] Completed state [maas.wait_for_machine_status] at time 03:19:55.822135 duration_in_ms=367581.279
2019-06-04 03:19:55,825 [salt.minion      :1711][INFO    ][15246] Returning information for job: 20190604031343347039
2019-06-04 03:20:06,607 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command pillar.get with jid 20190604032006601199
2019-06-04 03:20:06,628 [salt.minion      :1432][INFO    ][16840] Starting a new job with PID 16840
2019-06-04 03:20:06,633 [salt.minion      :1711][INFO    ][16840] Returning information for job: 20190604032006601199
2019-06-04 03:20:07,120 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command service.status with jid 20190604032007111688
2019-06-04 03:20:07,135 [salt.minion      :1432][INFO    ][16847] Starting a new job with PID 16847
2019-06-04 03:20:07,506 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][16847] Executing command ['systemctl', 'status', 'maas-fixup.service', '-n', '0'] in directory '/root'
2019-06-04 03:20:07,540 [salt.loader.10.20.0.2.int.module.cmdmod:395 ][INFO    ][16847] Executing command ['systemctl', 'is-active', 'maas-fixup.service'] in directory '/root'
2019-06-04 03:20:07,556 [salt.minion      :1711][INFO    ][16847] Returning information for job: 20190604032007111688
2019-06-04 03:20:08,067 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command state.apply with jid 20190604032008054894
2019-06-04 03:20:08,086 [salt.minion      :1432][INFO    ][16865] Starting a new job with PID 16865
2019-06-04 03:20:11,877 [salt.state       :915 ][INFO    ][16865] Loading fresh modules for state activity
2019-06-04 03:20:12,332 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command 'salt-minion --version' in directory '/root'
2019-06-04 03:20:12,706 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command 'salt-minion --version' in directory '/root'
2019-06-04 03:20:13,487 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command 'salt-minion --version' in directory '/root'
2019-06-04 03:20:13,832 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command 'salt-minion --version' in directory '/root'
2019-06-04 03:20:15,220 [salt.state       :1780][INFO    ][16865] Running state [salt-minion] at time 03:20:15.220515
2019-06-04 03:20:15,220 [salt.state       :1813][INFO    ][16865] Executing state pkg.installed for [salt-minion]
2019-06-04 03:20:15,221 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-04 03:20:15,308 [salt.state       :300 ][INFO    ][16865] All specified packages are already installed
2019-06-04 03:20:15,309 [salt.state       :1951][INFO    ][16865] Completed state [salt-minion] at time 03:20:15.309179 duration_in_ms=88.664
2019-06-04 03:20:15,309 [salt.state       :1780][INFO    ][16865] Running state [salt_minion_dependency_packages] at time 03:20:15.309467
2019-06-04 03:20:15,309 [salt.state       :1813][INFO    ][16865] Executing state pkg.installed for [salt_minion_dependency_packages]
2019-06-04 03:20:15,315 [salt.state       :300 ][INFO    ][16865] All specified packages are already installed
2019-06-04 03:20:15,315 [salt.state       :1951][INFO    ][16865] Completed state [salt_minion_dependency_packages] at time 03:20:15.315612 duration_in_ms=6.144
2019-06-04 03:20:15,318 [salt.state       :1780][INFO    ][16865] Running state [/etc/salt/minion.d/minion.conf] at time 03:20:15.318360
2019-06-04 03:20:15,318 [salt.state       :1813][INFO    ][16865] Executing state file.managed for [/etc/salt/minion.d/minion.conf]
2019-06-04 03:20:15,503 [salt.state       :300 ][INFO    ][16865] File /etc/salt/minion.d/minion.conf is in the correct state
2019-06-04 03:20:15,504 [salt.state       :1951][INFO    ][16865] Completed state [/etc/salt/minion.d/minion.conf] at time 03:20:15.503976 duration_in_ms=185.616
2019-06-04 03:20:15,504 [salt.state       :1780][INFO    ][16865] Running state [python-netaddr] at time 03:20:15.504156
2019-06-04 03:20:15,504 [salt.state       :1813][INFO    ][16865] Executing state pkg.installed for [python-netaddr]
2019-06-04 03:20:15,508 [salt.state       :300 ][INFO    ][16865] All specified packages are already installed
2019-06-04 03:20:15,508 [salt.state       :1951][INFO    ][16865] Completed state [python-netaddr] at time 03:20:15.508887 duration_in_ms=4.73
2019-06-04 03:20:15,510 [salt.state       :1780][INFO    ][16865] Running state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:20:15.510946
2019-06-04 03:20:15,511 [salt.state       :1813][INFO    ][16865] Executing state file.managed for [/etc/systemd/system/salt-minion.service.d/50-restarts.conf]
2019-06-04 03:20:15,520 [salt.state       :300 ][INFO    ][16865] File /etc/systemd/system/salt-minion.service.d/50-restarts.conf is in the correct state
2019-06-04 03:20:15,520 [salt.state       :1951][INFO    ][16865] Completed state [/etc/systemd/system/salt-minion.service.d/50-restarts.conf] at time 03:20:15.520367 duration_in_ms=9.42
2019-06-04 03:20:15,521 [salt.state       :1780][INFO    ][16865] Running state [salt-minion] at time 03:20:15.521036
2019-06-04 03:20:15,521 [salt.state       :1813][INFO    ][16865] Executing state service.running for [salt-minion]
2019-06-04 03:20:15,521 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command ['systemctl', 'status', 'salt-minion.service', '-n', '0'] in directory '/root'
2019-06-04 03:20:15,556 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command ['systemctl', 'is-active', 'salt-minion.service'] in directory '/root'
2019-06-04 03:20:15,573 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command ['systemctl', 'is-enabled', 'salt-minion.service'] in directory '/root'
2019-06-04 03:20:15,589 [salt.state       :300 ][INFO    ][16865] The service salt-minion is already running
2019-06-04 03:20:15,589 [salt.state       :1951][INFO    ][16865] Completed state [salt-minion] at time 03:20:15.589695 duration_in_ms=68.657
2019-06-04 03:20:15,591 [salt.state       :1780][INFO    ][16865] Running state [/etc/salt/grains.d] at time 03:20:15.591103
2019-06-04 03:20:15,591 [salt.state       :1813][INFO    ][16865] Executing state file.directory for [/etc/salt/grains.d]
2019-06-04 03:20:15,592 [salt.state       :300 ][INFO    ][16865] Directory /etc/salt/grains.d is in the correct state
Directory /etc/salt/grains.d updated
2019-06-04 03:20:15,592 [salt.state       :1951][INFO    ][16865] Completed state [/etc/salt/grains.d] at time 03:20:15.592516 duration_in_ms=1.413
2019-06-04 03:20:15,593 [salt.state       :1780][INFO    ][16865] Running state [/etc/salt/grains] at time 03:20:15.593134
2019-06-04 03:20:15,593 [salt.state       :1813][INFO    ][16865] Executing state file.managed for [/etc/salt/grains]
2019-06-04 03:20:15,593 [salt.state       :300 ][INFO    ][16865] File /etc/salt/grains exists with proper permissions. No changes made.
2019-06-04 03:20:15,594 [salt.state       :1951][INFO    ][16865] Completed state [/etc/salt/grains] at time 03:20:15.594140 duration_in_ms=1.006
2019-06-04 03:20:15,594 [salt.state       :1780][INFO    ][16865] Running state [/etc/salt/grains.d/placeholder] at time 03:20:15.594582
2019-06-04 03:20:15,594 [salt.state       :1813][INFO    ][16865] Executing state file.managed for [/etc/salt/grains.d/placeholder]
2019-06-04 03:20:15,595 [salt.state       :300 ][INFO    ][16865] File /etc/salt/grains.d/placeholder exists with proper permissions. No changes made.
2019-06-04 03:20:15,595 [salt.state       :1951][INFO    ][16865] Completed state [/etc/salt/grains.d/placeholder] at time 03:20:15.595540 duration_in_ms=0.958
2019-06-04 03:20:15,596 [salt.state       :1780][INFO    ][16865] Running state [/etc/salt/grains.d/sphinx] at time 03:20:15.595965
2019-06-04 03:20:15,596 [salt.state       :1813][INFO    ][16865] Executing state file.managed for [/etc/salt/grains.d/sphinx]
2019-06-04 03:20:15,611 [salt.state       :300 ][INFO    ][16865] File /etc/salt/grains.d/sphinx is in the correct state
2019-06-04 03:20:15,612 [salt.state       :1951][INFO    ][16865] Completed state [/etc/salt/grains.d/sphinx] at time 03:20:15.612167 duration_in_ms=16.201
2019-06-04 03:20:15,615 [salt.state       :1780][INFO    ][16865] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:20:15.615576
2019-06-04 03:20:15,616 [salt.state       :1813][INFO    ][16865] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"]
2019-06-04 03:20:15,616 [salt.state       :300 ][INFO    ][16865] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"
2019-06-04 03:20:15,616 [salt.state       :1951][INFO    ][16865] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/sphinx', 'r'); yaml.load(stream); stream.close()"] at time 03:20:15.616904 duration_in_ms=1.329
2019-06-04 03:20:15,617 [salt.state       :1780][INFO    ][16865] Running state [/etc/salt/grains.d/dns_records] at time 03:20:15.617675
2019-06-04 03:20:15,618 [salt.state       :1813][INFO    ][16865] Executing state file.managed for [/etc/salt/grains.d/dns_records]
2019-06-04 03:20:15,629 [salt.state       :300 ][INFO    ][16865] File /etc/salt/grains.d/dns_records is in the correct state
2019-06-04 03:20:15,629 [salt.state       :1951][INFO    ][16865] Completed state [/etc/salt/grains.d/dns_records] at time 03:20:15.629870 duration_in_ms=12.194
2019-06-04 03:20:15,631 [salt.state       :1780][INFO    ][16865] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:20:15.631264
2019-06-04 03:20:15,631 [salt.state       :1813][INFO    ][16865] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"]
2019-06-04 03:20:15,632 [salt.state       :300 ][INFO    ][16865] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"
2019-06-04 03:20:15,632 [salt.state       :1951][INFO    ][16865] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/dns_records', 'r'); yaml.load(stream); stream.close()"] at time 03:20:15.632547 duration_in_ms=1.284
2019-06-04 03:20:15,633 [salt.state       :1780][INFO    ][16865] Running state [/etc/salt/grains.d/salt] at time 03:20:15.633252
2019-06-04 03:20:15,633 [salt.state       :1813][INFO    ][16865] Executing state file.managed for [/etc/salt/grains.d/salt]
2019-06-04 03:20:15,647 [salt.state       :300 ][INFO    ][16865] File /etc/salt/grains.d/salt is in the correct state
2019-06-04 03:20:15,648 [salt.state       :1951][INFO    ][16865] Completed state [/etc/salt/grains.d/salt] at time 03:20:15.647938 duration_in_ms=14.685
2019-06-04 03:20:15,649 [salt.state       :1780][INFO    ][16865] Running state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:20:15.649266
2019-06-04 03:20:15,649 [salt.state       :1813][INFO    ][16865] Executing state cmd.wait for [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"]
2019-06-04 03:20:15,650 [salt.state       :300 ][INFO    ][16865] No changes made for python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"
2019-06-04 03:20:15,650 [salt.state       :1951][INFO    ][16865] Completed state [python -c "import yaml; stream = file('/etc/salt/grains.d/salt', 'r'); yaml.load(stream); stream.close()"] at time 03:20:15.650523 duration_in_ms=1.256
2019-06-04 03:20:15,653 [salt.state       :1780][INFO    ][16865] Running state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:20:15.653399
2019-06-04 03:20:15,653 [salt.state       :1813][INFO    ][16865] Executing state cmd.wait for [cat /etc/salt/grains.d/* > /etc/salt/grains]
2019-06-04 03:20:15,654 [salt.state       :300 ][INFO    ][16865] No changes made for cat /etc/salt/grains.d/* > /etc/salt/grains
2019-06-04 03:20:15,654 [salt.state       :1951][INFO    ][16865] Completed state [cat /etc/salt/grains.d/* > /etc/salt/grains] at time 03:20:15.654671 duration_in_ms=1.271
2019-06-04 03:20:15,655 [salt.state       :1780][INFO    ][16865] Running state [mine.update] at time 03:20:15.655685
2019-06-04 03:20:15,656 [salt.state       :1813][INFO    ][16865] Executing state module.wait for [mine.update]
2019-06-04 03:20:15,656 [salt.state       :300 ][INFO    ][16865] No changes made for mine.update
2019-06-04 03:20:15,656 [salt.state       :1951][INFO    ][16865] Completed state [mine.update] at time 03:20:15.656853 duration_in_ms=1.168
2019-06-04 03:20:15,657 [salt.state       :1780][INFO    ][16865] Running state [ca-certificates] at time 03:20:15.657217
2019-06-04 03:20:15,657 [salt.state       :1813][INFO    ][16865] Executing state pkg.installed for [ca-certificates]
2019-06-04 03:20:15,668 [salt.state       :300 ][INFO    ][16865] All specified packages are already installed
2019-06-04 03:20:15,668 [salt.state       :1951][INFO    ][16865] Completed state [ca-certificates] at time 03:20:15.668840 duration_in_ms=11.623
2019-06-04 03:20:15,669 [salt.state       :1780][INFO    ][16865] Running state [update-ca-certificates] at time 03:20:15.669839
2019-06-04 03:20:15,670 [salt.state       :1813][INFO    ][16865] Executing state cmd.wait for [update-ca-certificates]
2019-06-04 03:20:15,670 [salt.state       :300 ][INFO    ][16865] No changes made for update-ca-certificates
2019-06-04 03:20:15,671 [salt.state       :1951][INFO    ][16865] Completed state [update-ca-certificates] at time 03:20:15.670995 duration_in_ms=1.155
2019-06-04 03:20:15,671 [salt.state       :1780][INFO    ][16865] Running state [iptables] at time 03:20:15.671342
2019-06-04 03:20:15,671 [salt.state       :1813][INFO    ][16865] Executing state pkg.installed for [iptables]
2019-06-04 03:20:15,681 [salt.state       :300 ][INFO    ][16865] All specified packages are already installed
2019-06-04 03:20:15,681 [salt.state       :1951][INFO    ][16865] Completed state [iptables] at time 03:20:15.681511 duration_in_ms=10.169
2019-06-04 03:20:15,681 [salt.state       :1780][INFO    ][16865] Running state [iptables-persistent] at time 03:20:15.681851
2019-06-04 03:20:15,682 [salt.state       :1813][INFO    ][16865] Executing state pkg.installed for [iptables-persistent]
2019-06-04 03:20:15,691 [salt.state       :300 ][INFO    ][16865] All specified packages are already installed
2019-06-04 03:20:15,691 [salt.state       :1951][INFO    ][16865] Completed state [iptables-persistent] at time 03:20:15.691628 duration_in_ms=9.777
2019-06-04 03:20:15,693 [salt.state       :1780][INFO    ][16865] Running state [iptables_modules_v4_load] at time 03:20:15.692957
2019-06-04 03:20:15,693 [salt.state       :1813][INFO    ][16865] Executing state kmod.present for [iptables_modules_v4_load]
2019-06-04 03:20:15,694 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command 'lsmod' in directory '/root'
2019-06-04 03:20:15,715 [salt.state       :300 ][INFO    ][16865] Kernel modules iptable_filter, ip_tables are already present
2019-06-04 03:20:15,716 [salt.state       :1951][INFO    ][16865] Completed state [iptables_modules_v4_load] at time 03:20:15.716297 duration_in_ms=23.341
2019-06-04 03:20:15,717 [salt.state       :1780][INFO    ][16865] Running state [/etc/iptables/rules.v4] at time 03:20:15.717127
2019-06-04 03:20:15,717 [salt.state       :1813][INFO    ][16865] Executing state file.managed for [/etc/iptables/rules.v4]
2019-06-04 03:20:15,821 [salt.state       :300 ][INFO    ][16865] File /etc/iptables/rules.v4 is in the correct state
2019-06-04 03:20:15,821 [salt.state       :1951][INFO    ][16865] Completed state [/etc/iptables/rules.v4] at time 03:20:15.821686 duration_in_ms=104.559
2019-06-04 03:20:15,822 [salt.state       :1780][INFO    ][16865] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:20:15.822812
2019-06-04 03:20:15,823 [salt.state       :1813][INFO    ][16865] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;]
2019-06-04 03:20:15,823 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command 'test $(iptables-save | wc -l) -eq 0' in directory '/root'
2019-06-04 03:20:15,844 [salt.state       :300 ][INFO    ][16865] onlyif execution failed
2019-06-04 03:20:15,844 [salt.state       :1951][INFO    ][16865] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip4tables -exec {} start \;] at time 03:20:15.844751 duration_in_ms=21.939
2019-06-04 03:20:15,845 [salt.state       :1780][INFO    ][16865] Running state [netfilter-persistent] at time 03:20:15.845821
2019-06-04 03:20:15,846 [salt.state       :1813][INFO    ][16865] Executing state service.running for [netfilter-persistent]
2019-06-04 03:20:15,847 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command ['systemctl', 'status', 'netfilter-persistent.service', '-n', '0'] in directory '/root'
2019-06-04 03:20:15,866 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command ['systemctl', 'is-active', 'netfilter-persistent.service'] in directory '/root'
2019-06-04 03:20:15,884 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command ['systemctl', 'is-enabled', 'netfilter-persistent.service'] in directory '/root'
2019-06-04 03:20:15,902 [salt.state       :300 ][INFO    ][16865] The service netfilter-persistent is already running
2019-06-04 03:20:15,902 [salt.state       :1951][INFO    ][16865] Completed state [netfilter-persistent] at time 03:20:15.902854 duration_in_ms=57.033
2019-06-04 03:20:15,904 [salt.state       :1780][INFO    ][16865] Running state [iptables_extra.remove_stale_tables] at time 03:20:15.904173
2019-06-04 03:20:15,904 [salt.state       :1813][INFO    ][16865] Executing state module.wait for [iptables_extra.remove_stale_tables]
2019-06-04 03:20:15,905 [salt.state       :300 ][INFO    ][16865] No changes made for iptables_extra.remove_stale_tables
2019-06-04 03:20:15,905 [salt.state       :1951][INFO    ][16865] Completed state [iptables_extra.remove_stale_tables] at time 03:20:15.905552 duration_in_ms=1.379
2019-06-04 03:20:15,905 [salt.state       :1780][INFO    ][16865] Running state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:20:15.905936
2019-06-04 03:20:15,906 [salt.state       :1813][INFO    ][16865] Executing state cmd.run for [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;]
2019-06-04 03:20:15,907 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16865] Executing command 'test $(which ip6tables-save) -eq 0 && test $(ip6tables-save | wc -l) -ne 0' in directory '/root'
2019-06-04 03:20:15,922 [salt.state       :300 ][INFO    ][16865] onlyif execution failed
2019-06-04 03:20:15,923 [salt.state       :1951][INFO    ][16865] Completed state [find /usr/share/netfilter-persistent/plugins.d/[0-9]*-ip6tables -exec {} flush \;] at time 03:20:15.922999 duration_in_ms=17.063
2019-06-04 03:20:15,924 [salt.state       :1780][INFO    ][16865] Running state [/etc/iptables/rules.v6] at time 03:20:15.924255
2019-06-04 03:20:15,924 [salt.state       :1813][INFO    ][16865] Executing state file.absent for [/etc/iptables/rules.v6]
2019-06-04 03:20:15,925 [salt.state       :300 ][INFO    ][16865] File /etc/iptables/rules.v6 is not present
2019-06-04 03:20:15,925 [salt.state       :1951][INFO    ][16865] Completed state [/etc/iptables/rules.v6] at time 03:20:15.925600 duration_in_ms=1.345
2019-06-04 03:20:15,926 [salt.state       :1780][INFO    ][16865] Running state [iptables_extra.flush_all] at time 03:20:15.926500
2019-06-04 03:20:15,926 [salt.state       :1813][INFO    ][16865] Executing state module.wait for [iptables_extra.flush_all]
2019-06-04 03:20:15,927 [salt.state       :300 ][INFO    ][16865] No changes made for iptables_extra.flush_all
2019-06-04 03:20:15,927 [salt.state       :1951][INFO    ][16865] Completed state [iptables_extra.flush_all] at time 03:20:15.927561 duration_in_ms=1.061
2019-06-04 03:20:15,931 [salt.minion      :1711][INFO    ][16865] Returning information for job: 20190604032008054894
2019-06-04 03:20:16,520 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command state.apply with jid 20190604032016507949
2019-06-04 03:20:16,542 [salt.minion      :1432][INFO    ][16958] Starting a new job with PID 16958
2019-06-04 03:20:17,311 [salt.state       :915 ][INFO    ][16958] Loading fresh modules for state activity
2019-06-04 03:20:17,929 [salt.state       :1780][INFO    ][16958] Running state [maas-rack-controller] at time 03:20:17.929795
2019-06-04 03:20:17,930 [salt.state       :1813][INFO    ][16958] Executing state pkg.installed for [maas-rack-controller]
2019-06-04 03:20:17,930 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16958] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-04 03:20:18,001 [salt.state       :300 ][INFO    ][16958] All specified packages are already installed
2019-06-04 03:20:18,002 [salt.state       :1951][INFO    ][16958] Completed state [maas-rack-controller] at time 03:20:18.002066 duration_in_ms=72.27
2019-06-04 03:20:18,002 [salt.state       :1780][INFO    ][16958] Running state [ipmitool] at time 03:20:18.002324
2019-06-04 03:20:18,002 [salt.state       :1813][INFO    ][16958] Executing state pkg.installed for [ipmitool]
2019-06-04 03:20:18,007 [salt.state       :300 ][INFO    ][16958] All specified packages are already installed
2019-06-04 03:20:18,007 [salt.state       :1951][INFO    ][16958] Completed state [ipmitool] at time 03:20:18.007248 duration_in_ms=4.924
2019-06-04 03:20:18,009 [salt.state       :1780][INFO    ][16958] Running state [/etc/maas/rackd.conf] at time 03:20:18.009480
2019-06-04 03:20:18,009 [salt.state       :1813][INFO    ][16958] Executing state file.line for [/etc/maas/rackd.conf]
2019-06-04 03:20:18,010 [salt.state       :300 ][INFO    ][16958] No changes needed to be made
2019-06-04 03:20:18,010 [salt.state       :1951][INFO    ][16958] Completed state [/etc/maas/rackd.conf] at time 03:20:18.010633 duration_in_ms=1.152
2019-06-04 03:20:18,010 [salt.state       :1780][INFO    ][16958] Running state [/etc/maas/rackd.conf] at time 03:20:18.010804
2019-06-04 03:20:18,011 [salt.state       :1813][INFO    ][16958] Executing state file.managed for [/etc/maas/rackd.conf]
2019-06-04 03:20:18,011 [salt.loaded.int.states.file:2298][WARNING ][16958] 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-06-04 03:20:18,011 [salt.state       :300 ][INFO    ][16958] File /etc/maas/rackd.conf exists with proper permissions. No changes made.
2019-06-04 03:20:18,011 [salt.state       :1951][INFO    ][16958] Completed state [/etc/maas/rackd.conf] at time 03:20:18.011760 duration_in_ms=0.957
2019-06-04 03:20:18,012 [salt.state       :1780][INFO    ][16958] Running state [maas-rackd] at time 03:20:18.012468
2019-06-04 03:20:18,012 [salt.state       :1813][INFO    ][16958] Executing state service.running for [maas-rackd]
2019-06-04 03:20:18,013 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16958] Executing command ['systemctl', 'status', 'maas-rackd.service', '-n', '0'] in directory '/root'
2019-06-04 03:20:18,043 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16958] Executing command ['systemctl', 'is-active', 'maas-rackd.service'] in directory '/root'
2019-06-04 03:20:18,058 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16958] Executing command ['systemctl', 'is-enabled', 'maas-rackd.service'] in directory '/root'
2019-06-04 03:20:18,075 [salt.state       :300 ][INFO    ][16958] The service maas-rackd is already running
2019-06-04 03:20:18,075 [salt.state       :1951][INFO    ][16958] Completed state [maas-rackd] at time 03:20:18.075555 duration_in_ms=63.086
2019-06-04 03:20:18,077 [salt.minion      :1711][INFO    ][16958] Returning information for job: 20190604032016507949
2019-06-04 03:20:18,638 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command state.apply with jid 20190604032018626873
2019-06-04 03:20:18,659 [salt.minion      :1432][INFO    ][16990] Starting a new job with PID 16990
2019-06-04 03:20:19,398 [salt.state       :915 ][INFO    ][16990] Loading fresh modules for state activity
2019-06-04 03:20:20,112 [salt.state       :1780][INFO    ][16990] Running state [maas-region-controller] at time 03:20:20.111955
2019-06-04 03:20:20,112 [salt.state       :1813][INFO    ][16990] Executing state pkg.installed for [maas-region-controller]
2019-06-04 03:20:20,112 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['dpkg-query', '--showformat', '${Status} ${Package} ${Version} ${Architecture}', '-W'] in directory '/root'
2019-06-04 03:20:20,210 [salt.state       :300 ][INFO    ][16990] All specified packages are already installed
2019-06-04 03:20:20,210 [salt.state       :1951][INFO    ][16990] Completed state [maas-region-controller] at time 03:20:20.210818 duration_in_ms=98.863
2019-06-04 03:20:20,211 [salt.state       :1780][INFO    ][16990] Running state [python-oauth] at time 03:20:20.211260
2019-06-04 03:20:20,211 [salt.state       :1813][INFO    ][16990] Executing state pkg.installed for [python-oauth]
2019-06-04 03:20:20,218 [salt.state       :300 ][INFO    ][16990] All specified packages are already installed
2019-06-04 03:20:20,218 [salt.state       :1951][INFO    ][16990] Completed state [python-oauth] at time 03:20:20.218461 duration_in_ms=7.201
2019-06-04 03:20:20,221 [salt.state       :1780][INFO    ][16990] Running state [/etc/maas/regiond.conf] at time 03:20:20.221241
2019-06-04 03:20:20,221 [salt.state       :1813][INFO    ][16990] Executing state file.replace for [/etc/maas/regiond.conf]
2019-06-04 03:20:20,283 [salt.state       :300 ][INFO    ][16990] No changes needed to be made
2019-06-04 03:20:20,283 [salt.state       :1951][INFO    ][16990] Completed state [/etc/maas/regiond.conf] at time 03:20:20.283803 duration_in_ms=62.562
2019-06-04 03:20:20,284 [salt.state       :1780][INFO    ][16990] Running state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:20:20.284369
2019-06-04 03:20:20,284 [salt.state       :1813][INFO    ][16990] Executing state file.managed for [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template]
2019-06-04 03:20:20,354 [salt.state       :300 ][INFO    ][16990] File /usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template is in the correct state
2019-06-04 03:20:20,354 [salt.state       :1951][INFO    ][16990] Completed state [/usr/lib/python3/dist-packages/provisioningserver/templates/proxy/maas-proxy.conf.template] at time 03:20:20.354706 duration_in_ms=70.337
2019-06-04 03:20:20,355 [salt.state       :1780][INFO    ][16990] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:20:20.355224
2019-06-04 03:20:20,355 [salt.state       :1813][INFO    ][16990] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-04 03:20:20,367 [salt.state       :300 ][INFO    ][16990] No changes needed to be made
2019-06-04 03:20:20,368 [salt.state       :1951][INFO    ][16990] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:20:20.368023 duration_in_ms=12.799
2019-06-04 03:20:20,368 [salt.state       :1780][INFO    ][16990] Running state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:20:20.368523
2019-06-04 03:20:20,368 [salt.state       :1813][INFO    ][16990] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/node_status.py]
2019-06-04 03:20:20,391 [salt.state       :300 ][INFO    ][16990] No changes needed to be made
2019-06-04 03:20:20,391 [salt.state       :1951][INFO    ][16990] Completed state [/usr/lib/python3/dist-packages/maasserver/node_status.py] at time 03:20:20.391908 duration_in_ms=23.385
2019-06-04 03:20:20,392 [salt.state       :1780][INFO    ][16990] Running state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:20:20.392396
2019-06-04 03:20:20,392 [salt.state       :1813][INFO    ][16990] Executing state file.replace for [/usr/lib/python3/dist-packages/maasserver/models/node.py]
2019-06-04 03:20:20,431 [salt.state       :300 ][INFO    ][16990] No changes needed to be made
2019-06-04 03:20:20,433 [salt.state       :1951][INFO    ][16990] Completed state [/usr/lib/python3/dist-packages/maasserver/models/node.py] at time 03:20:20.433749 duration_in_ms=41.35
2019-06-04 03:20:20,436 [salt.state       :1780][INFO    ][16990] Running state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:20:20.436122
2019-06-04 03:20:20,437 [salt.state       :1813][INFO    ][16990] Executing state file.managed for [/etc/apache2/conf-enabled/maas-http.conf]
2019-06-04 03:20:20,459 [salt.state       :300 ][INFO    ][16990] File /etc/apache2/conf-enabled/maas-http.conf is in the correct state
2019-06-04 03:20:20,459 [salt.state       :1951][INFO    ][16990] Completed state [/etc/apache2/conf-enabled/maas-http.conf] at time 03:20:20.459769 duration_in_ms=23.647
2019-06-04 03:20:20,467 [salt.state       :1780][INFO    ][16990] Running state [a2enmod headers] at time 03:20:20.467095
2019-06-04 03:20:20,467 [salt.state       :1813][INFO    ][16990] Executing state cmd.run for [a2enmod headers]
2019-06-04 03:20:20,468 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command 'a2enmod headers' in directory '/root'
2019-06-04 03:20:20,544 [salt.state       :300 ][INFO    ][16990] {'pid': 17015, 'retcode': 0, 'stderr': '', 'stdout': 'Module headers already enabled'}
2019-06-04 03:20:20,545 [salt.state       :1951][INFO    ][16990] Completed state [a2enmod headers] at time 03:20:20.545295 duration_in_ms=78.199
2019-06-04 03:20:20,545 [salt.state       :1780][INFO    ][16990] Running state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:20:20.545885
2019-06-04 03:20:20,546 [salt.state       :1813][INFO    ][16990] Executing state file.managed for [/usr/share/maas/web/static/css/maas-styles.css]
2019-06-04 03:20:20,565 [salt.state       :300 ][INFO    ][16990] File /usr/share/maas/web/static/css/maas-styles.css is in the correct state
2019-06-04 03:20:20,566 [salt.state       :1951][INFO    ][16990] Completed state [/usr/share/maas/web/static/css/maas-styles.css] at time 03:20:20.566279 duration_in_ms=20.394
2019-06-04 03:20:20,567 [salt.state       :1780][INFO    ][16990] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:20:20.567262
2019-06-04 03:20:20,567 [salt.state       :1813][INFO    ][16990] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty]
2019-06-04 03:20:20,672 [salt.state       :300 ][INFO    ][16990] File /etc/maas/preseeds/curtin_userdata_amd64_generic_trusty is in the correct state
2019-06-04 03:20:20,672 [salt.state       :1951][INFO    ][16990] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_trusty] at time 03:20:20.672728 duration_in_ms=105.466
2019-06-04 03:20:20,673 [salt.state       :1780][INFO    ][16990] Running state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:20:20.673415
2019-06-04 03:20:20,673 [salt.state       :1813][INFO    ][16990] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial]
2019-06-04 03:20:20,756 [salt.state       :300 ][INFO    ][16990] File /etc/maas/preseeds/curtin_userdata_amd64_generic_xenial is in the correct state
2019-06-04 03:20:20,756 [salt.state       :1951][INFO    ][16990] Completed state [/etc/maas/preseeds/curtin_userdata_amd64_generic_xenial] at time 03:20:20.756255 duration_in_ms=82.841
2019-06-04 03:20:20,756 [salt.state       :1780][INFO    ][16990] Running state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:20:20.756883
2019-06-04 03:20:20,757 [salt.state       :1813][INFO    ][16990] Executing state file.managed for [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial]
2019-06-04 03:20:20,827 [salt.state       :300 ][INFO    ][16990] File /etc/maas/preseeds/curtin_userdata_arm64_generic_xenial is in the correct state
2019-06-04 03:20:20,828 [salt.state       :1951][INFO    ][16990] Completed state [/etc/maas/preseeds/curtin_userdata_arm64_generic_xenial] at time 03:20:20.828237 duration_in_ms=71.354
2019-06-04 03:20:20,828 [salt.state       :1780][INFO    ][16990] Running state [/root/.pgpass] at time 03:20:20.828593
2019-06-04 03:20:20,828 [salt.state       :1813][INFO    ][16990] Executing state file.managed for [/root/.pgpass]
2019-06-04 03:20:20,893 [salt.state       :300 ][INFO    ][16990] File /root/.pgpass is in the correct state
2019-06-04 03:20:20,894 [salt.state       :1951][INFO    ][16990] Completed state [/root/.pgpass] at time 03:20:20.893938 duration_in_ms=65.344
2019-06-04 03:20:20,900 [salt.state       :1780][INFO    ][16990] Running state [maas-region syncdb --noinput] at time 03:20:20.900711
2019-06-04 03:20:20,901 [salt.state       :1813][INFO    ][16990] Executing state cmd.run for [maas-region syncdb --noinput]
2019-06-04 03:20:20,901 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command 'maas-region syncdb --noinput' in directory '/root'
2019-06-04 03:20:22,967 [salt.state       :300 ][INFO    ][16990] {'pid': 17028, 'retcode': 0, 'stderr': '', 'stdout': 'Operations to perform:\n  Synchronize unmigrated apps: messages, staticfiles\n  Apply all migrations: metadataserver, contenttypes, piston3, sites, auth, maasserver, sessions\nSynchronizing apps without migrations:\n  Creating tables...\n    Running deferred SQL...\n  Installing custom SQL...\nRunning migrations:\n  No migrations to apply.'}
2019-06-04 03:20:22,968 [salt.state       :1951][INFO    ][16990] Completed state [maas-region syncdb --noinput] at time 03:20:22.968440 duration_in_ms=2067.726
2019-06-04 03:20:22,968 [salt.state       :2022][WARNING ][16990] State is set to retry, but a valid dict for retry configuration was not found.  Using retry defaults
2019-06-04 03:20:22,971 [salt.state       :1780][INFO    ][16990] Running state [maas-regiond] at time 03:20:22.971551
2019-06-04 03:20:22,972 [salt.state       :1813][INFO    ][16990] Executing state service.running for [maas-regiond]
2019-06-04 03:20:22,973 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['systemctl', 'status', 'maas-regiond.service', '-n', '0'] in directory '/root'
2019-06-04 03:20:23,017 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['systemctl', 'is-active', 'maas-regiond.service'] in directory '/root'
2019-06-04 03:20:23,036 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['systemctl', 'is-enabled', 'maas-regiond.service'] in directory '/root'
2019-06-04 03:20:23,055 [salt.state       :300 ][INFO    ][16990] The service maas-regiond is already running
2019-06-04 03:20:23,055 [salt.state       :1951][INFO    ][16990] Completed state [maas-regiond] at time 03:20:23.055846 duration_in_ms=84.295
2019-06-04 03:20:23,058 [salt.state       :1780][INFO    ][16990] Running state [bind9] at time 03:20:23.058447
2019-06-04 03:20:23,058 [salt.state       :1813][INFO    ][16990] Executing state service.running for [bind9]
2019-06-04 03:20:23,060 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['systemctl', 'status', 'bind9.service', '-n', '0'] in directory '/root'
2019-06-04 03:20:23,080 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['systemctl', 'is-active', 'bind9.service'] in directory '/root'
2019-06-04 03:20:23,099 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['systemctl', 'is-enabled', 'bind9.service'] in directory '/root'
2019-06-04 03:20:23,117 [salt.state       :300 ][INFO    ][16990] The service bind9 is already running
2019-06-04 03:20:23,117 [salt.state       :1951][INFO    ][16990] Completed state [bind9] at time 03:20:23.117692 duration_in_ms=59.244
2019-06-04 03:20:23,120 [salt.state       :1780][INFO    ][16990] Running state [apache2] at time 03:20:23.120069
2019-06-04 03:20:23,120 [salt.state       :1813][INFO    ][16990] Executing state service.running for [apache2]
2019-06-04 03:20:23,121 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['systemctl', 'status', 'apache2.service', '-n', '0'] in directory '/root'
2019-06-04 03:20:23,141 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['systemctl', 'is-active', 'apache2.service'] in directory '/root'
2019-06-04 03:20:23,158 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command ['systemctl', 'is-enabled', 'apache2.service'] in directory '/root'
2019-06-04 03:20:23,180 [salt.state       :300 ][INFO    ][16990] The service apache2 is already running
2019-06-04 03:20:23,180 [salt.state       :1951][INFO    ][16990] Completed state [apache2] at time 03:20:23.180653 duration_in_ms=60.583
2019-06-04 03:20:23,182 [salt.state       :1780][INFO    ][16990] Running state [maasng.wait_for_http_code] at time 03:20:23.182717
2019-06-04 03:20:23,183 [salt.state       :1813][INFO    ][16990] Executing state module.run for [maasng.wait_for_http_code]
2019-06-04 03:20:23,183 [salt.utils.decorators:613 ][WARNING ][16990] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:20:23,320 [salt.state       :300 ][INFO    ][16990] {'ret': {'comment': 'MAAS API:http://localhost:5240/MAAS up.', 'result': True}}
2019-06-04 03:20:23,321 [salt.state       :1951][INFO    ][16990] Completed state [maasng.wait_for_http_code] at time 03:20:23.321103 duration_in_ms=138.386
2019-06-04 03:20:23,322 [salt.state       :1780][INFO    ][16990] Running state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:20:23.322430
2019-06-04 03:20:23,322 [salt.state       :1813][INFO    ][16990] Executing state cmd.run for [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin]
2019-06-04 03:20:23,323 [salt.state       :300 ][INFO    ][16990] /var/lib/maas/.setup_admin exists
2019-06-04 03:20:23,324 [salt.state       :1951][INFO    ][16990] Completed state [maas createadmin --username opnfv --password opnfv_secret --email email@example.com && touch /var/lib/maas/.setup_admin] at time 03:20:23.324039 duration_in_ms=1.609
2019-06-04 03:20:23,325 [salt.state       :1780][INFO    ][16990] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:23.325214
2019-06-04 03:20:23,325 [salt.state       :1813][INFO    ][16990] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 03:20:23,326 [salt.loaded.int.module.cmdmod:395 ][INFO    ][16990] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 03:20:24,719 [salt.state       :300 ][INFO    ][16990] {'pid': 17053, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 03:20:24,720 [salt.state       :1951][INFO    ][16990] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:24.719985 duration_in_ms=1394.77
2019-06-04 03:20:24,729 [salt.state       :1780][INFO    ][16990] Running state [maas_region_boot_source_resources_mirror] at time 03:20:24.729229
2019-06-04 03:20:24,729 [salt.state       :1813][INFO    ][16990] Executing state maasng.boot_source_present for [maas_region_boot_source_resources_mirror]
2019-06-04 03:20:24,830 [salt.state       :300 ][INFO    ][16990] {'changes': {}}
2019-06-04 03:20:24,830 [salt.state       :1951][INFO    ][16990] Completed state [maas_region_boot_source_resources_mirror] at time 03:20:24.830792 duration_in_ms=101.562
2019-06-04 03:20:24,832 [salt.state       :1780][INFO    ][16990] Running state [maasng.boot_resources_import] at time 03:20:24.832069
2019-06-04 03:20:24,832 [salt.state       :1813][INFO    ][16990] Executing state module.run for [maasng.boot_resources_import]
2019-06-04 03:20:24,833 [salt.utils.decorators:613 ][WARNING ][16990] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:20:24,956 [salt.loaded.ext.module.maasng:1600][INFO    ][16990] Waiting boot-resources import done
sleep for:5s Left:900.0/900s
2019-06-04 03:20:30,012 [salt.loaded.ext.module.maasng:1600][INFO    ][16990] Waiting boot-resources import done
sleep for:5s Left:895.0/900s
2019-06-04 03:20:33,669 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032033657814
2019-06-04 03:20:33,692 [salt.minion      :1432][INFO    ][17095] Starting a new job with PID 17095
2019-06-04 03:20:33,715 [salt.minion      :1711][INFO    ][17095] Returning information for job: 20190604032033657814
2019-06-04 03:20:35,069 [salt.loaded.ext.module.maasng:1600][INFO    ][16990] Waiting boot-resources import done
sleep for:5s Left:890.0/900s
2019-06-04 03:20:40,184 [salt.state       :300 ][INFO    ][16990] {'ret': True}
2019-06-04 03:20:40,185 [salt.state       :1951][INFO    ][16990] Completed state [maasng.boot_resources_import] at time 03:20:40.185056 duration_in_ms=15352.986
2019-06-04 03:20:40,186 [salt.state       :1780][INFO    ][16990] Running state [maas_region_boot_sources_selection_xenial] at time 03:20:40.186325
2019-06-04 03:20:40,186 [salt.state       :1813][INFO    ][16990] Executing state maasng.boot_sources_selections_present for [maas_region_boot_sources_selection_xenial]
2019-06-04 03:20:40,402 [salt.state       :300 ][INFO    ][16990] Requested boot-source selection for http://images.maas.io/ephemeral-v3/daily already exist.
2019-06-04 03:20:40,403 [salt.state       :1951][INFO    ][16990] Completed state [maas_region_boot_sources_selection_xenial] at time 03:20:40.403135 duration_in_ms=216.809
2019-06-04 03:20:40,404 [salt.state       :1780][INFO    ][16990] Running state [maasng.sync_and_wait_bs_to_all_racks] at time 03:20:40.404360
2019-06-04 03:20:40,404 [salt.state       :1813][INFO    ][16990] Executing state module.run for [maasng.sync_and_wait_bs_to_all_racks]
2019-06-04 03:20:40,405 [salt.utils.decorators:613 ][WARNING ][16990] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:20:40,405 [salt.loaded.ext.module.maasng:1771][INFO    ][16990] boot-sources sync initiated for ALL Rack's
2019-06-04 03:20:41,252 [salt.state       :300 ][INFO    ][16990] {'ret': True}
2019-06-04 03:20:41,253 [salt.state       :1951][INFO    ][16990] Completed state [maasng.sync_and_wait_bs_to_all_racks] at time 03:20:41.252980 duration_in_ms=848.62
2019-06-04 03:20:41,254 [salt.state       :1780][INFO    ][16990] Running state [maas.process_maas_config] at time 03:20:41.254010
2019-06-04 03:20:41,254 [salt.state       :1813][INFO    ][16990] Executing state module.run for [maas.process_maas_config]
2019-06-04 03:20:41,254 [salt.utils.decorators:613 ][WARNING ][16990] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:20:41,255 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=enable_http_proxy value=True
2019-06-04 03:20:41,290 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=upstream_dns value=8.8.8.8
2019-06-04 03:20:41,337 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=commissioning_distro_series value=xenial
2019-06-04 03:20:41,394 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=default_osystem value=ubuntu
2019-06-04 03:20:44,571 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=active_discovery_interval value=600
2019-06-04 03:20:44,669 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=dnssec_validation value=no
2019-06-04 03:20:44,742 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=maas_name value=mas01
2019-06-04 03:20:44,799 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=network_discovery value=enabled
2019-06-04 03:20:44,904 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=enable_third_party_drivers value=True
2019-06-04 03:20:44,956 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=default_storage_layout value=lvm
2019-06-04 03:20:45,025 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=ntp_external_only value=True
2019-06-04 03:20:45,071 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=disk_erase_with_secure_erase value=False
2019-06-04 03:20:45,138 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=default_distro_series value=xenial
2019-06-04 03:20:45,196 [salt.loaded.ext.module.maas:92  ][INFO    ][16990] maasconfig name=default_min_hwe_kernel value=ga-16.04
2019-06-04 03:20:45,314 [salt.state       :300 ][INFO    ][16990] {'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-06-04 03:20:45,315 [salt.state       :1951][INFO    ][16990] Completed state [maas.process_maas_config] at time 03:20:45.315138 duration_in_ms=4061.127
2019-06-04 03:20:45,316 [salt.state       :1780][INFO    ][16990] Running state [pxe_admin] at time 03:20:45.316015
2019-06-04 03:20:45,316 [salt.state       :1813][INFO    ][16990] Executing state maasng.fabric_present for [pxe_admin]
2019-06-04 03:20:45,367 [salt.loaded.ext.module.maasng:945 ][INFO    ][16990] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'bpbenn', 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-06-04 03:20:45,403 [salt.loaded.ext.module.maasng:1008][WARNING ][16990] Detected cidr:192.168.11.0/24 in fabric:pxe_admin
2019-06-04 03:20:45,403 [salt.loaded.ext.module.maasng:1011][WARNING ][16990] Guessing, that fabric with current name:pxe_admin
 should be renamed to:pxe_admin
2019-06-04 03:20:45,457 [salt.state       :300 ][INFO    ][16990] {'new': 'Fabric  pxe_admin created', 'result': True}
2019-06-04 03:20:45,457 [salt.state       :1951][INFO    ][16990] Completed state [pxe_admin] at time 03:20:45.457870 duration_in_ms=141.856
2019-06-04 03:20:45,458 [salt.state       :1780][INFO    ][16990] Running state [vlan 0] at time 03:20:45.458165
2019-06-04 03:20:45,458 [salt.state       :1813][INFO    ][16990] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-04 03:20:45,505 [salt.loaded.ext.module.maasng:945 ][INFO    ][16990] [{u'class_type': None, u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bpbenn', u'name': u'untagged', 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-06-04 03:20:45,607 [salt.loaded.ext.module.maasng:945 ][INFO    ][16990] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'primary_rack': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 1, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'primary_rack': 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'name': u'untagged', u'vid': 0, u'space': u'undefined', u'fabric_id': 2, u'dhcp_on': True, u'mtu': 1500, u'external_dhcp': None, u'fabric': u'pxe_admin', u'relay_vlan': None, u'primary_rack': u'bpbenn', 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-06-04 03:20:45,867 [salt.loaded.ext.module.maasng:945 ][INFO    ][16990] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'class_type': None, u'name': u'fabric-0'}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'class_type': None, u'name': u'fabric-1'}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'bpbenn', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'class_type': u'', u'name': u'pxe_admin'}]
2019-06-04 03:20:45,958 [salt.state       :300 ][INFO    ][16990] {'new': 'Vlan untagged was updated'}
2019-06-04 03:20:45,958 [salt.state       :1951][INFO    ][16990] Completed state [vlan 0] at time 03:20:45.958530 duration_in_ms=500.363
2019-06-04 03:20:45,960 [salt.state       :1780][INFO    ][16990] Running state [192.168.11.0/24] at time 03:20:45.960078
2019-06-04 03:20:45,960 [salt.state       :1813][INFO    ][16990] Executing state maasng.subnet_present for [192.168.11.0/24]
2019-06-04 03:20:46,167 [salt.loaded.ext.module.maasng:945 ][INFO    ][16990] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'bpbenn', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 03:20:46,168 [salt.loaded.ext.module.maasng:1235][WARNING ][16990] Ignoring parameter vlan:0
2019-06-04 03:20:46,274 [salt.state       :300 ][INFO    ][16990] Subnet 192.168.11.0/24 has been updated for pxe_admin
2019-06-04 03:20:46,274 [salt.state       :1951][INFO    ][16990] Completed state [192.168.11.0/24] at time 03:20:46.274691 duration_in_ms=314.613
2019-06-04 03:20:46,276 [salt.state       :1780][INFO    ][16990] Running state [maas_create_iprange_1] at time 03:20:46.276097
2019-06-04 03:20:46,276 [salt.state       :1813][INFO    ][16990] Executing state maasng.iprange_present for [maas_create_iprange_1]
2019-06-04 03:20:46,326 [salt.state       :300 ][INFO    ][16990] Iprange maas_create_iprange_1 already exist.
2019-06-04 03:20:46,326 [salt.state       :1951][INFO    ][16990] Completed state [maas_create_iprange_1] at time 03:20:46.326712 duration_in_ms=50.615
2019-06-04 03:20:46,327 [salt.state       :1780][INFO    ][16990] Running state [vlan 0] at time 03:20:46.327149
2019-06-04 03:20:46,327 [salt.state       :1813][INFO    ][16990] Executing state maasng.vlan_present_in_fabric for [vlan 0]
2019-06-04 03:20:46,398 [salt.loaded.ext.module.maasng:945 ][INFO    ][16990] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'bpbenn', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 03:20:46,521 [salt.loaded.ext.module.maasng:945 ][INFO    ][16990] [{u'vlans': [{u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/0/', u'id': 0, u'class_type': None, u'name': u'fabric-0'}, {u'vlans': [{u'fabric': u'fabric-1', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/1/', u'id': 1, u'class_type': None, u'name': u'fabric-1'}, {u'vlans': [{u'fabric': u'pxe_admin', u'vid': 0, u'space': u'undefined', u'name': u'untagged', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'bpbenn', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'resource_uri': u'/MAAS/api/2.0/fabrics/2/', u'id': 2, u'class_type': u'', u'name': u'pxe_admin'}]
2019-06-04 03:20:46,736 [salt.loaded.ext.module.maasng:945 ][INFO    ][16990] [{u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}], u'id': 0, u'name': u'fabric-0', u'resource_uri': u'/MAAS/api/2.0/fabrics/0/'}, {u'class_type': None, u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 1, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-1', u'relay_vlan': None, u'external_dhcp': None, u'id': 5002, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5002/'}], u'id': 1, u'name': u'fabric-1', u'resource_uri': u'/MAAS/api/2.0/fabrics/1/'}, {u'class_type': u'', u'vlans': [{u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'bpbenn', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}], u'id': 2, u'name': u'pxe_admin', u'resource_uri': u'/MAAS/api/2.0/fabrics/2/'}]
2019-06-04 03:20:46,846 [salt.state       :300 ][INFO    ][16990] {'new': 'Vlan untagged was updated'}
2019-06-04 03:20:46,846 [salt.state       :1951][INFO    ][16990] Completed state [vlan 0] at time 03:20:46.846681 duration_in_ms=519.531
2019-06-04 03:20:46,847 [salt.state       :1780][INFO    ][16990] Running state [opnfv] at time 03:20:46.847268
2019-06-04 03:20:46,847 [salt.state       :1813][INFO    ][16990] Executing state maasng.sshkey_present for [opnfv]
2019-06-04 03:20:46,898 [salt.loaded.ext.module.maasng:1903][INFO    ][16990] [{u'keysource': u'', u'id': 1, u'key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP', u'resource_uri': u'/MAAS/api/2.0/account/prefs/sshkeys/1/'}]
2019-06-04 03:20:46,898 [salt.state       :300 ][INFO    ][16990] SSH key ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9EPrpVPjbJtSqDZMX5nXn6LMNnuXDhsh1V4Zf0ynamBhtwcs6ztm8AaLppz+mdXFAdO0jHy1U72eWTefrkaMjL/tFjZY03xJnuRPmhzPOy/LT8tOjkp1SRLb3JhYoKUDcJIJ2aAv0SIDuXhTT8r4aUvJOWUSv0Og34WfS1afOLKSjiz1j2sOW2iG1nim0uF+sX1K3GHPnE5LtwJMAG4WQO1yK9XG3CUxkaYnJRdMfwAx5QAhGhxu/bK7NwyTNxz8fkPdJhxookorf7JetCWwq6ScSTbAHqoTWbzLh4BhNVMOEdbMKAODdOXj2ii5mEFnQYBBmh1dXSP3k2bzD/TCP already exist for user opnfv.
2019-06-04 03:20:46,899 [salt.state       :1951][INFO    ][16990] Completed state [opnfv] at time 03:20:46.898982 duration_in_ms=51.713
2019-06-04 03:20:46,903 [salt.minion      :1711][INFO    ][16990] Returning information for job: 20190604032018626873
2019-06-04 03:20:47,407 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command state.apply with jid 20190604032047395943
2019-06-04 03:20:47,423 [salt.minion      :1432][INFO    ][17646] Starting a new job with PID 17646
2019-06-04 03:20:50,881 [salt.state       :915 ][INFO    ][17646] Loading fresh modules for state activity
2019-06-04 03:20:50,931 [salt.state       :1780][INFO    ][17646] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:50.931401
2019-06-04 03:20:50,931 [salt.state       :1813][INFO    ][17646] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 03:20:50,932 [salt.loaded.int.module.cmdmod:395 ][INFO    ][17646] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 03:20:52,153 [salt.state       :300 ][INFO    ][17646] {'pid': 17672, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 03:20:52,154 [salt.state       :1951][INFO    ][17646] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:20:52.154616 duration_in_ms=1223.215
2019-06-04 03:20:52,156 [salt.state       :1780][INFO    ][17646] Running state [maas.process_machines] at time 03:20:52.156907
2019-06-04 03:20:52,157 [salt.state       :1813][INFO    ][17646] Executing state module.run for [maas.process_machines]
2019-06-04 03:20:52,158 [salt.utils.decorators:613 ][WARNING ][17646] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:20:52,428 [salt.loaded.ext.module.maas:412 ][WARNING ][17646] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:20:52,429 [salt.loaded.ext.module.maas:92  ][INFO    ][17646] 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=k3gbfh architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:20:53,286 [salt.loaded.ext.module.maas:412 ][WARNING ][17646] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:20:53,287 [salt.loaded.ext.module.maas:92  ][INFO    ][17646] 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=nettfa architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:20:54,281 [salt.loaded.ext.module.maas:412 ][WARNING ][17646] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:20:54,282 [salt.loaded.ext.module.maas:92  ][INFO    ][17646] 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=qrg6rc architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:20:55,313 [salt.loaded.ext.module.maas:412 ][WARNING ][17646] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:20:55,314 [salt.loaded.ext.module.maas:92  ][INFO    ][17646] 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=f4w6k4 architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:20:56,188 [salt.loaded.ext.module.maas:412 ][WARNING ][17646] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:20:56,189 [salt.loaded.ext.module.maas:92  ][INFO    ][17646] 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=hgf3mw architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:20:57,233 [salt.state       :300 ][INFO    ][17646] {'ret': {'updated': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02'], 'errors': {}, 'success': []}}
2019-06-04 03:20:57,234 [salt.state       :1951][INFO    ][17646] Completed state [maas.process_machines] at time 03:20:57.234197 duration_in_ms=5077.289
2019-06-04 03:20:57,238 [salt.minion      :1711][INFO    ][17646] Returning information for job: 20190604032047395943
2019-06-04 03:21:28,154 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command state.apply with jid 20190604032128147760
2019-06-04 03:21:28,174 [salt.minion      :1432][INFO    ][18003] Starting a new job with PID 18003
2019-06-04 03:21:32,223 [salt.state       :915 ][INFO    ][18003] Loading fresh modules for state activity
2019-06-04 03:21:32,271 [salt.state       :1780][INFO    ][18003] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:21:32.271766
2019-06-04 03:21:32,272 [salt.state       :1813][INFO    ][18003] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 03:21:32,273 [salt.loaded.int.module.cmdmod:395 ][INFO    ][18003] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 03:21:33,629 [salt.state       :300 ][INFO    ][18003] {'pid': 18030, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 03:21:33,630 [salt.state       :1951][INFO    ][18003] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:21:33.630765 duration_in_ms=1358.998
2019-06-04 03:21:33,633 [salt.state       :1780][INFO    ][18003] Running state [maas.wait_for_machine_status] at time 03:21:33.633730
2019-06-04 03:21:33,634 [salt.state       :1813][INFO    ][18003] Executing state module.run for [maas.wait_for_machine_status]
2019-06-04 03:21:33,634 [salt.utils.decorators:613 ][WARNING ][18003] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:21:36,251 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1497.39071393s left)
2019-06-04 03:21:43,184 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032143171622
2019-06-04 03:21:43,206 [salt.minion      :1432][INFO    ][18150] Starting a new job with PID 18150
2019-06-04 03:21:43,230 [salt.minion      :1711][INFO    ][18150] Returning information for job: 20190604032143171622
2019-06-04 03:22:08,911 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1464.73052311s left)
2019-06-04 03:22:13,228 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032213215780
2019-06-04 03:22:13,250 [salt.minion      :1432][INFO    ][18178] Starting a new job with PID 18178
2019-06-04 03:22:13,275 [salt.minion      :1711][INFO    ][18178] Returning information for job: 20190604032213215780
2019-06-04 03:22:41,644 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1431.99794912s left)
2019-06-04 03:22:43,283 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032243271073
2019-06-04 03:22:43,306 [salt.minion      :1432][INFO    ][18236] Starting a new job with PID 18236
2019-06-04 03:22:43,329 [salt.minion      :1711][INFO    ][18236] Returning information for job: 20190604032243271073
2019-06-04 03:23:13,330 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032313316980
2019-06-04 03:23:13,352 [salt.minion      :1432][INFO    ][18256] Starting a new job with PID 18256
2019-06-04 03:23:13,375 [salt.minion      :1711][INFO    ][18256] Returning information for job: 20190604032313316980
2019-06-04 03:23:14,243 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1399.39873195s left)
2019-06-04 03:23:43,377 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032343364927
2019-06-04 03:23:43,399 [salt.minion      :1432][INFO    ][18317] Starting a new job with PID 18317
2019-06-04 03:23:43,423 [salt.minion      :1711][INFO    ][18317] Returning information for job: 20190604032343364927
2019-06-04 03:23:44,940 [salt.loaded.ext.module.maas:981 ][INFO    ][18003] Machine k3gbfh deleted
2019-06-04 03:23:45,717 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:45,718 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] machine hostname=cmp002 power_type=ipmi mac_addresses=00:25:b5:a0:00:6a power_parameters_power_address=172.30.8.72 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:47,039 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:47,040 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] 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=nettfa architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:47,912 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:47,913 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] machine hostname=kvm01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=qrg6rc architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:49,226 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:49,227 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] 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=f4w6k4 architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:50,062 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:50,063 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] 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=hgf3mw architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:52,894 [salt.loaded.ext.module.maas:981 ][INFO    ][18003] Machine f4w6k4 deleted
2019-06-04 03:23:53,651 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:53,651 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] 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=eawk73 architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:54,445 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:54,446 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] 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=nettfa architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:55,439 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:55,440 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] machine hostname=kvm01 power_type=ipmi mac_addresses=['00:25:b5:a0:00:2a'] power_parameters_power_address=172.30.8.75 power_parameters_power_pass=octopus system_id=qrg6rc architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:56,718 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:56,718 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] machine hostname=kvm03 power_type=ipmi mac_addresses=00:25:b5:a0:00:4a power_parameters_power_address=172.30.8.74 power_parameters_power_pass=octopus architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:58,170 [salt.loaded.ext.module.maas:412 ][WARNING ][18003] Old machine-describe detected! Please read documentation for 'salt-formulas/maas' for migration!
2019-06-04 03:23:58,171 [salt.loaded.ext.module.maas:92  ][INFO    ][18003] 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=hgf3mw architecture=amd64/generic power_parameters_power_user=admin
2019-06-04 03:23:59,939 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1353.70209098s left)
2019-06-04 03:24:13,435 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032413422611
2019-06-04 03:24:13,457 [salt.minion      :1432][INFO    ][18810] Starting a new job with PID 18810
2019-06-04 03:24:13,479 [salt.minion      :1711][INFO    ][18810] Returning information for job: 20190604032413422611
2019-06-04 03:24:32,569 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1321.07287097s left)
2019-06-04 03:24:43,488 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032443475530
2019-06-04 03:24:43,510 [salt.minion      :1432][INFO    ][18872] Starting a new job with PID 18872
2019-06-04 03:24:43,533 [salt.minion      :1711][INFO    ][18872] Returning information for job: 20190604032443475530
2019-06-04 03:25:05,175 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1288.4665091s left)
2019-06-04 03:25:13,545 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032513531313
2019-06-04 03:25:13,567 [salt.minion      :1432][INFO    ][18906] Starting a new job with PID 18906
2019-06-04 03:25:13,588 [salt.minion      :1711][INFO    ][18906] Returning information for job: 20190604032513531313
2019-06-04 03:25:37,509 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1256.13227105s left)
2019-06-04 03:25:43,604 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032543591200
2019-06-04 03:25:43,626 [salt.minion      :1432][INFO    ][18972] Starting a new job with PID 18972
2019-06-04 03:25:43,649 [salt.minion      :1711][INFO    ][18972] Returning information for job: 20190604032543591200
2019-06-04 03:26:10,193 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1223.44828701s left)
2019-06-04 03:26:13,671 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032613658840
2019-06-04 03:26:13,690 [salt.minion      :1432][INFO    ][19072] Starting a new job with PID 19072
2019-06-04 03:26:13,712 [salt.minion      :1711][INFO    ][19072] Returning information for job: 20190604032613658840
2019-06-04 03:26:42,299 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1191.34204793s left)
2019-06-04 03:26:43,744 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032643732643
2019-06-04 03:26:43,768 [salt.minion      :1432][INFO    ][19397] Starting a new job with PID 19397
2019-06-04 03:26:43,792 [salt.minion      :1711][INFO    ][19397] Returning information for job: 20190604032643732643
2019-06-04 03:27:13,819 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032713808840
2019-06-04 03:27:13,840 [salt.minion      :1432][INFO    ][19428] Starting a new job with PID 19428
2019-06-04 03:27:13,862 [salt.minion      :1711][INFO    ][19428] Returning information for job: 20190604032713808840
2019-06-04 03:27:14,643 [salt.loaded.ext.module.maas:1023][INFO    ][18003] Waiting status:Ready|Deployed for machines:['cmp002', 'kvm03']
sleep for:30s Timeout:1500s (1158.99808002s left)
2019-06-04 03:27:43,904 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032743891308
2019-06-04 03:27:43,926 [salt.minion      :1432][INFO    ][19555] Starting a new job with PID 19555
2019-06-04 03:27:43,949 [salt.minion      :1711][INFO    ][19555] Returning information for job: 20190604032743891308
2019-06-04 03:27:47,988 [salt.state       :300 ][INFO    ][18003] {'ret': True}
2019-06-04 03:27:47,989 [salt.state       :1951][INFO    ][18003] Completed state [maas.wait_for_machine_status] at time 03:27:47.988925 duration_in_ms=374355.192
2019-06-04 03:27:47,992 [salt.minion      :1711][INFO    ][18003] Returning information for job: 20190604032128147760
2019-06-04 03:27:48,651 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command state.apply with jid 20190604032748638202
2019-06-04 03:27:48,673 [salt.minion      :1432][INFO    ][19574] Starting a new job with PID 19574
2019-06-04 03:27:52,332 [salt.state       :915 ][INFO    ][19574] Loading fresh modules for state activity
2019-06-04 03:27:52,383 [salt.fileclient  :1219][INFO    ][19574] Fetching file from saltenv 'base', ** done ** 'maas/machines/storage.sls'
2019-06-04 03:27:52,463 [salt.state       :1780][INFO    ][19574] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:27:52.463332
2019-06-04 03:27:52,463 [salt.state       :1813][INFO    ][19574] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 03:27:52,465 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19574] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 03:27:53,825 [salt.state       :300 ][INFO    ][19574] {'pid': 19582, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 03:27:53,826 [salt.state       :1951][INFO    ][19574] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:27:53.826378 duration_in_ms=1363.045
2019-06-04 03:27:53,827 [salt.state       :1780][INFO    ][19574] Running state [maas_machines_storage_cmp002_lvm] at time 03:27:53.827822
2019-06-04 03:27:53,828 [salt.state       :1813][INFO    ][19574] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp002_lvm]
2019-06-04 03:27:55,127 [salt.loaded.ext.module.maasng:610 ][INFO    ][19574] eawk73
2019-06-04 03:27:55,128 [salt.loaded.ext.module.maasng:626 ][INFO    ][19574] sda
2019-06-04 03:27:55,694 [salt.loaded.ext.module.maasng:361 ][INFO    ][19574] eawk73
2019-06-04 03:27:55,821 [salt.loaded.ext.module.maasng:367 ][INFO    ][19574] [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/7/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'eawk73', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 7, u'partitions': [{u'uuid': u'857003a3-554e-4f11-b8d9-4536ba49c391', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/7/partition/4', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'eawk73', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'09da2df9-db6b-4d73-b900-80e0ebd18109', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 4, u'device_id': 7}]}, {u'size': 2397988454400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/9/', u'used_size': 2397988454400, u'tags': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'ccaa4754-dec2-4a53-a1f9-c89f115ede5f', u'fstype': u'ext4'}, u'uuid': u'eda69b0a-c44f-4edb-a226-2a7a2628db54', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'eawk73', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 9, u'partitions': []}]
2019-06-04 03:27:55,822 [salt.loaded.ext.module.maasng:632 ][INFO    ][19574] vgroot
2019-06-04 03:27:55,822 [salt.loaded.ext.module.maasng:635 ][INFO    ][19574] lvroot
2019-06-04 03:27:55,822 [salt.loaded.ext.module.maasng:639 ][INFO    ][19574] 107374182400
2019-06-04 03:27:56,488 [salt.loaded.ext.module.maasng:645 ][INFO    ][19574] {u'hwe_kernel': u'', u'swap_size': None, u'memory_test_status': -1, u'ip_addresses': [u'192.168.11.39'], u'storage_test_status_name': u'Passed', u'power_type': u'ipmi', u'domain': {u'resource_record_count': 0, u'name': u'maas', u'authoritative': True, u'ttl': None, u'id': 0, u'resource_uri': u'/MAAS/api/2.0/domains/0/'}, u'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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bpbenn', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bpbenn', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 34}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6a', 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bpbenn', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'eawk73', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/interfaces/18/'}, u'status_action': u'modules-final', u'tag_names': [], u'testing_status_name': u'Passed', u'owner': None, u'pod': None, u'cache_sets': [], u'iscsiblockdevice_set': [], u'boot_disk': {u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/7/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'eawk73', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 7, u'partitions': [{u'uuid': u'1dee335f-512a-437b-9f7f-c9b6778e7160', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/7/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'eawk73', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'33dc96c1-c31f-434f-8550-6f9799b626d1', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 7}]}, u'blockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/7/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'eawk73', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 7, u'partitions': [{u'uuid': u'1dee335f-512a-437b-9f7f-c9b6778e7160', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/7/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'eawk73', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'33dc96c1-c31f-434f-8550-6f9799b626d1', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 7}]}, {u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/11/', u'used_size': 107374182400, u'tags': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'6dfdede9-b63b-4a34-8074-83c1d1b24fd2', u'fstype': u'ext4'}, u'uuid': u'2e5507a7-5a94-4154-8dff-3054033fd797', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'eawk73', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 11, u'partitions': []}], u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/eawk73/', u'current_commissioning_result_id': 12, u'hostname': u'cmp002', u'storage': 2397998.9401599998, u'node_type': 0, u'testing_status': 2, u'system_id': u'eawk73', u'raids': [], u'memory': 32768, u'current_installation_result_id': None, u'default_gateways': {u'ipv4': {u'gateway_ip': None, u'link_id': None}, u'ipv6': {u'gateway_ip': None, u'link_id': None}}, u'status_message': u"'cloudinit' running modules for final", u'virtualblockdevice_set': [{u'size': 107374182400, u'model': None, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/11/', u'used_size': 107374182400, u'tags': [], u'filesystem': {u'mount_options': None, u'label': u'root', u'mount_point': u'/', u'uuid': u'6dfdede9-b63b-4a34-8074-83c1d1b24fd2', u'fstype': u'ext4'}, u'uuid': u'2e5507a7-5a94-4154-8dff-3054033fd797', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'eawk73', u'partition_table_type': None, u'available_size': 0, u'id_path': None, u'path': u'/dev/disk/by-dname/vgroot-lvroot', u'serial': None, u'block_size': 4096, u'type': u'virtual', u'id': 11, u'partitions': []}], u'architecture': u'amd64/generic', u'status': 4, u'bcaches': [], u'cpu_count': 16, u'power_state': u'on', u'owner_data': {}, u'memory_test_status_name': u'Unknown', u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'eawk73', u'id': 6}], u'special_filesystems': [], u'cpu_test_status_name': u'Unknown', u'commissioning_status_name': u'Passed', u'current_testing_result_id': 13, u'cpu_test_status': -1, u'storage_test_status': 2, u'status_name': u'Ready', u'physicalblockdevice_set': [{u'size': 2397998940160, u'model': u'UCSB-MRAID12G', u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/7/', u'used_size': 2397998940160, u'tags': [u'rotary'], u'filesystem': None, u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'eawk73', u'partition_table_type': u'GPT', u'available_size': 0, u'id_path': u'/dev/disk/by-id/wwn-0x618e728372755980239b15112698bc66', u'path': u'/dev/disk/by-dname/sda', u'serial': u'618e728372755980239b15112698bc66', u'block_size': 4096, u'type': u'physical', u'id': 7, u'partitions': [{u'uuid': u'1dee335f-512a-437b-9f7f-c9b6778e7160', u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/blockdevices/7/partition/6', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'eawk73', u'filesystem': {u'mount_options': None, u'label': None, u'mount_point': None, u'uuid': u'33dc96c1-c31f-434f-8550-6f9799b626d1', u'fstype': u'lvm-pv'}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 6, u'device_id': 7}]}], u'netboot': True, u'osystem': u'', u'fqdn': u'cmp002.maas', u'disable_ipv4': False, u'commissioning_status': 2, u'min_hwe_kernel': u'ga-16.04', 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bpbenn', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bpbenn', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39', u'mode': u'dhcp', u'id': 34}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6a', 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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': u'bpbenn', u'name': u'untagged', u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'ip_address': u'192.168.11.39'}], u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'eawk73', u'type': u'physical', u'id': 18, u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/interfaces/18/'}, {u'vlan': {u'fabric': u'fabric-0', u'vid': 0, u'space': u'undefined', u'fabric_id': 0, u'dhcp_on': False, u'mtu': 1500, u'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 35}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6c', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'eawk73', u'type': u'physical', u'id': 20, u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/interfaces/20/'}, {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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 36}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6d', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'eawk73', u'type': u'physical', u'id': 21, u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/interfaces/21/'}, {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'external_dhcp': None, u'relay_vlan': None, u'primary_rack': None, u'name': u'untagged', u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 37}], u'tags': [], u'mac_address': u'00:25:b5:a0:00:6b', u'enabled': True, u'children': [], u'discovered': None, u'parents': [], u'params': u'', u'effective_mtu': 1500, u'system_id': u'eawk73', u'type': u'physical', u'id': 22, u'resource_uri': u'/MAAS/api/2.0/nodes/eawk73/interfaces/22/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'node_type_name': u'Machine'}
2019-06-04 03:27:56,491 [salt.state       :300 ][INFO    ][19574] {'new': {'storage_layout': 'lvm'}}
2019-06-04 03:27:56,492 [salt.state       :1951][INFO    ][19574] Completed state [maas_machines_storage_cmp002_lvm] at time 03:27:56.491926 duration_in_ms=2664.101
2019-06-04 03:27:56,492 [salt.state       :1780][INFO    ][19574] Running state [maas_machines_storage_cmp001_lvm] at time 03:27:56.492472
2019-06-04 03:27:56,492 [salt.state       :1813][INFO    ][19574] Executing state maasng.disk_layout_present for [maas_machines_storage_cmp001_lvm]
2019-06-04 03:27:57,760 [salt.loaded.ext.module.maasng:610 ][INFO    ][19574] nettfa
2019-06-04 03:27:57,761 [salt.loaded.ext.module.maasng:626 ][INFO    ][19574] sda
2019-06-04 03:27:58,418 [salt.loaded.ext.module.maasng:361 ][INFO    ][19574] nettfa
2019-06-04 03:27:58,545 [salt.loaded.ext.module.maasng:367 ][INFO    ][19574] [{u'size': 2397998940160, u'available_size': 0, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/1/', u'type': u'physical', u'tags': [u'rotary'], u'uuid': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'nettfa', 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'model': u'UCSB-MRAID12G', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'serial': u'618e72837274f1901cc7889705aa1b02', u'partitions': [{u'size': 2397992648704, u'uuid': u'a61d031b-1cf8-4622-8a20-1643dc7dfe15', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'nettfa', u'filesystem': {u'mount_options': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'8591467e-87c2-4d45-8866-78e36f39cc9f', u'label': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/1/partition/1', u'type': u'partition', u'id': 1, u'device_id': 1}]}, {u'size': 2397988454400, u'available_size': 0, u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/4/', u'type': u'virtual', u'tags': [], u'uuid': u'b1f408b1-8853-439a-906e-67809cf422e2', u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'nettfa', u'partition_table_type': None, u'filesystem': {u'mount_options': None, u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'a5bdf7c1-bcc5-4333-bf09-1cfa798ebbda', u'label': u'root'}, u'id_path': None, u'path': u'/dev/disk/by-dname/lvroot', u'model': None, u'block_size': 4096, u'used_size': 2397988454400, u'id': 4, u'serial': None, u'partitions': []}]
2019-06-04 03:27:58,546 [salt.loaded.ext.module.maasng:632 ][INFO    ][19574] vgroot
2019-06-04 03:27:58,546 [salt.loaded.ext.module.maasng:635 ][INFO    ][19574] lvroot
2019-06-04 03:27:58,546 [salt.loaded.ext.module.maasng:639 ][INFO    ][19574] 107374182400
2019-06-04 03:27:59,235 [salt.loaded.ext.module.maasng:645 ][INFO    ][19574] {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'memory_test_status': -1, u'ip_addresses': [], u'storage_test_status_name': u'Passed', u'owner_data': {}, 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'cpu_test_status_name': u'Unknown', u'iscsiblockdevice_set': [], u'status_action': u'', u'blockdevice_set': [{u'model': u'UCSB-MRAID12G', u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/1/', u'type': u'physical', u'partitions': [{u'uuid': u'c7948315-68ad-4405-9e78-42b3373c28b5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'nettfa', u'device_id': 1, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'ea60f643-8e7b-4f99-b98d-f34e8feede14', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/1/partition/7'}], u'tags': [u'rotary'], u'filesystem': None, u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'nettfa', u'partition_table_type': u'GPT', u'path': u'/dev/disk/by-dname/sda', u'id_path': u'/dev/disk/by-id/wwn-0x618e72837274f1901cc7889705aa1b02', u'available_size': 0, u'serial': u'618e72837274f1901cc7889705aa1b02', u'block_size': 4096, u'used_size': 2397998940160, u'id': 1, u'size': 2397998940160}, {u'model': None, u'uuid': u'9a1bc77e-5fbd-4ec1-9c5f-b4e0dc8887d9', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/12/', u'type': u'virtual', u'partitions': [], u'tags': [], u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'de465f96-d324-40ab-a54b-3d05beaf998a', u'mount_options': None}, u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'nettfa', u'partition_table_type': None, u'path': u'/dev/disk/by-dname/lvroot', u'id_path': None, u'available_size': 0, u'serial': None, u'block_size': 4096, u'used_size': 107374182400, u'id': 12, u'size': 107374182400}], u'zone': {u'description': u'', u'id': 1, u'name': u'default', u'resource_uri': u'/MAAS/api/2.0/zones/default/'}, u'resource_uri': u'/MAAS/api/2.0/machines/nettfa/', u'node_type_name': u'Machine', u'hostname': u'cmp001', u'storage': 2397998.9401599998, u'testing_status': 2, u'system_id': u'nettfa', 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'model': None, u'available_size': 0, u'uuid': u'9a1bc77e-5fbd-4ec1-9c5f-b4e0dc8887d9', u'name': u'vgroot-lvroot', u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/12/', u'type': u'virtual', u'partitions': [], u'tags': [], u'used_for': u'ext4 formatted filesystem mounted at /', u'system_id': u'nettfa', u'partition_table_type': None, u'filesystem': {u'label': u'root', u'fstype': u'ext4', u'mount_point': u'/', u'uuid': u'de465f96-d324-40ab-a54b-3d05beaf998a', u'mount_options': None}, 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'size': 107374182400}], u'min_hwe_kernel': u'ga-16.04', u'status': 4, u'storage_test_status': 2, u'cpu_count': 16, u'raids': [], u'power_type': u'ipmi', u'physicalblockdevice_set': [{u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/1/', u'type': u'physical', u'partitions': [{u'uuid': u'c7948315-68ad-4405-9e78-42b3373c28b5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'nettfa', u'device_id': 1, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'ea60f643-8e7b-4f99-b98d-f34e8feede14', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/1/partition/7'}], u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'nettfa', 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': 1, u'size': 2397998940160}], u'other_test_status_name': u'Unknown', u'volume_groups': [{u'__incomplete__': True, u'system_id': u'nettfa', u'id': 7}], u'special_filesystems': [], u'current_commissioning_result_id': 4, u'boot_disk': {u'model': u'UCSB-MRAID12G', u'available_size': 0, u'uuid': None, u'name': u'sda', u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/1/', u'type': u'physical', u'partitions': [{u'uuid': u'c7948315-68ad-4405-9e78-42b3373c28b5', u'bootable': False, u'used_for': u'LVM volume for vgroot', u'system_id': u'nettfa', u'device_id': 1, u'filesystem': {u'label': None, u'fstype': u'lvm-pv', u'mount_point': None, u'uuid': u'ea60f643-8e7b-4f99-b98d-f34e8feede14', u'mount_options': None}, u'path': u'/dev/disk/by-dname/sda-part2', u'size': 2397992648704, u'type': u'partition', u'id': 7, u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/blockdevices/1/partition/7'}], u'tags': [u'rotary'], u'used_for': u'GPT partitioned with 1 partition', u'system_id': u'nettfa', 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': 1, u'size': 2397998940160}, u'current_testing_result_id': 5, u'cpu_test_status': -1, u'bcaches': [], u'status_name': u'Ready', u'netboot': True, u'osystem': u'', u'fqdn': u'cmp001.maas', u'disable_ipv4': False, u'commissioning_status': 2, u'architecture': u'amd64/generic', 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'bpbenn', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'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'bpbenn', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'mode': u'dhcp', u'id': 15}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'nettfa', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/interfaces/5/'}, u'interface_set': [{u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': True, u'fabric_id': 2, u'mtu': 1500, u'primary_rack': u'bpbenn', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'name': u'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'bpbenn', u'fabric': u'pxe_admin', u'relay_vlan': None, u'external_dhcp': None, u'id': 5003, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5003/'}, u'allow_proxy': True, u'rdns_mode': 2, u'gateway_ip': u'192.168.11.3', u'active_discovery': False, u'cidr': u'192.168.11.0/24', u'id': 3, u'resource_uri': u'/MAAS/api/2.0/subnets/3/'}, u'mode': u'dhcp', u'id': 15}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': [], u'params': u'', u'mac_address': u'00:25:b5:a0:00:5a', u'parents': [], u'system_id': u'nettfa', u'type': u'physical', u'id': 5, u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/interfaces/5/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp8s0', u'links': [{u'mode': u'link_up', u'id': 16}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5c', u'parents': [], u'system_id': u'nettfa', u'type': u'physical', u'id': 9, u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/interfaces/9/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp9s0', u'links': [{u'mode': u'link_up', u'id': 17}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5d', u'parents': [], u'system_id': u'nettfa', u'type': u'physical', u'id': 10, u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/interfaces/10/'}, {u'vlan': {u'name': u'untagged', u'vid': 0, u'space': u'undefined', u'dhcp_on': False, u'fabric_id': 0, u'mtu': 1500, u'primary_rack': None, u'fabric': u'fabric-0', u'relay_vlan': None, u'external_dhcp': None, u'id': 5001, u'secondary_rack': None, u'resource_uri': u'/MAAS/api/2.0/vlans/5001/'}, u'name': u'enp7s0', u'links': [{u'mode': u'link_up', u'id': 18}], u'tags': [], u'effective_mtu': 1500, u'enabled': True, u'children': [], u'discovered': None, u'params': u'', u'mac_address': u'00:25:b5:a0:00:5b', u'parents': [], u'system_id': u'nettfa', u'type': u'physical', u'id': 11, u'resource_uri': u'/MAAS/api/2.0/nodes/nettfa/interfaces/11/'}], u'address_ttl': None, u'other_test_status': -1, u'distro_series': u'', u'commissioning_status_name': u'Passed'}
2019-06-04 03:27:59,237 [salt.state       :300 ][INFO    ][19574] {'new': {'storage_layout': 'lvm'}}
2019-06-04 03:27:59,238 [salt.state       :1951][INFO    ][19574] Completed state [maas_machines_storage_cmp001_lvm] at time 03:27:59.238050 duration_in_ms=2745.577
2019-06-04 03:27:59,241 [salt.minion      :1711][INFO    ][19574] Returning information for job: 20190604032748638202
2019-06-04 03:27:59,856 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command state.apply with jid 20190604032759843351
2019-06-04 03:27:59,879 [salt.minion      :1432][INFO    ][19600] Starting a new job with PID 19600
2019-06-04 03:28:00,608 [salt.state       :915 ][INFO    ][19600] Loading fresh modules for state activity
2019-06-04 03:28:00,663 [salt.fileclient  :1219][INFO    ][19600] Fetching file from saltenv 'base', ** done ** 'maas/machines/deploy.sls'
2019-06-04 03:28:00,705 [salt.state       :1780][INFO    ][19600] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:28:00.705487
2019-06-04 03:28:00,705 [salt.state       :1813][INFO    ][19600] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 03:28:00,707 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19600] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 03:28:02,163 [salt.state       :300 ][INFO    ][19600] {'pid': 19607, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 03:28:02,163 [salt.state       :1951][INFO    ][19600] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:28:02.163453 duration_in_ms=1457.978
2019-06-04 03:28:02,164 [salt.state       :1780][INFO    ][19600] Running state [maas.deploy_machines] at time 03:28:02.164717
2019-06-04 03:28:02,164 [salt.state       :1813][INFO    ][19600] Executing state module.run for [maas.deploy_machines]
2019-06-04 03:28:02,165 [salt.utils.decorators:613 ][WARNING ][19600] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:28:02,838 [salt.loaded.ext.module.maas:684 ][INFO    ][19600] deploymachines hwe_kernel=ga-16.04 system_id=eawk73 distro_series=xenial
2019-06-04 03:28:06,583 [salt.loaded.ext.module.maas:684 ][INFO    ][19600] deploymachines hwe_kernel=ga-16.04 system_id=nettfa distro_series=xenial
2019-06-04 03:28:09,159 [salt.loaded.ext.module.maas:684 ][INFO    ][19600] deploymachines hwe_kernel=ga-16.04 system_id=qrg6rc distro_series=xenial
2019-06-04 03:28:11,560 [salt.loaded.ext.module.maas:684 ][INFO    ][19600] deploymachines hwe_kernel=ga-16.04 system_id=7bperc distro_series=xenial
2019-06-04 03:28:14,280 [salt.loaded.ext.module.maas:684 ][INFO    ][19600] deploymachines hwe_kernel=ga-16.04 system_id=hgf3mw distro_series=xenial
2019-06-04 03:28:14,882 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032814869178
2019-06-04 03:28:14,905 [salt.minion      :1432][INFO    ][19885] Starting a new job with PID 19885
2019-06-04 03:28:14,929 [salt.minion      :1711][INFO    ][19885] Returning information for job: 20190604032814869178
2019-06-04 03:28:17,095 [salt.state       :300 ][INFO    ][19600] {'ret': {'updated': [], 'errors': {}, 'success': ['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']}}
2019-06-04 03:28:17,096 [salt.state       :1951][INFO    ][19600] Completed state [maas.deploy_machines] at time 03:28:17.096068 duration_in_ms=14931.349
2019-06-04 03:28:17,099 [salt.minion      :1711][INFO    ][19600] Returning information for job: 20190604032759843351
2019-06-04 03:28:17,741 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command state.apply with jid 20190604032817728642
2019-06-04 03:28:17,764 [salt.minion      :1432][INFO    ][19943] Starting a new job with PID 19943
2019-06-04 03:28:21,463 [salt.state       :915 ][INFO    ][19943] Loading fresh modules for state activity
2019-06-04 03:28:21,503 [salt.fileclient  :1219][INFO    ][19943] Fetching file from saltenv 'base', ** done ** 'maas/machines/wait_for_deployed.sls'
2019-06-04 03:28:21,536 [salt.state       :1780][INFO    ][19943] Running state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:28:21.536588
2019-06-04 03:28:21,536 [salt.state       :1813][INFO    ][19943] Executing state cmd.run for [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials]
2019-06-04 03:28:21,538 [salt.loaded.int.module.cmdmod:395 ][INFO    ][19943] Executing command 'maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials' in directory '/root'
2019-06-04 03:28:23,064 [salt.state       :300 ][INFO    ][19943] {'pid': 19957, 'retcode': 0, 'stderr': '', 'stdout': ''}
2019-06-04 03:28:23,065 [salt.state       :1951][INFO    ][19943] Completed state [maas-region apikey --username opnfv > /var/lib/maas/.maas_credentials] at time 03:28:23.065696 duration_in_ms=1529.107
2019-06-04 03:28:23,069 [salt.state       :1780][INFO    ][19943] Running state [maas.wait_for_machine_status] at time 03:28:23.068933
2019-06-04 03:28:23,069 [salt.state       :1813][INFO    ][19943] Executing state module.run for [maas.wait_for_machine_status]
2019-06-04 03:28:23,070 [salt.utils.decorators:613 ][WARNING ][19943] The function "module.run" is using its deprecated version and will expire in version "Sodium".
2019-06-04 03:28:26,337 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2246.74283195s left)
2019-06-04 03:28:32,862 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032832849195
2019-06-04 03:28:32,884 [salt.minion      :1432][INFO    ][19969] Starting a new job with PID 19969
2019-06-04 03:28:32,907 [salt.minion      :1711][INFO    ][19969] Returning information for job: 20190604032832849195
2019-06-04 03:28:59,763 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2213.31712604s left)
2019-06-04 03:29:02,914 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032902901763
2019-06-04 03:29:02,937 [salt.minion      :1432][INFO    ][20025] Starting a new job with PID 20025
2019-06-04 03:29:02,961 [salt.minion      :1711][INFO    ][20025] Returning information for job: 20190604032902901763
2019-06-04 03:29:32,996 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604032932983831
2019-06-04 03:29:33,017 [salt.minion      :1432][INFO    ][20045] Starting a new job with PID 20045
2019-06-04 03:29:33,040 [salt.minion      :1711][INFO    ][20045] Returning information for job: 20190604032932983831
2019-06-04 03:29:33,093 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2179.98758101s left)
2019-06-04 03:30:03,045 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033003032799
2019-06-04 03:30:03,062 [salt.minion      :1432][INFO    ][20200] Starting a new job with PID 20200
2019-06-04 03:30:03,073 [salt.minion      :1711][INFO    ][20200] Returning information for job: 20190604033003032799
2019-06-04 03:30:05,957 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2147.1233449s left)
2019-06-04 03:30:33,077 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033033064813
2019-06-04 03:30:33,100 [salt.minion      :1432][INFO    ][20364] Starting a new job with PID 20364
2019-06-04 03:30:33,124 [salt.minion      :1711][INFO    ][20364] Returning information for job: 20190604033033064813
2019-06-04 03:30:39,471 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2113.60894394s left)
2019-06-04 03:31:03,135 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033103123481
2019-06-04 03:31:03,158 [salt.minion      :1432][INFO    ][20953] Starting a new job with PID 20953
2019-06-04 03:31:03,181 [salt.minion      :1711][INFO    ][20953] Returning information for job: 20190604033103123481
2019-06-04 03:31:13,029 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2080.05120492s left)
2019-06-04 03:31:33,188 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033133180178
2019-06-04 03:31:33,207 [salt.minion      :1432][INFO    ][20973] Starting a new job with PID 20973
2019-06-04 03:31:33,229 [salt.minion      :1711][INFO    ][20973] Returning information for job: 20190604033133180178
2019-06-04 03:31:46,422 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2046.65837789s left)
2019-06-04 03:32:03,243 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033203229825
2019-06-04 03:32:03,264 [salt.minion      :1432][INFO    ][21253] Starting a new job with PID 21253
2019-06-04 03:32:03,288 [salt.minion      :1711][INFO    ][21253] Returning information for job: 20190604033203229825
2019-06-04 03:32:19,751 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (2013.32902789s left)
2019-06-04 03:32:33,306 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033233295050
2019-06-04 03:32:33,327 [salt.minion      :1432][INFO    ][21281] Starting a new job with PID 21281
2019-06-04 03:32:33,346 [salt.minion      :1711][INFO    ][21281] Returning information for job: 20190604033233295050
2019-06-04 03:32:52,621 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1980.45945096s left)
2019-06-04 03:33:03,369 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033303356715
2019-06-04 03:33:03,391 [salt.minion      :1432][INFO    ][21516] Starting a new job with PID 21516
2019-06-04 03:33:03,416 [salt.minion      :1711][INFO    ][21516] Returning information for job: 20190604033303356715
2019-06-04 03:33:26,151 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1946.9287169s left)
2019-06-04 03:33:33,442 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033333429577
2019-06-04 03:33:33,464 [salt.minion      :1432][INFO    ][21536] Starting a new job with PID 21536
2019-06-04 03:33:33,488 [salt.minion      :1711][INFO    ][21536] Returning information for job: 20190604033333429577
2019-06-04 03:33:59,500 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1913.580374s left)
2019-06-04 03:34:03,517 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033403504946
2019-06-04 03:34:03,540 [salt.minion      :1432][INFO    ][21866] Starting a new job with PID 21866
2019-06-04 03:34:03,564 [salt.minion      :1711][INFO    ][21866] Returning information for job: 20190604033403504946
2019-06-04 03:34:33,101 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1879.97934008s left)
2019-06-04 03:34:33,600 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033433588366
2019-06-04 03:34:33,622 [salt.minion      :1432][INFO    ][21890] Starting a new job with PID 21890
2019-06-04 03:34:33,646 [salt.minion      :1711][INFO    ][21890] Returning information for job: 20190604033433588366
2019-06-04 03:35:03,689 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033503676564
2019-06-04 03:35:03,712 [salt.minion      :1432][INFO    ][22323] Starting a new job with PID 22323
2019-06-04 03:35:03,737 [salt.minion      :1711][INFO    ][22323] Returning information for job: 20190604033503676564
2019-06-04 03:35:06,397 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1846.68363595s left)
2019-06-04 03:35:33,784 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033533771211
2019-06-04 03:35:33,807 [salt.minion      :1432][INFO    ][22343] Starting a new job with PID 22343
2019-06-04 03:35:33,830 [salt.minion      :1711][INFO    ][22343] Returning information for job: 20190604033533771211
2019-06-04 03:35:39,605 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1813.47480488s left)
2019-06-04 03:36:03,888 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033603876387
2019-06-04 03:36:03,913 [salt.minion      :1432][INFO    ][22525] Starting a new job with PID 22525
2019-06-04 03:36:03,936 [salt.minion      :1711][INFO    ][22525] Returning information for job: 20190604033603876387
2019-06-04 03:36:13,414 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'cmp001', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1779.66581607s left)
2019-06-04 03:36:34,000 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033633988020
2019-06-04 03:36:34,024 [salt.minion      :1432][INFO    ][22612] Starting a new job with PID 22612
2019-06-04 03:36:34,049 [salt.minion      :1711][INFO    ][22612] Returning information for job: 20190604033633988020
2019-06-04 03:36:46,778 [salt.loaded.ext.module.maas:1023][INFO    ][19943] Waiting status:Deployed for machines:['cmp002', 'kvm01', 'kvm03', 'kvm02']
sleep for:30s Timeout:2250s (1746.30186796s left)
2019-06-04 03:37:04,082 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command saltutil.find_job with jid 20190604033704069721
2019-06-04 03:37:04,106 [salt.minion      :1432][INFO    ][22849] Starting a new job with PID 22849
2019-06-04 03:37:04,133 [salt.minion      :1711][INFO    ][22849] Returning information for job: 20190604033704069721
2019-06-04 03:37:19,710 [salt.state       :300 ][INFO    ][19943] {'ret': True}
2019-06-04 03:37:19,710 [salt.state       :1951][INFO    ][19943] Completed state [maas.wait_for_machine_status] at time 03:37:19.710691 duration_in_ms=536641.755
2019-06-04 03:37:19,714 [salt.minion      :1711][INFO    ][19943] Returning information for job: 20190604032817728642
2019-06-04 04:13:19,481 [salt.utils.schedule:1377][INFO    ][15098] Running scheduled job: __mine_interval
2019-06-04 05:13:19,482 [salt.utils.schedule:1377][INFO    ][15098] Running scheduled job: __mine_interval
2019-06-04 05:14:07,038 [salt.minion      :1308][INFO    ][15098] User sudo_ubuntu Executing command cp.push_dir with jid 20190604051407025478
2019-06-04 05:14:07,059 [salt.minion      :1432][INFO    ][30244] Starting a new job with PID 30244
